Hi,


we're running version 3.1.11 on debian a) intel, b) arm. While delivery reports work on intel, they don't work on arm, same OS, same version, compiled from source. Modem is cinterion (siemens chipset), so this isn't the issuel.

In the logs below the arm machine has GMT 6: xxx, the intel machine local time 8:54.

We know that later versions have some issues, so we've compiled 3.1.11 on each box.

Has anybody an idea what's going on here? What could be an issue is the the arm machine runs an android based kernel, which needs some permissions to access the internet. smsd runs as smsd:dialout and has inet permissions:

/etc/group:
dialout: x:20: agocontrol,smsd
inet: x:3003: root,jbk,postgres,www-data,smsd



Log start:
2013-05-28 08:18:37,2, smsd: Smsd v3.1.11 started.
2013-05-28 08:18:37,2, smsd: Running as smsd:dialout.
2013-05-28 08:18:37,7, smsd: Running startup_check (shell): /tmp/smsd_script.IRQDMP /tmp/smsd_data.ySfr63
2013-05-28 08:18:37,7, smsd: Done: startup_check (shell), execution time 0 sec., status: 0 (0)
2013-05-28 08:18:37,4, smsd: File mode creation mask: 022 (0644, rw-r--r--).
2013-05-28 08:18:37,5, smsd: Outgoing file checker has started. PID: 1404.
2013-05-28 08:18:37,5, GSM1: Modem handler 0 has started. PID: 1405.
2013-05-28 08:18:37,5, GSM1: Using check_memory_method 1: CPMS is used.
2013-05-28 08:18:37,6, GSM1: Checking device for incoming SMS
2013-05-28 08:18:37,6, GSM1: Checking if modem is ready
2013-05-28 08:18:37,7, GSM1: -> AT
2013-05-28 08:18:37,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:37,7, GSM1: <- AT OK
2013-05-28 08:18:37,6, GSM1: Pre-initializing modem
2013-05-28 08:18:37,7, GSM1: -> ATE0+CMEE=1
2013-05-28 08:18:37,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:38,7, GSM1: <- ATE0+CMEE=1 OK
2013-05-28 08:18:38,6, GSM1: Checking if modem needs PIN
2013-05-28 08:18:38,7, GSM1: -> AT+CPIN?
2013-05-28 08:18:38,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:38,7, GSM1: <- +CPIN: READY OK
2013-05-28 08:18:38,6, GSM1: Initializing modem
2013-05-28 08:18:38,7, GSM1: -> ATZ
2013-05-28 08:18:38,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:39,7, GSM1: <- OK
2013-05-28 08:18:39,7, GSM1: -> AT+CNMI=2,0,0,2,1;+CFUN=1
2013-05-28 08:18:39,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:39,7, GSM1: <- AT+CNMI=2,0,0,2,1;+CFUN=1 OK
2013-05-28 08:18:39,7, GSM1: -> AT+CSQ
2013-05-28 08:18:39,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:40,7, GSM1: <- AT+CSQ +CSQ: 17,99 OK
2013-05-28 08:18:40,6, GSM1: Checking if Modem is registered to the network
2013-05-28 08:18:40,7, GSM1: -> AT+CREG?
2013-05-28 08:18:40,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:40,7, GSM1: <- AT+CREG? +CREG: 0,1 OK
2013-05-28 08:18:40,6, GSM1: Modem is registered to the network
2013-05-28 08:18:40,6, GSM1: Selecting PDU mode
2013-05-28 08:18:40,7, GSM1: -> AT+CMGF=0
2013-05-28 08:18:40,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:41,7, GSM1: <- AT+CMGF=0 OK
2013-05-28 08:18:41,7, GSM1: -> AT+CIMI
2013-05-28 08:18:41,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:41,7, GSM1: <- AT+CIMI 262029023831401 OK
2013-05-28 08:18:41,7, GSM1: -> AT+CGSN
2013-05-28 08:18:41,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:42,7, GSM1: <- AT+CGSN 356613020064804 OK
2013-05-28 08:18:42,5, GSM1: CGSN: 356613020064804
2013-05-28 08:18:42,5, GSM1: IMSI: 262029023831401
2013-05-28 08:18:42,6, GSM1: Checking if reading of messages is supported
2013-05-28 08:18:42,7, GSM1: -> AT+CPMS?
2013-05-28 08:18:42,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:42,7, GSM1: <- AT+CPMS? +CPMS: "MT",0,45,"MT",0,45,"MT",0,45 OK
2013-05-28 08:18:42,6, GSM1: Checking memory size
2013-05-28 08:18:42,7, GSM1: -> AT+CPMS?
2013-05-28 08:18:42,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:18:43,7, GSM1: <- AT+CPMS? +CPMS: "MT",0,45,"MT",0,45,"MT",0,45 OK
2

