I'm using Kannel as an SMS gateway to send and receive SMS messages. I have downloaded, installed, and configured Kannel according to the document guided. I can send an SMS by typing http://localhost:13013/cgi-bin/sendsms?username=tester&password=foobar&from="from number"&to="to number"&text=Testing in a browser. However, when I send an SMS from a phone to the gateway, I got the error ERROR: request failed.
I'm using Kannel 1.4.3 installed on Ubuntu 10.04 LTS. I use a wavecom modem whose model is WAVECOM FASTRACK type DUAL BRANCH MODEM connected to kannel via serial port.
Should you need further information, please let me know.
I'm really thankful for your help.
Kannel.conf
group = core
admin-port = 13000
admin-password = bar
smsbox-port = 13001
smsbox-port-ssl = false
log-file = "/tmp/kannel.log"
log-level = 0
access-log = "/home/sambath/kannel/access.log"
access-log-clean = true
# SMSC GSM
group = smsc
smsc = at
smsc-id = abc
modemtype = wavecom
device = /dev/ttyUSB0
pin = 0000
alt-charset = "ASCII"
group = modems
id = wavecom
name = "wavecom"
detect-string = "wavecom"
message-storage = sm
speed = 115200
# SMSBOX SETUP
group = smsbox
bearerbox-host = localhost
sendsms-port = 13013
sendsms-chars = "0123456789 +-"
log-file = "/tmp/smsbox.log"
#log-level = 0
access-log = "/home/sambath/kannel/access.log"
mo-recode = true
# SEND-SMS USERS
group = sendsms-user
username = tester
password = foobar
access.log
2010-10-04 14:36:30 Log begins
Receive SMS [SMSC:abc] [SVC:] [ACT:] [BINF:] [FID:] [from:+85516635262] [to:1234] [flags:-1:0:-1:0:-1] [msg:5:Hello] [udh:0:]
Sent SMS [SMSC:abc] [SVC:] [ACT:] [BINF:] [FID:] [from:1234] [to:+85516635262] [flags:-1:0:-1:-1:-1] [msg:14:Request Failed] [udh:0:]
2010-10-04 14:36:55 Log ends
Receive SMS [SMSC:abc] [SVC:] [ACT:] [BINF:] [FID:] [from:+85516635262] [to:1234] [flags:0:0:-1:0:-1] [msg:113:Your message on <04/10/10,14:36> has been received by +85516635262 on <04/10/10,14:36> Thank you for using hello.] [udh:0:]
kannel.log
2010-10-04 14:36:15 [2524] [0] INFO: Added logfile `/tmp/kannel.log' with level `0'.
2010-10-04 14:36:15 [2524] [0] INFO: Started access logfile `/home/sambath/kannel/access.log'.
2010-10-04 14:36:15 [2524] [0] INFO: SSL not supported, no SSL initialization done.
2010-10-04 14:36:15 [2524] [0] INFO: HTTP: Opening server at port 13000.
2010-10-04 14:36:15 [2524] [0] DEBUG: Started thread 1 (gwlib/fdset.c:poller)
2010-10-04 14:36:15 [2524] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) maps to pid 2524.
2010-10-04 14:36:15 [2524] [0] DEBUG: Started thread 2 (gwlib/http.c:server_thread)
2010-10-04 14:36:15 [2524] [2] DEBUG: Thread 2 (gwlib/http.c:server_thread) maps to pid 2524.
2010-10-04 14:36:15 [2524] [0] DEBUG: Started thread 3 (gw/bb_http.c:httpadmin_run)
2010-10-04 14:36:15 [2524] [3] DEBUG: Thread 3 (gw/bb_http.c:httpadmin_run) maps to pid 2524.
2010-10-04 14:36:15 [2524] [0] DEBUG: starting smsbox connection module
2010-10-04 14:36:15 [2524] [0] INFO: BOXC: 'smsbox-max-pending' not set, using default (100).
2010-10-04 14:36:15 [2524] [0] DEBUG: Started thread 4 (gw/bb_boxc.c:sms_to_smsboxes)
2010-10-04 14:36:15 [2524] [4] DEBUG: Thread 4 (gw/bb_boxc.c:sms_to_smsboxes) maps to pid 2524.
2010-10-04 14:36:15 [2524] [0] DEBUG: Started thread 5 (gw/bb_boxc.c:smsboxc_run)
2010-10-04 14:36:15 [2524] [5] DEBUG: Thread 5 (gw/bb_boxc.c:smsboxc_run) maps to pid 2524.
2010-10-04 14:36:15 [2524] [0] INFO: Set SMS resend frequency to 60 seconds.
2010-10-04 14:36:15 [2524] [0] INFO: SMS resend retry set to unlimited.
2010-10-04 14:36:15 [2524] [0] DEBUG: smsbox MO concatenated message handling enabled
2010-10-04 14:36:15 [2524] [0] INFO: DLR rerouting for smsc id <abc> disabled.
2010-10-04 14:36:15 [2524] [0] INFO: AT2[abc]: configuration shows modemtype <wavecom>
2010-10-04 14:36:15 [2524] [0] DEBUG: AT2[abc]: Reading modem definitions from <kannel.conf>
2010-10-04 14:36:15 [2524] [0] DEBUG: AT2[abc]: Found <1> modems in config
2010-10-04 14:36:15 [2524] [0] INFO: AT2[abc]: read modem definition for <wavecom>
2010-10-04 14:36:15 [2524] [0] DEBUG: Started thread 6 (gw/smsc/smsc_at.c:at2_device_thread)
2010-10-04 14:36:15 [2524] [6] DEBUG: Thread 6 (gw/smsc/smsc_at.c:at2_device_thread) maps to pid 2524.
2010-10-04 14:36:15 [2524] [0] DEBUG: Started thread 7 (gw/bb_smscconn.c:sms_router)
2010-10-04 14:36:15 [2524] [6] INFO: AT2[abc]: trying to use speed <115200> from modem definition
2010-10-04 14:36:15 [2524] [7] DEBUG: Thread 7 (gw/bb_smscconn.c:sms_router) maps to pid 2524.
2010-10-04 14:36:15 [2524] [0] INFO: ----------------------------------------
2010-10-04 14:36:15 [2524] [6] INFO: AT2[abc]: opening device
2010-10-04 14:36:15 [2524] [0] INFO: Kannel bearerbox II version 1.4.3 starting
2010-10-04 14:36:15 [2524] [0] INFO: MAIN: Start-up done, entering mainloop
2010-10-04 14:36:15 [2524] [0] DEBUG: AT2[abc]: start called
2010-10-04 14:36:15 [2524] [6] DEBUG: AT2[abc]: device opened. Telnet mode = 0
2010-10-04 14:36:15 [2524] [6] DEBUG: AT2[abc]: device opened
2010-10-04 14:36:15 [2524] [6] INFO: AT2[abc]: speed set to 115200
2010-10-04 14:36:15 [2524] [6] DEBUG: AT2[abc]: --> ^M
2010-10-04 14:36:17 [2524] [6] DEBUG: AT2[abc]: --> AT^M
2010-10-04 14:36:17 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:17 [2524] [6] INFO: AT2[abc]: Closing device
2010-10-04 14:36:17 [2524] [6] INFO: AT2[abc]: speed is 115200
2010-10-04 14:36:17 [2524] [6] INFO: AT2[abc]: opening device
2010-10-04 14:36:17 [2524] [6] DEBUG: AT2[abc]: device opened. Telnet mode = 0
2010-10-04 14:36:17 [2524] [6] DEBUG: AT2[abc]: device opened
2010-10-04 14:36:17 [2524] [6] INFO: AT2[abc]: Logging in
2010-10-04 14:36:17 [2524] [6] INFO: AT2[abc]: init device
2010-10-04 14:36:17 [2524] [6] INFO: AT2[abc]: speed set to 115200
2010-10-04 14:36:17 [2524] [6] DEBUG: AT2[abc]: --> ATZ^M
2010-10-04 14:36:17 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:17 [2524] [6] DEBUG: AT2[abc]: --> AT^M
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- AT
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: --> AT&F^M
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- AT&F
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: --> ATE0^M
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- ATE0
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: --> AT+IFC=2,2^M
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: --> AT+CPIN?^M
2010-10-04 14:36:18 [2524] [6] DEBUG: AT2[abc]: <-- +CPIN: READY
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: --> AT+CMGF=0^M
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: --> AT+CSMS=?^M
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: <-- +CSMS: (0,1)
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:29 [2524] [6] INFO: AT2[abc]: Phase 2+ is supported
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: --> AT+CSMS=1^M
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: <-- +CSMS: 1,1,1
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: --> AT+CNMI=1,2,0,1,0^M
2010-10-04 14:36:29 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:29 [2524] [6] INFO: AT2[abc]: AT SMSC successfully opened.
2010-10-04 14:36:30 [2524] [5] INFO: Client connected from <127.0.0.1>
2010-10-04 14:36:30 [2524] [5] DEBUG: Started thread 8 (gw/bb_boxc.c:function)
2010-10-04 14:36:30 [2524] [8] DEBUG: Thread 8 (gw/bb_boxc.c:function) maps to pid 2524.
2010-10-04 14:36:30 [2524] [8] DEBUG: Started thread 9 (gw/bb_boxc.c:boxc_sender)
2010-10-04 14:36:30 [2524] [9] DEBUG: Thread 9 (gw/bb_boxc.c:boxc_sender) maps to pid 2524.
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: <-- +CMT: ,24
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: <-- 07915815860000F0240B915815665362F200000101404163218205C8329BFD06
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: received message from SMSC: +85516800000
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: Numeric sender (international) <+85516635262>
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: User data length read as (5)
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: Udh decoding done len=5 udhi=0 udhlen=0 udh=''
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: --> AT+CNMA^M
2010-10-04 14:36:46 [2524] [9] DEBUG: send_msg: sending msg to box: <127.0.0.1>
2010-10-04 14:36:46 [2524] [9] DEBUG: boxc_sender: sent message to <127.0.0.1>
2010-10-04 14:36:46 [2524] [8] DEBUG: boxc_receiver: sms received
2010-10-04 14:36:46 [2524] [8] DEBUG: send_msg: sending msg to box: <127.0.0.1>
2010-10-04 14:36:46 [2524] [8] DEBUG: boxc_receiver: got ack
2010-10-04 14:36:46 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:47 [2524] [6] DEBUG: AT2[abc]: TP-Validity-Period: 24.0 hours
2010-10-04 14:36:47 [2524] [6] DEBUG: AT2[abc]: --> AT+CMGS=27^M
2010-10-04 14:36:47 [2524] [6] DEBUG: AT2[abc]: <-- >
2010-10-04 14:36:47 [2524] [6] DEBUG: AT2[abc]: send command status: 1
2010-10-04 14:36:47 [2524] [6] DEBUG: AT2[abc]: --> 0011000B915815665362F20000A70ED272BC5E9ED341C6709A5D2603
2010-10-04 14:36:47 [2524] [6] DEBUG: AT2[abc]: --> ^Z
2010-10-04 14:36:49 [2524] [6] DEBUG: AT2[abc]: <-- >
2010-10-04 14:36:49 [2524] [6] DEBUG: AT2[abc]: <-- +CMGS: 122
2010-10-04 14:36:49 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:36:49 [2524] [6] DEBUG: AT2[abc]: send command status: 0
2010-10-04 14:36:55 [2524] [8] DEBUG: boxc_receiver: heartbeat with load value 0 received
2010-10-04 14:36:55 [2524] [8] INFO: Connection closed by the box <127.0.0.1>
2010-10-04 14:36:55 [2524] [9] DEBUG: send_msg: sending msg to box: <127.0.0.1>
2010-10-04 14:36:55 [2524] [9] DEBUG: Thread 9 (gw/bb_boxc.c:boxc_sender) terminates.
2010-10-04 14:36:55 [2524] [8] DEBUG: Thread 8 (gw/bb_boxc.c:function) terminates.
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: <-- +CMT: ,118
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: <-- 07915815860000F0040B915815665362F200100101404163328271D9775D0E6A97E7F3F0B90C7ABB413C18ED1583BD6230568CA69BD97C2074780E1297CB6E90BC3C2EA7ED6532489C07AD70B55ACC669BD5643619E8ED06F160B4570CF68AC158319A6E66F381A8E8B07B0DCABFEB20F35B0EAACFD3EE33085D66B3DF2E
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: received message from SMSC: +85516800000
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: Numeric sender (international) <+85516635262>
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: User data length read as (113)
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: Udh decoding done len=113 udhi=0 udhlen=0 udh=''
2010-10-04 14:36:58 [2524] [6] WARNING: smsbox_list empty!
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: --> AT+CNMA^M
2010-10-04 14:36:58 [2524] [4] WARNING: smsbox_list empty!
2010-10-04 14:36:58 [2524] [4] WARNING: smsbox_list empty!
2010-10-04 14:36:58 [2524] [6] DEBUG: AT2[abc]: <-- OK
2010-10-04 14:37:02 [2524] [2] DEBUG: HTTP: Creating HTTPClient for `127.0.0.1'.
2010-10-04 14:37:02 [2524] [2] DEBUG: HTTP: Created HTTPClient area 0x957b368.
2010-10-04 14:37:02 [2524] [3] DEBUG: Shutting down Kannel...
2010-10-04 14:37:02 [2524] [3] DEBUG: shutting down smsc
2010-10-04 14:37:02 [2524] [3] DEBUG: AT2[abc]: Shutting down SMSCConn, slow
2010-10-04 14:37:02 [2524] [3] DEBUG: shutting down udp
2010-10-04 14:37:02 [2524] [3] DEBUG: HTTP: Resetting HTTPClient for `127.0.0.1'.
2010-10-04 14:37:02 [2524] [0] WARNING: Killing signal or HTTP admin command received, shutting down...
2010-10-04 14:37:03 [2524] [6] INFO: AT2[abc]: Closing device
2010-10-04 14:37:03 [2524] [6] DEBUG: Thread 6 (gw/smsc/smsc_at.c:at2_device_thread) terminates.
2010-10-04 14:37:12 [2524] [7] DEBUG: Thread 7 (gw/bb_smscconn.c:sms_router) terminates.
2010-10-04 14:37:12 [2524] [4] DEBUG: Thread 4 (gw/bb_boxc.c:sms_to_smsboxes) terminates.
2010-10-04 14:37:12 [2524] [5] DEBUG: Thread 5 (gw/bb_boxc.c:smsboxc_run) terminates.
2010-10-04 14:37:12 [2524] [0] INFO: All flow threads have died, killing core
2010-10-04 14:37:12 [2524] [0] DEBUG: Waiting for 2 (gwlib/http.c:server_thread) to terminate
2010-10-04 14:37:12 [2524] [3] DEBUG: HTTP: No clients with requests, quitting.
2010-10-04 14:37:12 [2524] [3] DEBUG: Thread 3 (gw/bb_http.c:httpadmin_run) terminates.
2010-10-04 14:37:12 [2524] [2] DEBUG: HTTP: Destroying HTTPClient area 0x957b368.
2010-10-04 14:37:12 [2524] [2] DEBUG: HTTP: Destroying HTTPClient for `127.0.0.1'.
2010-10-04 14:37:12 [2524] [2] DEBUG: Thread 2 (gwlib/http.c:server_thread) terminates.
2010-10-04 14:37:12 [2524] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) terminates.
2010-10-04 14:37:12 [2524] [0] DEBUG: final clean-up for SMSCConn
2010-10-04 14:37:12 [2524] [0] DEBUG: smsbox MO concatenated message handling cleaned up
2010-10-04 14:37:12 [2524] [0] INFO: Total WDP messages: received 0, sent 0
2010-10-04 14:37:12 [2524] [0] DEBUG: Remaining SMS: 1 incoming, 0 outgoing
2010-10-04 14:37:12 [2524] [0] INFO: Total SMS messages: received 2, sent 1
2010-10-04 14:37:12 [2524] [0] DEBUG: Immutable octet strings: 230.
**smsbox.log**
2010-10-04 14:36:30 [2535] [0] INFO: Added logfile `/tmp/smsbox.log' with level `0'.
2010-10-04 14:36:30 [2535] [0] INFO: Logging accesses to '/home/sambath/kannel/access.log'.
2010-10-04 14:36:30 [2535] [0] INFO: Started access logfile `/home/sambath/kannel/access.log'.
2010-10-04 14:36:30 [2535] [0] INFO: HTTP: Opening server at port 13013.
2010-10-04 14:36:30 [2535] [0] DEBUG: Started thread 1 (gwlib/fdset.c:poller)
2010-10-04 14:36:30 [2535] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) maps to pid 2535.
2010-10-04 14:36:30 [2535] [0] DEBUG: Started thread 2 (gwlib/http.c:server_thread)
2010-10-04 14:36:30 [2535] [2] DEBUG: Thread 2 (gwlib/http.c:server_thread) maps to pid 2535.
2010-10-04 14:36:30 [2535] [0] INFO: Set up send sms service at port 13013
2010-10-04 14:36:30 [2535] [0] DEBUG: Started thread 3 (gw/smsbox.c:sendsms_thread)
2010-10-04 14:36:30 [2535] [3] DEBUG: Thread 3 (gw/smsbox.c:sendsms_thread) maps to pid 2535.
2010-10-04 14:36:30 [2535] [0] DEBUG: ----------------------------------------------
2010-10-04 14:36:30 [2535] [0] DEBUG: Kannel smsbox version 1.4.3 starting
2010-10-04 14:36:30 [2535] [0] DEBUG: dumping group (sendsms-user):
2010-10-04 14:36:30 [2535] [0] DEBUG: <group> = <sendsms-user>
2010-10-04 14:36:30 [2535] [0] DEBUG: <username> = <tester>
2010-10-04 14:36:30 [2535] [0] DEBUG: <password> = <foobar>
2010-10-04 14:36:30 [2535] [0] DEBUG: Started thread 4 (gw/smsbox.c:obey_request_thread)
2010-10-04 14:36:30 [2535] [4] DEBUG: Thread 4 (gw/smsbox.c:obey_request_thread) maps to pid 2535.
2010-10-04 14:36:30 [2535] [0] DEBUG: Started thread 5 (gw/smsbox.c:url_result_thread)
2010-10-04 14:36:30 [2535] [5] DEBUG: Thread 5 (gw/smsbox.c:url_result_thread) maps to pid 2535.
2010-10-04 14:36:30 [2535] [0] DEBUG: Started thread 6 (gw/smsbox.c:http_queue_thread)
2010-10-04 14:36:30 [2535] [6] DEBUG: Thread 6 (gw/smsbox.c:http_queue_thread) maps to pid 2535.
2010-10-04 14:36:30 [2535] [0] INFO: Connected to bearerbox at localhost port 13001.
2010-10-04 14:36:30 [2535] [0] DEBUG: Started thread 7 (gw/heartbeat.c:heartbeat_thread)
2010-10-04 14:36:30 [2535] [7] DEBUG: Thread 7 (gw/heartbeat.c:heartbeat_thread) maps to pid 2535.
2010-10-04 14:36:46 [2535] [4] WARNING: No translation found for <Hello> from <+85516635262> to <1234>
**2010-10-04 14:36:46 [2535] [4] ERROR: request failed**
2010-10-04 14:36:46 [2535] [4] DEBUG: message length 14, sending 1 messages
2010-10-04 14:36:46 [2535] [0] DEBUG: Got ACK (0) of 51b64a81-5f2a-488c-8cd8-9649b7cc9e0c
2010-10-04 14:36:46 [2535] [0] DEBUG: No client - multi-send or ACK to pull-reply
2010-10-04 14:36:55 [2535] [0] ERROR: SIGINT received, aborting program...
2010-10-04 14:36:55 [2535] [0] INFO: Received (and handled?) 1 requests in 9 seconds (0.11 per second)
2010-10-04 14:36:55 [2535] [0] INFO: Kannel smsbox terminating.
2010-10-04 14:36:55 [2535] [7] DEBUG: Thread 7 (gw/heartbeat.c:heartbeat_thread) terminates.
2010-10-04 14:36:55 [2535] [0] DEBUG: Waiting for 2 (gwlib/http.c:server_thread) to terminate
2010-10-04 14:36:55 [2535] [3] DEBUG: HTTP: No clients with requests, quitting.
2010-10-04 14:36:55 [2535] [3] DEBUG: Thread 3 (gw/smsbox.c:sendsms_thread) terminates.
2010-10-04 14:36:55 [2535] [2] DEBUG: Thread 2 (gwlib/http.c:server_thread) terminates.
2010-10-04 14:36:55 [2535] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) terminates.
2010-10-04 14:36:55 [2535] [0] DEBUG: Waiting for 4 (gw/smsbox.c:obey_request_thread) to terminate
2010-10-04 14:36:55 [2535] [4] DEBUG: Thread 4 (gw/smsbox.c:obey_request_thread) terminates.
2010-10-04 14:36:55 [2535] [6] DEBUG: Thread 6 (gw/smsbox.c:http_queue_thread) terminates.
2010-10-04 14:36:55 [2535] [0] DEBUG: Waiting for 5 (gw/smsbox.c:url_result_thread) to terminate
2010-10-04 14:36:55 [2535] [5] DEBUG: Thread 5 (gw/smsbox.c:url_result_thread) terminates.
2010-10-04 14:36:55 [2535] [0] DEBUG: Immutable octet strings: 162.
I think u may have missing SMS-service configurations
# Test
group = sms-service
keyword = default
text = "This is a reply"
max-messages = 1