I'm running NCIDpop v.0.10.6.0 on OS X v.10.10.3 and NCIDD on a rasPI 1.0.3.6a-ns32. The cidcall.log file is 4400 bytes in size with approx. 530 lines in it.
My question is that it now takes about 1-2 minutes to add a new alias via NCIDpop. Is that what other users are finding?
I haven't tried starting a new log file yet I'm just thinking that 530 lines isn't a particularly large file to process. I've found that occasionally ncidd starts generating cidcall.log.new.new... files which slows the adding aliases down but that's easily remedied.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Adding aliases should be nearly instantaneous. Upon clicking on a name in the call (or message) log, NCIDpop does a request to the server to see if an alias exists; if not, the option to "add alias" appears. Adding an alias results in a command to the server, which should also be instantaneous. From there, you are presented with the option to update log files with the new alias.
Sounds like the problem exists with a slowly functioning server or a slow connection to the server.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
You mention the cidcall.log.new.new files you're seeing.
When NCIDpop asks, "Would you like to apply aliases to all call logs?", choosing "All Logs" could definitely result in more processing time needed based on 1) the number of cidcall.log files and 2) the size of each one. ncidd waits until all cidcall.log files get updated.
If everything is running correctly, there should be no .new files when the "add alias" step completes. The presence of .new files means something went wrong, and NCIDpop should display a message about the problem.
If you answer the NCIDpop prompt by choosing, "Just Current Log", you should experience the nearly instantaneous update that Chris is describing.
To troubleshoot this, you could try stopping ncidd and restart in debug mode with at least verbose level 3:
sudo ncidd -Dv3
Add an alias through NCIDpop and watch the output from ncidd. Maybe you'll notice where delays are occurring.
Note to John: ncidd version 1.0.3.6a-ns32 is one I created just for nospam based on this post.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I think the .new files are appearing when I update the alias and receive a call at the same time. The .new files seem to appear at random intervals so I can't give you more detail yet as to when they happen. I have been running ncidd in Verbose level: 3 unfortunatly my logs of the previous problems were lost after reboot.
Is there anything in particular I should look for in the logs?
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Is there anything in particular I should look for in the logs?
Unfortunately not because the issue at hand is the amount of processing time being taken to add an alias and we don't know yet exactly which step is experiencing the slow down. Looking at past logs won't help because there's no indication in a log as to how long something takes to complete. You have to be watching the debug activity in real time.
Start adding an alias in NCIDpop, then immediately start watching the ncidd debug activity.
When you experience the slow down, how did you answer the NCIDpop prompt, "Would you like to apply aliases to all call logs?"
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Everything seemed ok then on May 5th it started creating and leaving the .new files.
The log file contains:(actual phone numbers and an alias are asterisked out)
REQ: alias add "--*&&SPAM" "NAMEDEP&&OUT-OF-AREA"
/usr/bin/ncidutil --multi "/etc/ncid/ncidd.blacklist /etc/ncid/ncidd.whitelist" "/etc/ncid/ncidd.alias" Alias add "--&&SPAM" "NAMEDEP&&OUT-OF-AREA" 2>&1
402 Start of data showing status of handled request
RESP: Done.
411 End of response
REQ: RELOAD
Received Signal 1: Hangup
Reloading alias, blacklist, and whitelist files: 05/01/2015 14:04:20
Processed alias file: /etc/ncid/ncidd.alias
Alias Table:
Number of Entries: 145
Processed blacklist file: /etc/ncid/ncidd.blacklist
Blacklist Table:
Number of Entries: 1
Processed whitelist file: /etc/ncid/ncidd.whitelist
Whitelist Table:
Number of Entries: 0
400 Start of data requiring OK
INFO: Received Signal 1: Hangup
INFO: Reloading alias, blacklist, and whitelist files: 05/01/2015 14:04:20
INFO: Processed alias file: /etc/ncid/ncidd.alias
INFO: Alias Table:
INFO: Number of Entries: 145
INFO: Processed blacklist file: /etc/ncid/ncidd.blacklist
INFO: Blacklist Table:
INFO: Number of Entries: 1
INFO: Processed whitelist file: /etc/ncid/ncidd.whitelist
INFO: Whitelist Table:
INFO: Number of Entries: 0
410 End of data
REQ: INFO *&&OUT-OF-AREA
403 Start of data defining permitted requests
INFO: alias NOALIAS
INFO: neither
411 End of response
REQ: UPDATES
/usr/bin/cidupdate -a /etc/ncid/ncidd.alias -c /var/log/cidcall.log --multi < /dev/null 2>&1
401 Start of data requiring ACCEPT or REJECT
INFO: There were 3 changes to /var/log/cidcall.log
INFO: There was 1 change to /var/log/cidcall.log.2015-04-27
INFO: There were no changes to /var/log/cidcall.log.2015-04-27.new
INFO: There were no changes to /var/log/cidcall.log.new
INFO:
INFO: 1 Changed "***" to "****" for * 3 times
INFO: 1 Changed "OUT-OF-AREA" to "SPAM" for * 1 time
410 End of data
REQ: INFO *&&OUT-OF-AREA
403 Start of data defining permitted requests
INFO: alias NOALIAS
INFO: neither
411 End of response
The worst case was when I noticed it was creating multiple .new files
cidcall.log.new.new.new.new.new.new.new.new.new.new.new.new.new
It looks to me that the script will parse any log file that begins with "cidcall.log" and the .new files aren't being deleted properly for whatever reason - maybe a busy processor not executing all commands in the stack?
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
It looks to me that the script will parse any log file that begins with "cidcall.log"
That is exactly right. The more cidcall.log files it finds when you say "All Logs," the longer it will take for the "add alias" process to complete.
and the .new files aren't being deleted properly for whatever reason - maybe a busy processor not executing all commands in the stack?
The primary way I can see this happening is if something interrupts the RPi while it's updating all the files. For example, hitting <CTRL-C> while ncidd is running in debug mode, or maybe something triggers the RPi to reboot.
Another way this could happen would be if there is some bug in the code. EXCEPT for the long delay you're experiencing, is the "add alias" working OK?
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
FYI I made a backup of the cidcall.log file and deleted everything but the last 40 lines. The add-alias now works in under 5 seconds. I'm guessing something in the way the code parses the file is getting bogged down on the wee little Pi. Hmm 40 lines 5 seconds, 500 lines 120 seconds...maybe to many other tasks running in the background?
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
maybe to many other tasks running in the background?
That is certainly possible.
I haven't seen responses to the slow down related questions I asked above or to the troubleshooting steps I provided -- does this mean you tried them but saw no evidence of slow down? And therefore the most reasonable conclusion you've come to is the slow down has to do with other background tasks? It's OK if this is the case, I'm just wondering.
Regarding the other issue of multiple .new files, we're looking into making changes to improve the "clean up" routines that would remove the .new files in unusual termination circumstances.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Sorry I missed answering your questions. Here's my responses:
is the "add alias" working OK?
Yes, just very slow with a larger log file. The only problem I've run into was having an alias that was too long causing ncidd to crash/be unresponsive until I manually changed the alias log file and rebooted.
Re- Debug mode
Haven't tried that yet. The rasPi is running headless and is also running Motion v.3.2.12 at the same time.
3.When you experience the slow down, how did you answer the NCIDpop prompt, "Would you like to apply aliases to all call logs?"
I answered Yes to apply to all logs.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Do you happen to still have details on the ncidd crash with the long alias line? There's a possibility this could have left an orphaned .new file, too.
Hold off on doing these steps. I was thinking about your slow down issue quite a bit today and I'm going to add some debug code that should help us pinpoint the problem. I'll try to complete this in the next few days and provide you modified program(s) with instructions.
The size of the logs you reported above seem to be only for the current one, cidcall.log. Since the alias update is being applied to all logs, you'll have to take the size of all of them into account when considering the total time it takes to add an alias.
Hi Todd, the ncidd.alias file is only 228 lines long (8671 bytes). I would want to clean up the alias file to remove private numbers before sending it by PE.
The only odd part is that some ncidd.alias entries are with quotes for the phone numbers but most are without quotes e.g.
alias NAME * = "test1" if "12345678910"
alias NAME * = "test2" if 12345678911
It looks like two different parts of code are writing to the alias file. "Update Alias" is adding the quotes as far as I can tell.
The other thing that I like to do is tag SPAMMER numbers with the alias "SPAM"
alias NAME * = "SPAM" if 18033392763
So my alias file has about 100 "SPAM" tags for different numbers. In my blacklist file I block any name with "SPAM" in it. My only entry in the blacklist file is the word SPAM.
/##############
/# Auto Added #
/##############
SPAM
My whitelist file is the stock version with no added entries.
The reason why I do this is that I find ncidd likes to tag many numbers as "OUT-OF-AREA" (even numbers with my local area code) and the ncid client on my iPad only shows the caller name as "OUT-OF-AREA" instead of the full caller ID or number. This may be due to the fact I'm running the USR5637 modem. Adding the alias "SPAM" is a nice way to quickly flag SPAM calls without having to click on anything in the ncidd client call list.
With regards to Motion I tried "Update Alias" with motion on and off. The test cidcall.log file has 58 entries (4873 bytes) and I modified the very last entry phone number that appears only once in the log. I timed it roughly from when I select the "OK" button from the prompt "Please Enter The Alias Name for Phone Number" to the time the "Accept or Reject" popup appears.
Motion OFF - 14 seconds
Motion ON - 20 seconds
Yes there is a penalty for multitasking on the Pi.
The ncidd crash logs are long gone sorry.
Generally ncidd is doing its job and blocks the SPAM numbers on the first ring (sweet). I could never get the "answer blacklisted callers with fax" working properly as ncidd crashes and stops working after the first time it answers the blacklisted caller with a fax. I assumed this was a problem with the USR modem and never pursued it beyond the first few crashes.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I'm running NCIDpop v.0.10.6.0 on OS X v.10.10.3 and NCIDD on a rasPI 1.0.3.6a-ns32. The cidcall.log file is 4400 bytes in size with approx. 530 lines in it.
My question is that it now takes about 1-2 minutes to add a new alias via NCIDpop. Is that what other users are finding?
I haven't tried starting a new log file yet I'm just thinking that 530 lines isn't a particularly large file to process. I've found that occasionally ncidd starts generating cidcall.log.new.new... files which slows the adding aliases down but that's easily remedied.
Hi,
Adding aliases should be nearly instantaneous. Upon clicking on a name in the call (or message) log, NCIDpop does a request to the server to see if an alias exists; if not, the option to "add alias" appears. Adding an alias results in a command to the server, which should also be instantaneous. From there, you are presented with the option to update log files with the new alias.
Sounds like the problem exists with a slowly functioning server or a slow connection to the server.
Hi nospam,
You mention the cidcall.log.new.new files you're seeing.
When NCIDpop asks, "Would you like to apply aliases to all call logs?", choosing "All Logs" could definitely result in more processing time needed based on 1) the number of cidcall.log files and 2) the size of each one.
ncidd
waits until all cidcall.log files get updated.If everything is running correctly, there should be no .new files when the "add alias" step completes. The presence of .new files means something went wrong, and NCIDpop should display a message about the problem.
If you answer the NCIDpop prompt by choosing, "Just Current Log", you should experience the nearly instantaneous update that Chris is describing.
To troubleshoot this, you could try stopping
ncidd
and restart in debug mode with at least verbose level 3:Add an alias through NCIDpop and watch the output from
ncidd
. Maybe you'll notice where delays are occurring.Note to John: ncidd version 1.0.3.6a-ns32 is one I created just for nospam based on this post.
I think the .new files are appearing when I update the alias and receive a call at the same time. The .new files seem to appear at random intervals so I can't give you more detail yet as to when they happen. I have been running ncidd in Verbose level: 3 unfortunatly my logs of the previous problems were lost after reboot.
Is there anything in particular I should look for in the logs?
Hi nospam,
Unfortunately not because the issue at hand is the amount of processing time being taken to add an alias and we don't know yet exactly which step is experiencing the slow down. Looking at past logs won't help because there's no indication in a log as to how long something takes to complete. You have to be watching the debug activity in real time.
Start adding an alias in NCIDpop, then immediately start watching the
ncidd
debug activity.When you experience the slow down, how did you answer the NCIDpop prompt, "Would you like to apply aliases to all call logs?"
Here is an excerpt from the last time it did something weird with the log files. I manually created a backup of the log file from the shell prompt.
Everything seemed ok then on May 5th it started creating and leaving the .new files.
The log file contains:(actual phone numbers and an alias are asterisked out)
The worst case was when I noticed it was creating multiple .new files
cidcall.log.new.new.new.new.new.new.new.new.new.new.new.new.new
It looks to me that the script will parse any log file that begins with "cidcall.log" and the .new files aren't being deleted properly for whatever reason - maybe a busy processor not executing all commands in the stack?
Hi nospam,
That is exactly right. The more cidcall.log files it finds when you say "All Logs," the longer it will take for the "add alias" process to complete.
The primary way I can see this happening is if something interrupts the RPi while it's updating all the files. For example, hitting <CTRL-C> while
ncidd
is running in debug mode, or maybe something triggers the RPi to reboot.Another way this could happen would be if there is some bug in the code. EXCEPT for the long delay you're experiencing, is the "add alias" working OK?
This could be another way. I think it will be best if we figure out what's causing the slow down first and then we can tackle the leftover .new files.
FYI I made a backup of the cidcall.log file and deleted everything but the last 40 lines. The add-alias now works in under 5 seconds. I'm guessing something in the way the code parses the file is getting bogged down on the wee little Pi. Hmm 40 lines 5 seconds, 500 lines 120 seconds...maybe to many other tasks running in the background?
Hi nospam,
That is certainly possible.
I haven't seen responses to the slow down related questions I asked above or to the troubleshooting steps I provided -- does this mean you tried them but saw no evidence of slow down? And therefore the most reasonable conclusion you've come to is the slow down has to do with other background tasks? It's OK if this is the case, I'm just wondering.
Regarding the other issue of multiple .new files, we're looking into making changes to improve the "clean up" routines that would remove the .new files in unusual termination circumstances.
Sorry I missed answering your questions. Here's my responses:
is the "add alias" working OK?
Yes, just very slow with a larger log file. The only problem I've run into was having an alias that was too long causing ncidd to crash/be unresponsive until I manually changed the alias log file and rebooted.
Re- Debug mode
Haven't tried that yet. The rasPi is running headless and is also running Motion v.3.2.12 at the same time.
3.When you experience the slow down, how did you answer the NCIDpop prompt, "Would you like to apply aliases to all call logs?"
I answered Yes to apply to all logs.
Motion is usually quite a cpu hog on an RPi. What is the performance of add-alias with Motion not running?
Hi nospam,
Do you happen to still have details on the
ncidd
crash with the long alias line? There's a possibility this could have left an orphaned .new file, too.Hold off on doing these steps. I was thinking about your slow down issue quite a bit today and I'm going to add some debug code that should help us pinpoint the problem. I'll try to complete this in the next few days and provide you modified program(s) with instructions.
The size of the logs you reported above seem to be only for the current one, cidcall.log. Since the alias update is being applied to all logs, you'll have to take the size of all of them into account when considering the total time it takes to add an alias.
Could you send me and John by private email your file
ncidd.alias
? Send as an attachment to: tandrews@users.sf.net and jlc@users.sf.net.Hi Todd, the ncidd.alias file is only 228 lines long (8671 bytes). I would want to clean up the alias file to remove private numbers before sending it by PE.
The only odd part is that some ncidd.alias entries are with quotes for the phone numbers but most are without quotes e.g.
It looks like two different parts of code are writing to the alias file. "Update Alias" is adding the quotes as far as I can tell.
The other thing that I like to do is tag SPAMMER numbers with the alias "SPAM"
So my alias file has about 100 "SPAM" tags for different numbers. In my blacklist file I block any name with "SPAM" in it. My only entry in the blacklist file is the word SPAM.
My whitelist file is the stock version with no added entries.
The reason why I do this is that I find ncidd likes to tag many numbers as "OUT-OF-AREA" (even numbers with my local area code) and the ncid client on my iPad only shows the caller name as "OUT-OF-AREA" instead of the full caller ID or number. This may be due to the fact I'm running the USR5637 modem. Adding the alias "SPAM" is a nice way to quickly flag SPAM calls without having to click on anything in the ncidd client call list.
With regards to Motion I tried "Update Alias" with motion on and off. The test cidcall.log file has 58 entries (4873 bytes) and I modified the very last entry phone number that appears only once in the log. I timed it roughly from when I select the "OK" button from the prompt "Please Enter The Alias Name for Phone Number" to the time the "Accept or Reject" popup appears.
Motion OFF - 14 seconds
Motion ON - 20 seconds
Yes there is a penalty for multitasking on the Pi.
The ncidd crash logs are long gone sorry.
Generally ncidd is doing its job and blocks the SPAM numbers on the first ring (sweet). I could never get the "answer blacklisted callers with fax" working properly as ncidd crashes and stops working after the first time it answers the blacklisted caller with a fax. I assumed this was a problem with the USR modem and never pursued it beyond the first few crashes.
I spoke to soon. I don't know what I did but ncidd is now hanging up on every caller. Don't have a clue why other than I ran several update aliases.