2013-05-28 08:23:05,6, GSM1: I have to send 1 short message for /var/spool/sms/checked/4431.sms
2013-05-28 08:23:05,6, GSM1: Sending SMS from to 4915201577269
2013-05-28 08:23:05,6, GSM1: Checking if modem is ready
2013-05-28 08:23:05,7, GSM1: -> AT
2013-05-28 08:23:05,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:05,7, GSM1: <- AT OK
2013-05-28 08:23:05,6, GSM1: Pre-initializing modem
2013-05-28 08:23:05,7, GSM1: -> ATE0+CMEE=1
2013-05-28 08:23:05,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:06,7, GSM1: <- ATE0+CMEE=1 OK
2013-05-28 08:23:06,6, GSM1: Initializing modem
2013-05-28 08:23:06,7, GSM1: -> ATZ
2013-05-28 08:23:06,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:06,7, GSM1: <- OK
2013-05-28 08:23:06,7, GSM1: -> AT+CNMI=2,0,0,2,1;+CFUN=1
2013-05-28 08:23:06,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:07,7, GSM1: <- AT+CNMI=2,0,0,2,1;+CFUN=1 OK
2013-05-28 08:23:07,7, GSM1: -> AT+CSQ
2013-05-28 08:23:07,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:07,7, GSM1: <- AT+CSQ +CSQ: 23,99 OK
2013-05-28 08:23:07,6, GSM1: Checking if Modem is registered to the network
2013-05-28 08:23:07,7, GSM1: -> AT+CREG?
2013-05-28 08:23:07,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:08,7, GSM1: <- AT+CREG? +CREG: 0,1 OK
2013-05-28 08:23:08,6, GSM1: Modem is registered to the network
2013-05-28 08:23:08,6, GSM1: Selecting PDU mode
2013-05-28 08:23:08,7, GSM1: -> AT+CMGF=0
2013-05-28 08:23:08,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:08,7, GSM1: <- AT+CMGF=0 OK
2013-05-28 08:23:08,7, GSM1: -> AT+CMGS=18
2013-05-28 08:23:08,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:09,7, GSM1: <- AT+CMGS=18 >
2013-05-28 08:23:09,7, GSM1: -> 0031000D91945102517762F90000FF036AB51A^Z
2013-05-28 08:23:09,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:12,7, GSM1: <- 0031000D91945102517762F90000FF036AB51A^Z +CMGS: 12 OK
2013-05-28 08:23:12,5, GSM1: SMS sent, Message_id: 12, To: 4915201577269, sending time 7 sec.
2
2013-05-28 08:23:28,6, GSM1: Modem is registered to the network
2013-05-28 08:23:28,6, GSM1: Selecting PDU mode
2013-05-28 08:23:28,7, GSM1: -> AT+CMGF=0
2013-05-28 08:23:28,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:28,7, GSM1: <- AT+CMGF=0 OK
2013-05-28 08:23:28,6, GSM1: Checking memory size
2013-05-28 08:23:29,7, GSM1: -> AT+CPMS?
2013-05-28 08:23:29,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:29,7, GSM1: <- AT+CPMS? +CPMS: "MT",1,45,"MT",1,45,"MT",1,45 OK
2013-05-28 08:23:29,6, GSM1: Used memory is 1 of 45
2013-05-28 08:23:29,6, GSM1: Trying to get stored message 1
2013-05-28 08:23:29,7, GSM1: -> AT+CMGR=1
2013-05-28 08:23:29,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:29,7, GSM1: <- AT+CMGR=1 +CMGR: 0,,26 0791947122723033060C0D91945102517762F9315082803201803150828032018000 OK
2013-05-28 08:23:29,5, GSM1: SMS received (report, Message_id: 12, Status: 0), From: 4915201577269
2013-05-28 08:23:29,6, GSM1: Wrote an incoming message file: /var/spool/sms/incoming/GSM1.t1TOaC
2013-05-28 08:23:29,7, GSM1: Running eventhandler: /var/www/tracklink.de/htdocs/lib/runsmstools3.sh REPORT /var/spool/sms/incoming/GSM1.t1TOaC
2013-05-28 08:23:29,7, GSM1: Done: eventhandler, execution time 0 sec., status: 0 (0)
2013-05-28 08:23:29,6, GSM1: Deleting message 1
2013-05-28 08:23:30,7, GSM1: -> AT+CMGD=1
2013-05-28 08:23:30,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:32,7, GSM1: <- AT+CMGD=1 OK
2013-05-28 08:23:32,6, GSM1: Checking device for incoming SMS
2013-05-28 08:23:32,6, GSM1: Checking memory size
2013-05-28 08:23:32,7, GSM1: -> AT+CPMS?
2013-05-28 08:23:32,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:32,7, GSM1: <- AT+CPMS? +CPMS: "MT",1,45,"MT",1,45,"MT",1,45 OK
2013-05-28 08:23:32,6, GSM1: Used memory is 1 of 45
2013-05-28 08:23:32,6, GSM1: Trying to get stored message 1
2013-05-28 08:23:32,7, GSM1: -> AT+CMGR=1
2013-05-28 08:23:32,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:33,7, GSM1: <- AT+CMGR=1 +CMGR: 0,,0 OK
2013-05-28 08:23:33,6, GSM1: Trying to get stored message 2
2013-05-28 08:23:33,7, GSM1: -> AT+CMGR=2
2013-05-28 08:23:33,7, GSM1: Command is sent, waiting for the answer
2013-05-28 08:23:33,7, GSM1: <- AT+CMGR=2 +CMGR: 0,,23 0791947122723033040D91945102517762F9000431508280320280036A6A6A OK
2013-05-28 08:23:33,5, GSM1: SMS received, From: 4915201577269
2013-05-28 08:23:33,6, GSM1: Wrote an incoming message file: /var/spool/sms/incoming/GSM1.QD7n0K
2013-05-28 08:23:33,7, GSM1: Running eventhandler: /var/www/tracklink.de/htdocs/lib/runsmstools3.sh RECEIVED /var/spool/sms/incoming/GSM1.QD7n0K
2013-05-28 08:23:33,7, GSM1: Done: eventhandler, execution time 0 sec., status: 0 (0)
2013-05-28 08:23:33,6, GSM1: Deleting message 2
2013-05-28 08:23:34,7, GSM1: -> AT+CMGD=2
2


