Operating system name and version: Linux localhost 2.6.32-22-generic #36-Ubuntu SMP Thu Jun 3 19:31:57 UTC 2010 x86_64 GNU/Linux
Version of smsd: Version 3.1.6
Smsd installed from: package repository
Name and model of a modem / phone: ID 12d1:1003 Huawei Technologies Co., Ltd. E220 HSDPA Modem / E270 HSDPA/HSUPA Modem, ID 1199:6813 Sierra Wireless, Inc.
Interface: USB

I'm testing with two usb 3G modems, Huawei external and Sierra Wireless integrated chip.

Both modems seem to initialize fine (see log below), but sending a message fails with strange error. It looks like smsd might be getting garbage from the modem, at least according to the log? But strangely both devices work similarly...

2010-06-23 17:38:36,5, smsd: Moved file /var/spool/sms/outgoing/testi12 to /var/spool/sms/checked 2010-06-23 17:38:37,6, GSM1: I have to send 1 short message for /var/spool/sms/checked/testi12 2010-06-23 17:38:37,6, GSM1: Sending SMS from to 358405227911 2010-06-23 17:38:37,6, GSM1: Checking if modem is ready 2010-06-23 17:38:37,7, GSM1: -> AT 2010-06-23 17:38:37,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:38,7, GSM1: <- O 2010-06-23 17:38:38,7, GSM1: -> . 2010-06-23 17:38:38,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:43,7, GSM1: put_command expected (OK)|(ERROR), timeout occurred. 1.

That . in the log file is actually ascii code 0x1a but the forum mangles it to a dot. What does 1a do there?

This is the message file:
To: 358405227911 Testataan taas..

I am able to send SMS using minicom with simple AT commands (AT+CMGF=1, AT+CMGS="+358405227911").

dmesg:
[474918.579303] usb 6-1: Sierra USB modem converter now attached to ttyUSB0 [474918.579414] usb 6-1: Sierra USB modem converter now attached to ttyUSB1 [474918.579573] usb 6-1: Sierra USB modem converter now attached to ttyUSB2 [483105.247426] option 5-2:1.0: GSM modem (1-port) converter detected [483105.247590] usb 5-2: GSM modem (1-port) converter now attached to ttyUSB3 [483105.259188] option 5-2:1.1: GSM modem (1-port) converter detected [483105.259340] usb 5-2: GSM modem (1-port) converter now attached to ttyUSB4

lsusb:
Bus 006 Device 015: ID 1199:6813 Sierra Wireless, Inc. Bus 005 Device 017: ID 12d1:1003 Huawei Technologies Co., Ltd. E220 HSDPA Modem / E270 HSDPA/HSUPA Modem

/etc/smsd.conf:
devices = GSM1 outgoing = /var/spool/sms/outgoing checked = /var/spool/sms/checked incoming = /var/spool/sms/incoming logfile = /var/log/smstools/smsd.log infofile = /var/run/smstools/smsd.working pidfile = /var/run/smstools/smsd.pid outgoing = /var/spool/sms/outgoing checked = /var/spool/sms/checked failed = /var/spool/sms/failed incoming = /var/spool/sms/incoming sent = /var/spool/sms/sent stats = /var/log/smstools/smsd_stats loglevel = 7 autosplit = 3 [GSM1] init2 = AT+CSQ device = /dev/ttyUSB3 check_network = yes incoming = no report = yes

