Hi Folks,
I would like to ask for your help in this problem. I'm using Kannel 1.2 on
Red Hat 7.3 connecting to a Logica's SMSC through SMPP 3.4. But I've seen
this problem for a logn time.
Firstly I'll describe exactly what I've done and after I'll print the log
lines before restarting Kannel and after restarting Kannel. The problem
happens when Kannel is restarted.
1) My App sent only one sms to kannel with dlrurl=28 (4+8+16 = "Queued on
SMSC"+"Delivered to SMSC""Non-Delivered to SMSC") and with and invalid
destination address ("to" field), intentionally
2) Bearerbox received and SMPP error 0x0000000b (Invalid Destination
Address) and sent it back to My App with type=16 (Non-Delivered to SMSC)
3) My App took charge of the resending process invoking the sendsms again
for some times.
4) When I restarted kannel after the shutdown cgi or though "killall -HUP
bearerbox smsbox" for log rotation purposes, Kannel read the store-file and
tried to send the failed message again
Questions:
1) Why did Kannel resend a unsuccessfull message after it had been
restarted?
2) Why did kannel do it if it had been notified to My Application which is
responsible to do that?
Please, see the Log lines before restarting Kannel:
--- BEARERBOX.LOG ---
2002-08-20 16:51:23 [0] INFO: Added logfile `/home/kannel/log/bearerbox.log'
with level `0'.
2002-08-20 16:51:23 [0] INFO: ----------------------------------------
2002-08-20 16:51:23 [0] INFO: Kannel bearerbox II version 1.2.0 starting
2002-08-20 16:51:23 [0] INFO: Started access logfile
`/home/kannel/log/bearerboxaccess.log'.
2002-08-20 16:51:23 [0] INFO: MAIN: Start-up done, entering mainloop
2002-08-20 16:51:26 [8] INFO: Client connected from <127.0.0.1>
2002-08-20 16:54:02 [6] WARNING: SMPP: PDU NUL terminated string has no NUL.
2002-08-20 16:54:02 [6] ERROR: SMPP[CARRIER]: SMSC returned error code
0x0000000b in response to submit_sm.
2002-08-20 16:54:02 [6] INFO: SMPP[CARRIER]: creating DLR message
2002-08-20 16:54:02 [6] INFO: SMPP[CARRIER]: DLR =
0x0000000b/http://localhost
2002-08-20 16:54:02 [9] DEBUG: boxc_sender: sent message to <127.0.0.1>
2002-08-20 16:54:02 [8] DEBUG: boxc_receiver: got ack
2002-08-20 16:54:02 [1] DEBUG: Dumping 1 messages and 0 acks to store <<<<
LOOK THIS!!!
--- BEARERBOXACCESS.LOG ---
2002-08-20 16:51:23 Log begins
2002-08-20 16:54:02 DLR SMS [SMSC:CARRIER] [SVC:tester] [ACT:]
[from:99999999] [to:000] [flags:0:0:0:0:16]
[msg:22:0x0000000b/http://localhost] [udh:0:]
--- SMSBOX.LOG ---
2002-08-20 16:51:26 [0] INFO: Added logfile `/home/kannel/log/smsbox.log'
with level `0'.
2002-08-20 16:51:26 [0] INFO: Service global sender set as '13013'
2002-08-20 16:51:26 [0] INFO: Logging accesses to
'/home/kannel/log/smsboxaccess.log'.
2002-08-20 16:51:26 [0] INFO: Started access logfile
`/home/kannel/log/smsboxaccess.log'.
2002-08-20 16:51:26 [0] INFO: Set up send sms service at port 13013
2002-08-20 16:51:26 [0] INFO: Connected to bearerbox at localhost port
13001.
2002-08-20 16:54:02 [3] INFO: smsbox: Got HTTP request </cgi-bin/sendsms>
from <xxx.xxx.xxx.xx>
2002-08-20 16:54:02 [3] INFO: sendsms used by <tester>
2002-08-20 16:54:02 [3] INFO: sendsms sender:<tester:1000805001>
(xxx.xxx.xxx.xx) to:<99999999> msg:<TEST>
2002-08-20 16:54:02 [3] DEBUG: message length 4, sending 1 messages
2002-08-20 16:54:02 [3] DEBUG: Status: 202 Answer: <Sent.>
2002-08-20 16:54:02 [4] INFO: Starting delivery report <tester> from
<99999999>
2002-08-20 16:54:02 [8] DEBUG: HTTP: Opening connection to `localhost:80'
(fd=27).
2002-08-20 16:54:02 [8] DEBUG: HTTP: Sending request:
2002-08-20 16:54:02 [8] DEBUG: Octet string at 0x80d8ae8:
2002-08-20 16:54:02 [8] DEBUG: len: 56
2002-08-20 16:54:02 [8] DEBUG: size: 57
2002-08-20 16:54:02 [8] DEBUG: immutable: 0
2002-08-20 16:54:02 [8] DEBUG: data: 47 45 54 20 2f 20 48 54 GET / HT
2002-08-20 16:54:02 [8] DEBUG: data: 54 50 2f 31 2e 31 0d 0a TP/1.1..
2002-08-20 16:54:02 [8] DEBUG: data: 48 6f 73 74 3a 20 77 61 Host: lo
2002-08-20 16:54:02 [8] DEBUG: data: 36 30 0d 0a 55 73 65 72 ca..User
2002-08-20 16:54:02 [8] DEBUG: data: 2d 41 67 65 6e 74 3a 20 -Agent:
2002-08-20 16:54:02 [8] DEBUG: data: 4b 61 6e 6e 65 6c 20 31 Kannel 1
2002-08-20 16:54:02 [8] DEBUG: data: 2e 32 2e 30 0d 0a 0d 0a .2.0....
2002-08-20 16:54:02 [8] DEBUG: Octet string dump ends.
2002-08-20 16:54:02 [7] DEBUG: HTTP: Status line: <HTTP/1.1 200 OK>
--- SMSBOXACCESS.LOG ---
2002-08-20 16:51:26 Log begins
2002-08-20 16:54:02 send-SMS request added - sender:tester:1000805001
xxx.xxx.xxx.xx target:99999999 request: 'TEST'
Now please see additional Log lines after restarting Kannel:
--- BEARERBOX.LOG ---
2002-08-20 17:08:33 [0] INFO: Added logfile `/home/kannel/log/bearerbox.log'
with level `0'.
2002-08-20 17:08:33 [0] INFO: ----------------------------------------
2002-08-20 17:08:33 [0] INFO: Kannel bearerbox II version 1.2.0 starting
2002-08-20 17:08:33 [0] INFO: Started access logfile
`/home/kannel/log/bearerboxaccess.log'.
2002-08-20 17:08:33 [0] DEBUG: Started thread 1
(gw/bb_store.c:store_cleanup)
2002-08-20 17:08:33 [0] DEBUG: HTTP: Opening server at port 13000.
2002-08-20 17:08:33 [0] DEBUG: Started thread 2 (gwlib/fdset.c:poller)
2002-08-20 17:08:33 [0] DEBUG: Started thread 3 (gwlib/http.c:server_thread)
2002-08-20 17:08:33 [0] DEBUG: Started thread 4 (gw/bb_http.c:httpadmin_run)
2002-08-20 17:08:33 [0] DEBUG: starting smsbox connection module
2002-08-20 17:08:33 [0] DEBUG: Started thread 5 (gw/bb_boxc.c:smsboxc_run)
2002-08-20 17:08:33 [0] DEBUG: Started thread 6 (gw/smsc_smpp.c:io_thread)
2002-08-20 17:08:33 [0] DEBUG: Started thread 7
(gw/bb_smscconn.c:sms_router)
2002-08-20 17:08:33 [0] INFO: Loading store file
/home/kannel/store/kannel.store
2002-08-20 17:08:33 [0] INFO: Store-file size 314, starting to unpack
2002-08-20 17:08:33 [0] INFO: Retrieved 1 messages, non-acknowledged
messages: 1
2002-08-20 17:08:33 [0] INFO: MAIN: Start-up done, entering mainloop
2002-08-20 17:08:33 [7] DEBUG: sms_router: time to sleep
2002-08-20 17:08:33 [7] DEBUG: sms_router: list_len = 1
2002-08-20 17:08:33 [7] DEBUG: sms_router: time to sleep
2002-08-20 17:08:34 [7] DEBUG: sms_router: list_len = 1
2002-08-20 17:08:34 [6] DEBUG: SMPP[CARRIER]: Manually forced source addr
ton = 0, source add npi = 3
2002-08-20 17:08:34 [6] DEBUG: SMPP[CARRIER]: Manually forced dest addr ton
= 1, source add npi = 1
2002-08-20 17:08:34 [6] WARNING: SMPP: PDU NUL terminated string has no NUL.
2002-08-20 17:08:34 [6] ERROR: SMPP[CARRIER]: SMSC returned error code
0x0000000b in response to submit_sm.
2002-08-20 17:08:34 [6] INFO: SMPP[CARRIER]: creating DLR message
2002-08-20 17:08:34 [6] INFO: SMPP[CARRIER]: DLR =
0x0000000b/http://localhost
2002-08-20 17:08:44 [5] DEBUG: Started thread 8 (gw/bb_boxc.c:function)
2002-08-20 17:08:44 [8] INFO: Client connected from <127.0.0.1>
2002-08-20 17:08:44 [8] DEBUG: Started thread 9 (gw/bb_boxc.c:boxc_sender)
2002-08-20 17:08:44 [9] DEBUG: boxc_sender: sent message to <127.0.0.1>
2002-08-20 17:08:44 [1] DEBUG: Dumping 1 messages and 0 acks to store
2002-08-20 17:08:44 [8] DEBUG: boxc_receiver: got ack
--- BEARERBOXACCESS.LOG ---
2002-08-20 17:08:33 Log begins
2002-08-20 17:08:34 DLR SMS [SMSC:CARRIER] [SVC:tester] [ACT:]
[from:99999999] [to:000] [flags:0:0:0:0:16]
[msg:22:0x0000000b/http://localhost] [udh:0:]
--- SMSBOX.LOG ---
2002-08-20 17:08:44 [0] INFO: Added logfile `/home/kannel/log/smsbox.log'
with level `0'.
2002-08-20 17:08:44 [0] INFO: Service global sender set as '13013'
2002-08-20 17:08:44 [0] INFO: Logging accesses to
'/home/kannel/log/smsboxaccess.log'.
2002-08-20 17:08:44 [0] INFO: Started access logfile
`/home/kannel/log/smsboxaccess.log'.
2002-08-20 17:08:44 [0] DEBUG: HTTP: Opening server at port 13013.
2002-08-20 17:08:44 [0] DEBUG: Started thread 1 (gwlib/fdset.c:poller)
2002-08-20 17:08:44 [0] DEBUG: Started thread 2
(gwlib/http.c:server_thread)
2002-08-20 17:08:44 [0] INFO: Set up send sms service at port 13013
2002-08-20 17:08:44 [0] DEBUG: Started thread 3 (gw/smsbox.c:sendsms_thread)
2002-08-20 17:08:44 [0] DEBUG:
----------------------------------------------
2002-08-20 17:08:44 [0] DEBUG: Kannel smsbox version 1.2.0 starting
2002-08-20 17:08:44 [0] DEBUG: Started thread 4
(gw/smsbox.c:obey_request_thread)
2002-08-20 17:08:44 [0] DEBUG: Started thread 5
(gw/smsbox.c:url_result_thread)
2002-08-20 17:08:44 [0] INFO: Connected to bearerbox at localhost port
13001.
2002-08-20 17:08:44 [0] DEBUG: Started thread 6
(gw/heartbeat.c:heartbeat_thread)
2002-08-20 17:08:44 [4] INFO: Starting delivery report <tester> from
<99999999>
2002-08-20 17:08:44 [4] DEBUG: Started thread 7 (gwlib/fdset.c:poller)
2002-08-20 17:08:44 [4] DEBUG: Started thread 8
(gwlib/http.c:write_request_thread)
2002-08-20 17:08:44 [8] DEBUG: HTTP: Opening connection to `localhost:80'
(fd=27).
2002-08-20 17:08:44 [8] DEBUG: HTTP: Sending request:
2002-08-20 17:08:44 [8] DEBUG: Octet string at 0x80d8120:
2002-08-20 17:08:44 [8] DEBUG: len: 56
2002-08-20 17:08:44 [8] DEBUG: size: 57
2002-08-20 17:08:44 [8] DEBUG: immutable: 0
2002-08-20 17:08:44 [8] DEBUG: data: 47 45 54 20 2f 20 48 54 GET / HT
2002-08-20 17:08:44 [8] DEBUG: data: 54 50 2f 31 2e 31 0d 0a TP/1.1..
2002-08-20 17:08:44 [8] DEBUG: data: 48 6f 73 74 3a 20 77 61 Host: lo
2002-08-20 17:08:44 [8] DEBUG: data: 36 30 0d 0a 55 73 65 72 ca..User
2002-08-20 17:08:44 [8] DEBUG: data: 2d 41 67 65 6e 74 3a 20 -Agent:
2002-08-20 17:08:44 [8] DEBUG: data: 4b 61 6e 6e 65 6c 20 31 Kannel 1
2002-08-20 17:08:44 [8] DEBUG: data: 2e 32 2e 30 0d 0a 0d 0a .2.0....
2002-08-20 17:08:44 [8] DEBUG: Octet string dump ends.
2002-08-20 17:08:44 [7] DEBUG: HTTP: Status line: <HTTP/1.1 200 OK>
--- SMSBOXACCESS.LOG ---
2002-08-20 17:08:44 Log begins
And finally, the status cgi response:
Kannel bearerbox version `1.2.0'. System Linux, release 2.4.18-3,
version #1 Thu Apr 18 07:37:53 EDT 2002, machine i686. Hostname
xxx.xxxxx, IP xxx.xxx.xxx.xxx. Libxml version 20419. Using OpenSSL
0.9.6b [engine] 9 Jul 2001. Using native malloc.
Status: running, uptime 0d 0h 35m 18s
WDP: received 0 (0 queued), sent 0 (0 queued)
SMS: received 1 (0 queued), sent 0 (0 queued), store size 1
SMS: inbound 0.00 msg/sec, outbound 0.00 msg/sec
DLR: 0 queued, using internal storage
Box connections:
smsbox, IP 127.0.0.1 (on-line 0d 0h 35m 7s)
SMSC connections:
CARRIER SMPP:xxx.xxx.xxx.xxx:xxxx/xxxx:XXXXXX:XXXXXX (online
2117s, rcvd 1, sent 0, failed 0, queued 0 msgs)