So far, so good. Now the arm box. Same modem, but connected via USB (ttyACM0, no that's not the issue):
2013-05-28 06:02:45,2, smsd: Smsd v3.1.11 started.
2013-05-28 06:02:45,2, smsd: Running as smsd:dialout.
2013-05-28 06:02:45,7, smsd: Running startup_check (shell): /tmp/smsd_script.oJw7ps /tmp/smsd_data.ItgYYe
2013-05-28 06:02:45,7, smsd: Done: startup_check (shell), execution time 0 sec., status: 0 (0)
2013-05-28 06:02:45,4, smsd: File mode creation mask: 022 (0644, rw-r--r--).
2013-05-28 06:02:45,5, smsd: Outgoing file checker has started. PID: 4692.
2013-05-28 06:02:45,5, GSM1: Modem handler 0 has started. PID: 4693.
2013-05-28 06:02:45,5, GSM1: Using check_memory_method 1: CPMS is used.
2013-05-28 06:02:45,6, GSM1: Checking device for incoming SMS
2013-05-28 06:02:45,6, GSM1: Checking if modem is ready
2013-05-28 06:02:45,3, GSM1: Unexpected input: AT+CREG? +CREG: 0,1 OK
2013-05-28 06:02:45,7, GSM1: -> AT
2013-05-28 06:02:45,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:45,7, GSM1: <- AT OK
2013-05-28 06:02:45,6, GSM1: Pre-initializing modem
2013-05-28 06:02:46,7, GSM1: -> ATE0+CMEE=1
2013-05-28 06:02:46,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:46,7, GSM1: <- ATE0+CMEE=1 OK
2013-05-28 06:02:46,6, GSM1: Checking if modem needs PIN
2013-05-28 06:02:46,7, GSM1: -> AT+CPIN?
2013-05-28 06:02:46,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:47,7, GSM1: <- +CPIN: READY OK
2013-05-28 06:02:47,6, GSM1: Initializing modem
2013-05-28 06:02:47,7, GSM1: -> ATZ
2013-05-28 06:02:47,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:47,7, GSM1: <- OK
2013-05-28 06:02:47,7, GSM1: -> AT+CNMI=2,0,0,2,1
2013-05-28 06:02:47,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:48,7, GSM1: <- AT+CNMI=2,0,0,2,1 OK
2013-05-28 06:02:48,7, GSM1: -> AT+CSQ
2013-05-28 06:02:48,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:48,7, GSM1: <- AT+CSQ +CSQ: 21,99 OK
2013-05-28 06:02:48,6, GSM1: Checking if Modem is registered to the network
2013-05-28 06:02:48,7, GSM1: -> AT+CREG?
2013-05-28 06:02:48,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:49,7, GSM1: <- AT+CREG? +CREG: 0,1 OK
2013-05-28 06:02:49,6, GSM1: Modem is registered to the network
2013-05-28 06:02:49,6, GSM1: Selecting PDU mode
2013-05-28 06:02:49,7, GSM1: -> AT+CMGF=0
2013-05-28 06:02:49,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:49,7, GSM1: <- AT+CMGF=0 OK
2013-05-28 06:02:49,7, GSM1: -> AT+CIMI
2013-05-28 06:02:49,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:50,7, GSM1: <- AT+CIMI 262029023831401 OK
2013-05-28 06:02:50,7, GSM1: -> AT+CGSN
2013-05-28 06:02:50,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:50,7, GSM1: <- AT+CGSN 356613020064804 OK
2013-05-28 06:02:50,5, GSM1: CGSN: 356613020064804
2013-05-28 06:02:50,5, GSM1: IMSI: 262029023831401
2013-05-28 06:02:50,6, GSM1: Checking if reading of messages is supported
2013-05-28 06:02:51,7, GSM1: -> AT+CPMS?
2013-05-28 06:02:51,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:51,7, GSM1: <- AT+CPMS? +CPMS: "SM",0,20,"MT",16,45,"MT",16,45 OK
2013-05-28 06:02:51,6, GSM1: Checking memory size
2013-05-28 06:02:51,7, GSM1: -> AT+CPMS?
2013-05-28 06:02:51,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:02:51,7, GSM1: <- AT+CPMS? +CPMS: "SM",0,20,"MT",16,45,"MT",16,45 OK


2013-05-28 06:03:22,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:23,7, GSM1: <- AT+CPMS? +CPMS: "SM",0,20,"MT",16,45,"MT",16,45 OK
2013-05-28 06:03:23,6, GSM1: Used memory is 0 of 20
2013-05-28 06:03:23,6, GSM1: No SMS received
2013-05-28 06:03:23,6, GSM1: Checking if concatenation storage has expired message parts
2013-05-28 06:03:23,6, GSM1: I have to send 1 short message for /var/spool/sms/checked/4375.sms
2013-05-28 06:03:23,6, GSM1: Sending SMS from to 4915161301322
2013-05-28 06:03:23,6, GSM1: Checking if modem is ready
2013-05-28 06:03:23,7, GSM1: -> AT
2013-05-28 06:03:23,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:23,7, GSM1: <- AT OK
2013-05-28 06:03:23,6, GSM1: Pre-initializing modem
2013-05-28 06:03:23,7, GSM1: -> ATE0+CMEE=1
2013-05-28 06:03:24,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:24,7, GSM1: <- ATE0+CMEE=1 OK
2013-05-28 06:03:24,6, GSM1: Initializing modem
2013-05-28 06:03:24,7, GSM1: -> ATZ
2013-05-28 06:03:24,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:24,7, GSM1: <- OK
2013-05-28 06:03:25,7, GSM1: -> AT+CNMI=2,0,0,2,1
2013-05-28 06:03:25,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:25,7, GSM1: <- AT+CNMI=2,0,0,2,1 OK
2013-05-28 06:03:25,7, GSM1: -> AT+CSQ
2013-05-28 06:03:25,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:25,7, GSM1: <- AT+CSQ +CSQ: 21,99 OK
2013-05-28 06:03:25,6, GSM1: Checking if Modem is registered to the network
2013-05-28 06:03:26,7, GSM1: -> AT+CREG?
2013-05-28 06:03:26,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:26,7, GSM1: <- AT+CREG? +CREG: 0,1 OK
2013-05-28 06:03:26,6, GSM1: Modem is registered to the network
2013-05-28 06:03:26,6, GSM1: Selecting PDU mode
2013-05-28 06:03:26,7, GSM1: -> AT+CMGF=0
2013-05-28 06:03:26,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:27,7, GSM1: <- AT+CMGF=0 OK
2013-05-28 06:03:27,7, GSM1: -> AT+CMGS=17
2013-05-28 06:03:27,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:27,7, GSM1: <- AT+CMGS=17 >
2013-05-28 06:03:27,7, GSM1: -> 0031000D91945161311023F20000FF026A35^Z
2013-05-28 06:03:28,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:34,7, GSM1: <- 0031000D91945161311023F20000FF026A35^Z +CMGS: 10 OK
2013-05-28 06:03:34,5, GSM1: SMS sent, Message_id: 10, To: 4915161301322, sending time 11 sec.
2
...
2013-05-28 06:03:45,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:45,7, GSM1: <- AT+CREG? +CREG: 0,1 OK
2013-05-28 06:03:45,6, GSM1: Modem is registered to the network
2013-05-28 06:03:45,6, GSM1: Selecting PDU mode
2013-05-28 06:03:45,7, GSM1: -> AT+CMGF=0
2013-05-28 06:03:45,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:45,7, GSM1: <- AT+CMGF=0 OK
2013-05-28 06:03:45,6, GSM1: Checking memory size
2013-05-28 06:03:46,7, GSM1: -> AT+CPMS?
2013-05-28 06:03:46,7, GSM1: Command is sent, waiting for the answer
2013-05-28 06:03:46,7, GSM1: <- AT+CPMS? +CPMS: "SM",0,20,"MT",17,45,"MT",17,45 OK
2013-05-28 06:03:46,6, GSM1: Used memory is 0 of 20
2013-05-28 06:03:46,6, GSM1: No SMS received
2