/var/log/smstools/smsd.log:
2010-06-23 17:36:35,2, smsd: Smsd v3.1.6 started. 2010-06-23 17:36:35,2, smsd: Running as smsd:dialout. 2010-06-23 17:36:35,7, smsd: Running startup_check (shell): /tmp/smsd_script.dk4p6p /tmp/smsd_data.p6AGks 2010-06-23 17:36:35,7, smsd: Done: startup_check (shell), execution time 0 sec., status: 0 (0) 2010-06-23 17:36:35,4, smsd: File mode creation mask: 022 (0644, rw-r--r--). 2010-06-23 17:36:35,5, smsd: Outgoing file checker has started. PID: 27243. 2010-06-23 17:36:35,5, GSM1: Modem handler 0 has started. PID: 27244. Will only send messages. 2010-06-23 17:36:35,4, GSM1: Cannot receive status reports because receiving is disabled on modem GSM1 2010-06-23 17:36:35,5, GSM1: Using check_memory_method 1: CPMS is used. 2010-06-23 17:36:35,6, GSM1: Checking if modem is ready 2010-06-23 17:36:35,7, GSM1: -> AT 2010-06-23 17:36:35,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:36,7, GSM1: <- AT OK 2010-06-23 17:36:36,6, GSM1: Pre-initializing modem 2010-06-23 17:36:36,7, GSM1: -> ATE0+CMEE=1 2010-06-23 17:36:36,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:36,7, GSM1: <- ATE0+CMEE=1 OK 2010-06-23 17:36:36,6, GSM1: Checking if modem needs PIN 2010-06-23 17:36:36,7, GSM1: -> AT+CPIN? 2010-06-23 17:36:36,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:37,7, GSM1: <- +CPIN: READY OK 2010-06-23 17:36:37,6, GSM1: Initializing modem 2010-06-23 17:36:37,7, GSM1: -> AT+CSQ 2010-06-23 17:36:37,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:37,7, GSM1: <- +CSQ: 21,99 OK 2010-06-23 17:36:37,5, GSM1: Signal Strength Indicator: (21,99) -71 dBm, Bit Error Rate: not known or not detectable 2010-06-23 17:36:37,7, GSM1: -> AT+CSQ 2010-06-23 17:36:37,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:38,7, GSM1: <- +CSQ: 21,99 OK 2010-06-23 17:36:38,6, GSM1: Checking if Modem is registered to the network 2010-06-23 17:36:38,7, GSM1: -> AT+CREG? 2010-06-23 17:36:38,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:38,7, GSM1: <- +CREG: 0,1 OK 2010-06-23 17:36:38,6, GSM1: Modem is registered to the network 2010-06-23 17:36:38,6, GSM1: Selecting PDU mode 2010-06-23 17:36:38,7, GSM1: -> AT+CMGF=0 2010-06-23 17:36:38,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:39,7, GSM1: <- O 2010-06-23 17:36:39,7, GSM1: -> AT+CMGF=0 2010-06-23 17:36:39,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:39,7, GSM1: <- O 2010-06-23 17:36:39,7, GSM1: -> AT+CIMI 2010-06-23 17:36:39,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:40,7, GSM1: <- 244052160776725 OK 2010-06-23 17:36:40,7, GSM1: -> AT+CGSN 2010-06-23 17:36:40,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:40,7, GSM1: <- 354137026839102 OK 2010-06-23 17:36:40,5, GSM1: CGSN: 354137026839102 2010-06-23 17:36:40,5, GSM1: IMSI: 244052160776725 2010-06-23 17:36:40,6, GSM1: Checking if reading of messages is supported 2010-06-23 17:36:40,7, GSM1: -> AT+CPMS? 2010-06-23 17:36:40,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:36:41,7, GSM1: <- +CPMS: "SM",0,50,"SM",0,50,"SM",0,50 OK 2010-06-23 17:36:41,5, GSM1: Waiting for messages to send...

... after sending message:

2010-06-23 17:38:36,5, smsd: Moved file /var/spool/sms/outgoing/testi12 to /var/spool/sms/checked 2010-06-23 17:38:37,6, GSM1: I have to send 1 short message for /var/spool/sms/checked/testi12 2010-06-23 17:38:37,6, GSM1: Sending SMS from to 358405227911 2010-06-23 17:38:37,6, GSM1: Checking if modem is ready 2010-06-23 17:38:37,7, GSM1: -> AT 2010-06-23 17:38:37,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:38,7, GSM1: <- O 2010-06-23 17:38:38,7, GSM1: -> . 2010-06-23 17:38:38,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:43,7, GSM1: put_command expected (OK)|(ERROR), timeout occurred. 1. 2010-06-23 17:38:43,7, GSM1: <- 2010-06-23 17:38:43,7, GSM1: -> AT 2010-06-23 17:38:43,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:43,7, GSM1: <- O 2010-06-23 17:38:43,7, GSM1: -> . 2010-06-23 17:38:43,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:48,7, GSM1: put_command expected (OK)|(ERROR), timeout occurred. 1. 2010-06-23 17:38:48,7, GSM1: <- 2010-06-23 17:38:49,7, GSM1: -> AT 2010-06-23 17:38:49,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:49,7, GSM1: <- O 2010-06-23 17:38:49,7, GSM1: -> . 2010-06-23 17:38:49,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:54,7, GSM1: put_command expected (OK)|(ERROR), timeout occurred. 1. 2010-06-23 17:38:54,7, GSM1: <- 2010-06-23 17:38:54,7, GSM1: -> AT 2010-06-23 17:38:54,7, GSM1: Command is sent, waiting for the answer 2010-06-23 17:38:55,7, GSM1: <- O 2010-06-23 17:38:55,7, GSM1: -> . 2010-06-23 17:38:55,7, GSM1: Command is sent, waiting for the answer

Any ideas what might be the problem?

kortsi wrote

Any ideas what might be the problem?

It's the "overlapped buffers" bug which was found and fixed one week ago. In the version 3.1.9: "When manipulating strings, the coding style assumed that strcpy() and some other functions start copying from the begin of a buffer. That's how those have worked for years, but it's against what the manual of those functions says about overlapped buffers. With 64bit Ubuntu 10.04 running on Intel processor this caused serious failures. The code is reviewed and fixed. "

You need to download and compile the latest version 3.1.11.

Debian has already packaged the version 3.1.10, but I do not know when that is available as an Ubuntu package.

keke wrote

kortsi wrote

Any ideas what might be the problem?

It's the "overlapped buffers" bug which was found and fixed one week ago. In the version 3.1.9: "When manipulating strings, the coding style assumed that strcpy() and some other functions start copying from the begin of a buffer. That's how those have worked for years, but it's against what the manual of those functions says about overlapped buffers. With 64bit Ubuntu 10.04 running on Intel processor this caused serious failures. The code is reviewed and fixed. "

You need to download and compile the latest version 3.1.11.

Debian has already packaged the version 3.1.10, but I do not know when that is available as an Ubuntu package.

I figured something like this. Oh well, guess it is time to use the compiler. Cheers!