Menu
▾
▴
#42 ciddata.log gets corrupt
Very often ciddata.log gets corrupt. It happens both in 1.10 and 1.11. For example it might be working well for some time, and suddenly it starts behaving like this (I'm replacing some digits with * for privacy). If I kill and restart the daemon things are ok for a whlie but then it happens again.
DATE = 0406
TIME = 1354
NMBR = 408646****
NAME = WIRELESS CALLER
RING
A
T
A
T
+
C
G
M
I
...
= 650207****
EN
= 408808****
CNTY
ncidd.log also shows numbers logged strange (without NMBR)
Received: REQ: ACK [04/08/2020 17:54:17]
Sent Client 7 pos 3: ACK: REQ: ACK 04/08/2020 17:54:17
Serial fd 4 pos 0 sent 8 bytes 04/08/2020 18:10:01
Serial fd 4 pos 0 sent 32 bytes 04/08/2020 18:10:02
Serial fd 4 pos 0 sent 32 bytes 04/08/2020 18:10:02
= 408808****
Serial fd 4 pos 0 sent 7 bytes 04/08/2020 18:10:02
CNTY
Client 7 pos 3 from 192.168.10.186 [192.168.10.186] nodialout {ONEPLUS A3000-6605/NCIDandroid 0.2.0.2} disconnected 04/08/2020 18:12:53
Discussion
Anonymous
Here's another example from a few weeks ago:
RING
A
T
A
T
+
C
G
M
I
A
T
+
G
M
I
A
T
%
I
P
S
Y
S
?
A
T
%
I
P
S
Y
S
?
= 650207****
From that point on all entries are malformatted. It is not a problem with the modem (a Trendnet TFM-561U usb modem), if I use mgetty with the same modem I can collect caller-id reliably for months. ncid exhibits this problem both with the ubuntu distro-provided ncid 1.10, and with 1.11 which I downloaded here and compiled on my own. I cannot report about earlier versions of ncid.
This looks a lot like what the ModemManager sends when it is probing the modem.
Can you make sure that the ModemManager is not running/ trying to interfere? (Instructions can be found in the User Manual.)
ModemManager was running. I stopped and disabled it with systemctl and will let you know how it goes. Thank you for the suggestion!
Yes, it was indeed ModemManager, I reproduced the problem by starting ModemManager manually while monitoring the logs. Shouldn't ncid be able to recover from this rather than allowing a few seconds of ModemManager interference from making ncid permanently confused? It never recovers (unless you kill ncid). mgetty is also affected by ModemManager but re-tries a fresh initialization and recovers fully by itself.
In the past we've only seen the ModemManager interfere at system start-up. I put code into 1.11 to do a retry when this confuses the initialization, and when the modem is unplugged and plugged back in.
I can't picture a way to recover from having ModemManager talk at the same time as the modem is trying to send caller ID information. ncidd will eat everything that it sees on the modem usb, but this won't help if ModemManager keeps talking when the phone rings.
When ModemManager interferers during a ring, it's understandable. After that happens however, all future phone calls (even if if I kill ModemManager) continue to show garbled results of the form:
= ##########
XXXX
and ncidd never recovers. I reproduced it right now. ModemManager is no longer running but every time I call, ncidd continues to log the number without "NMBR", and in the next line it logs the last 4 characters of the caller-id name (without "NAME = ". The DATE and TIME are not logged at all. This behavior continues for all future calls even though ModemManager is no longer in the picture.
In contrast, mgetty senses interference with a log message like:
04/16 18:05:45 CM0 huh? Junk on the line?
04/16 18:05:45 CM0 >>> could be a dial-out program without proper locking - check this!
and re-initializes itself and works fine after that.
Could you please add a check in ncidd so that it if it reads strange things from the modem, and/or finds itself logging strange stuff like " = somenumber" it will re-initialize and correct itself ? Thank you!
Could you please attach an entire ncidd.log file at verbose level 7 for the case where your ModemManager causes nicidd to get stuck and stay that way? I'm having trouble visualising what might be happening here.
(change phone numbers to something obvious like 1234567)
Here you go, I easily can reproduce it any time (by starting and stopping ModemManager). Attaching the log, in which I inserted some lines starting with "##### Here" where I describe my actions (starting ModemManager, stopping it, calling my line)
The ModemManager is rudely changing the modem device from cooked/canonical mode to raw/noncanonical while it is poking it, and then not putting it back to the way it found it.
The read() done by ncidd then gets 0d0a52494e470d0a instead of the three lines that it would normally have gotten for "RING"
Can you make ncidd re-initialize if it notices unexpected stuff? A modem after initialization is completely silent until a ring comes. So if you see any characters you know it's interference. As I brought up before, another modem app (mgetty) as soon as it sees something other than a ring, it declares it as "noise" and assumes another app might have improperly accessed the modem, so it re-initializes. Even if an another app isn't changing the mode to raw/nocanonical, it could still pass a wrong init string to the modem or even ATZ or AT&F and make it stop reporting caller-id. So re-initializing would be good! Anyway if you want to address it I'll be happy to test a patch. If not, no worries, and thank you for the ModemManager pointer; I disabled it which is an acceptable workaround for me.
The most surprising thing in this is that your ModemManager is talking to the modem after the system boots. In our experience the interference has only been seen as ncidd starts up, and new code in 1.11 should detect it and retry the initialization.
I can change ncidd for a future version to stay in raw mode to gather bytes while reading from the modem.
John would like to know what version of ModemManager you have. Could you post the result from this?
ModemManager -V
It's the version that came with my Xubuntu 19.10 installation:
$ ModemManager -V
ModemManager 1.10.4
I'm closing this because it appears that stopping ModemManager fixes the complaint. The code for ncidd's modem interaction should also be more resistant to the confusion caused by interference from the ModemManager.