Re: Kannel address-range make trouble to dlr report?

Sat, 22 Aug 2009 05:06:02 -0700 

Hi,
Thanks for the logs. Unfortunately this is not what i had in mind when requesting packet dumps. Packet dumps are taken using tcpdump, ethereal or snoop (Solaris). However, these will do as well. 


Seems kannel is messing up the PDU fields. Somehow it mixes up addr-range 
with source-address. Ticket time. Any smpp gurus want to take a look at the 
PDU definition?


BR,
Nikos

----- Original Message ----- 
From: "Nguyen Hai Chau" <[email protected]>

To: <[email protected]>
Sent: Saturday, August 22, 2009 1:09 PM
Subject: Re: Kannel address-range make trouble to dlr report?



Case 3: Kannel running with address-range = 1x00 and sender of each SMS 
set to '1x00'. DLR with Selenium simulated SMSC works.


==> Dump from bearerbox:

2009-08-22 16:43:34 [4884] [0] INFO: Debug_lvl = 0, log_file = <none>, 
log_lvl = 0
2009-08-22 16:43:34 [4884] [0] INFO: MYSQL: Connected to server at 
localhost.
2009-08-22 16:43:34 [4884] [0] INFO: MYSQL: server version 5.1.36, client 
version 5.1.36.

2009-08-22 16:43:34 [4884] [0] INFO: DLR using storage type: mysql
2009-08-22 16:43:34 [4884] [0] DEBUG: Kannel bearerbox version `1.4.3'.
Build `Aug 22 2009 09:30:40', compiler `4.4.0 20090506 (Red Hat 4.4.0-4)'.

System Linux, release 2.6.29.6-217.2.8.fc11.x86_64, version #1 SMP Sat Aug 
15 01:06:26 EDT 2009, machine x86_64.

Hostname localhost.localdomain, IP 127.0.0.1.
Libxml version 2.7.3.
Compiled with MySQL 5.1.36, using MySQL 5.1.36.
Using native malloc.


2009-08-22 16:43:34 [4884] [0] INFO: Added logfile 
`/home/chau/xxx/tmp/xxxbearer.log' with level `1'.
2009-08-22 16:43:34 [4884] [0] INFO: Started access logfile 
`/home/chau/xxx/tmp/xxxbeareraccess.log'.
2009-08-22 16:43:34 [4884] [0] INFO: SSL not supported, no SSL 
initialization done.

2009-08-22 16:43:34 [4884] [0] INFO: HTTP: Opening server at port 15100.

2009-08-22 16:43:34 [4884] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) maps 
to pid 4884.
2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 1 
(gwlib/fdset.c:poller)
2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 2 
(gwlib/http.c:server_thread)
2009-08-22 16:43:34 [4884] [3] DEBUG: Thread 3 
(gw/bb_http.c:httpadmin_run) maps to pid 4884.
2009-08-22 16:43:34 [4884] [2] DEBUG: Thread 2 
(gwlib/http.c:server_thread) maps to pid 4884.
2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 3 
(gw/bb_http.c:httpadmin_run)

2009-08-22 16:43:34 [4884] [0] DEBUG: starting smsbox connection module

2009-08-22 16:43:34 [4884] [0] INFO: BOXC: 'smsbox-max-pending' not set, 
using default (100).
2009-08-22 16:43:34 [4884] [4] DEBUG: Thread 4 
(gw/bb_boxc.c:sms_to_smsboxes) maps to pid 4884.
2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 4 
(gw/bb_boxc.c:sms_to_smsboxes)
2009-08-22 16:43:34 [4884] [5] DEBUG: Thread 5 (gw/bb_boxc.c:smsboxc_run) 
maps to pid 4884.
2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 5 
(gw/bb_boxc.c:smsboxc_run)
2009-08-22 16:43:34 [4884] [0] INFO: Set SMS resend frequency to 60 
seconds.

2009-08-22 16:43:34 [4884] [0] INFO: SMS resend retry set to unlimited.

2009-08-22 16:43:34 [4884] [0] DEBUG: smsbox MO concatenated message 
handling enabled
2009-08-22 16:43:34 [4884] [0] INFO: Set throughput to 40.000 for smsc id 
<xxx>
2009-08-22 16:43:34 [4884] [0] INFO: DLR rerouting for smsc id <xxx> 
disabled.
2009-08-22 16:43:34 [4884] [6] DEBUG: Thread 6 
(gw/smsc/smsc_smpp.c:io_thread) maps to pid 4884.
2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 6 
(gw/smsc/smsc_smpp.c:io_thread)
2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 7 
(gw/bb_smscconn.c:sms_router)
2009-08-22 16:43:34 [4884] [7] DEBUG: Thread 7 
(gw/bb_smscconn.c:sms_router) maps to pid 4884.
2009-08-22 16:43:34 [4884] [0] 
INFO: ----------------------------------------
2009-08-22 16:43:34 [4884] [0] INFO: Kannel bearerbox II version 1.4.3 
starting

2009-08-22 16:43:34 [4884] [0] INFO: Loading store file `xxx.queue'
2009-08-22 16:43:34 [4884] [0] INFO: Store-file size 0, starting to unpack

2009-08-22 16:43:34 [4884] [0] INFO: Retrieved 0 messages, 
non-acknowledged messages: 0

2009-08-22 16:43:34 [4884] [6] DEBUG: SMPP[xxx]: Sending PDU:

2009-08-22 16:43:34 [4884] [8] DEBUG: Thread 8 
(gw/bb_store_file.c:store_dumper) maps to pid 4884.

2009-08-22 16:43:34 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac000a30 dump:
2009-08-22 16:43:34 [4884] [8] DEBUG: Dumping 0 messages to store
2009-08-22 16:43:34 [4884] [6] DEBUG:   type_name: bind_transceiver
2009-08-22 16:43:34 [4884] [6] DEBUG:   command_id: 9 = 0x00000009
2009-08-22 16:43:34 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:43:34 [4884] [6] DEBUG:   sequence_number: 1 = 0x00000001
2009-08-22 16:43:34 [4884] [6] DEBUG:   system_id: "smppclient"
2009-08-22 16:43:34 [4884] [6] DEBUG:   password: "password"

2009-08-22 16:43:34 [4884] [0] DEBUG: Started thread 8 
(gw/bb_store_file.c:store_dumper)

2009-08-22 16:43:34 [4884] [6] DEBUG:   system_type: "smpp"

2009-08-22 16:43:34 [4884] [0] INFO: MAIN: Start-up done, entering 
mainloop

2009-08-22 16:43:34 [4884] [6] DEBUG:   interface_version: 52 = 0x00000034
2009-08-22 16:43:34 [4884] [6] DEBUG:   addr_ton: 0 = 0x00000000
2009-08-22 16:43:34 [4884] [6] DEBUG:   addr_npi: 0 = 0x00000000
2009-08-22 16:43:34 [4884] [6] DEBUG:   address_range: "1x00"
2009-08-22 16:43:34 [4884] [6] DEBUG: SMPP PDU dump ends.
2009-08-22 16:43:34 [4884] [6] DEBUG: SMPP[xxx]: Got PDU:
2009-08-22 16:43:34 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac000e90 dump:
2009-08-22 16:43:34 [4884] [6] DEBUG:   type_name: bind_transceiver_resp

2009-08-22 16:43:34 [4884] [6] DEBUG:   command_id: 2147483657 = 
0x80000009

2009-08-22 16:43:34 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:43:34 [4884] [6] DEBUG:   sequence_number: 1 = 0x00000001
2009-08-22 16:43:34 [4884] [6] DEBUG:   system_id: "selenium"
2009-08-22 16:43:34 [4884] [6] DEBUG: SMPP PDU dump ends.
2009-08-22 16:43:36 [4884] [5] INFO: Client connected from <127.0.0.1>

2009-08-22 16:43:36 [4884] [5] DEBUG: Started thread 9 
(gw/bb_boxc.c:function)
2009-08-22 16:43:36 [4884] [9] DEBUG: Thread 9 (gw/bb_boxc.c:function) 
maps to pid 4884.
2009-08-22 16:43:36 [4884] [10] DEBUG: Thread 10 
(gw/bb_boxc.c:boxc_sender) maps to pid 4884.
2009-08-22 16:43:36 [4884] [9] DEBUG: Started thread 10 
(gw/bb_boxc.c:boxc_sender)

2009-08-22 16:43:41 [4884] [9] DEBUG: boxc_receiver: sms received

2009-08-22 16:43:41 [4884] [9] DEBUG: send_msg: sending msg to box: 
<127.0.0.1>

2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP[xxx]: Sending PDU:
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac000e90 dump:
2009-08-22 16:43:41 [4884] [6] DEBUG:   type_name: submit_sm
2009-08-22 16:43:41 [4884] [6] DEBUG:   command_id: 4 = 0x00000004
2009-08-22 16:43:41 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   sequence_number: 2 = 0x00000002
2009-08-22 16:43:41 [4884] [6] DEBUG:   service_type: NULL
2009-08-22 16:43:41 [4884] [6] DEBUG:   source_addr_ton: 5 = 0x00000005
2009-08-22 16:43:41 [4884] [6] DEBUG:   source_addr_npi: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   source_addr: "1x00"
2009-08-22 16:43:41 [4884] [6] DEBUG:   dest_addr_ton: 2 = 0x00000002
2009-08-22 16:43:41 [4884] [6] DEBUG:   dest_addr_npi: 1 = 0x00000001
2009-08-22 16:43:41 [4884] [6] DEBUG:   destination_addr: "84913465040"
2009-08-22 16:43:41 [4884] [6] DEBUG:   esm_class: 3 = 0x00000003
2009-08-22 16:43:41 [4884] [6] DEBUG:   protocol_id: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   priority_flag: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   schedule_delivery_time: NULL
2009-08-22 16:43:41 [4884] [6] DEBUG:   validity_period: NULL

2009-08-22 16:43:41 [4884] [6] DEBUG:   registered_delivery: 1 = 
0x00000001
2009-08-22 16:43:41 [4884] [6] DEBUG:   replace_if_present_flag: 0 = 
0x00000000

2009-08-22 16:43:41 [4884] [6] DEBUG:   data_coding: 4 = 0x00000004
2009-08-22 16:43:41 [4884] [6] DEBUG:   sm_default_msg_id: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   sm_length: 47 = 0x0000002f
2009-08-22 16:43:41 [4884] [6] DEBUG:   short_message:
2009-08-22 16:43:41 [4884] [6] DEBUG:    Octet string at 0x7fa7ac001090:
2009-08-22 16:43:41 [4884] [6] DEBUG:      len:  47
2009-08-22 16:43:41 [4884] [6] DEBUG:      size: 48
2009-08-22 16:43:41 [4884] [6] DEBUG:      immutable: 0

2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 53 65 6e 64 69 6e 67 20 
66 72 6f 6d 20 4b 61 6e   Sending from Kan
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 6e 65 6c 20 40 20 32 32 
2f 30 38 2f 32 30 30 39   nel @ 22/08/2009
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 20 31 36 3a 34 33 3a 34 
31 20 2b 30 37 30 30       16:43:41 +0700

2009-08-22 16:43:41 [4884] [6] DEBUG:    Octet string dump ends.
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU dump ends.
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP[xxx]: Got PDU:
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac000e60 dump:
2009-08-22 16:43:41 [4884] [6] DEBUG:   type_name: submit_sm_resp

2009-08-22 16:43:41 [4884] [6] DEBUG:   command_id: 2147483652 = 
0x80000004

2009-08-22 16:43:41 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   sequence_number: 2 = 0x00000002
2009-08-22 16:43:41 [4884] [6] DEBUG:   message_id: "3"
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU dump ends.

2009-08-22 16:43:41 [4884] [6] DEBUG: DLR[mysql]: Adding DLR smsc=xxx, 
ts=3, src=1x00, dst=84913465040, mask=3, boxc=
2009-08-22 16:43:41 [4884] [6] DEBUG: sql: INSERT INTO dlr (smsc, ts, 
source, destination, service, url, mask, boxc, status) VALUES ('xxx', '3', 
'1x00', '84913465040', 'SVVN', 
'http://localhost/~chau/xxx/dlr.php?sender=%p&recipient=%P&timestamp=%t&dlr=%d&bill=%A&&msgid=%F&outgoid=116', 
'3', '', '0');

2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP[xxx]: Got PDU:
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac0016f0 dump:
2009-08-22 16:43:41 [4884] [6] DEBUG:   type_name: deliver_sm
2009-08-22 16:43:41 [4884] [6] DEBUG:   command_id: 5 = 0x00000005
2009-08-22 16:43:41 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   sequence_number: 2 = 0x00000002
2009-08-22 16:43:41 [4884] [6] DEBUG:   service_type: NULL
2009-08-22 16:43:41 [4884] [6] DEBUG:   source_addr_ton: 2 = 0x00000002
2009-08-22 16:43:41 [4884] [6] DEBUG:   source_addr_npi: 1 = 0x00000001
2009-08-22 16:43:41 [4884] [6] DEBUG:   source_addr: "84913465040"
2009-08-22 16:43:41 [4884] [6] DEBUG:   dest_addr_ton: 5 = 0x00000005
2009-08-22 16:43:41 [4884] [6] DEBUG:   dest_addr_npi: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   destination_addr: "1x00"
2009-08-22 16:43:41 [4884] [6] DEBUG:   esm_class: 4 = 0x00000004
2009-08-22 16:43:41 [4884] [6] DEBUG:   protocol_id: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   priority_flag: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   schedule_delivery_time: NULL
2009-08-22 16:43:41 [4884] [6] DEBUG:   validity_period: NULL

2009-08-22 16:43:41 [4884] [6] DEBUG:   registered_delivery: 0 = 
0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   replace_if_present_flag: 0 = 
0x00000000

2009-08-22 16:43:41 [4884] [6] DEBUG:   data_coding: 4 = 0x00000004
2009-08-22 16:43:41 [4884] [6] DEBUG:   sm_default_msg_id: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   sm_length: 113 = 0x00000071
2009-08-22 16:43:41 [4884] [6] DEBUG:   short_message:
2009-08-22 16:43:41 [4884] [6] DEBUG:    Octet string at 0x7fa7ac001130:
2009-08-22 16:43:41 [4884] [6] DEBUG:      len:  113
2009-08-22 16:43:41 [4884] [6] DEBUG:      size: 114
2009-08-22 16:43:41 [4884] [6] DEBUG:      immutable: 0

2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 69 64 3a 33 20 73 75 62 
3a 30 30 31 20 64 6c 76   id:3 sub:001 dlv
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 72 64 3a 30 30 31 20 73 
75 62 6d 69 74 20 64 61   rd:001 submit da
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 74 65 3a 30 39 30 38 32 
32 31 36 34 39 20 64 6f   te:0908221649 do
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 6e 65 20 64 61 74 65 3a 
30 39 30 38 32 32 31 36   ne date:09082216
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 34 39 20 73 74 61 74 3a 
44 45 4c 49 56 52 44 20   49 stat:DELIVRD
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 65 72 72 3a 30 30 30 20 
54 65 78 74 3a 53 65 6e   err:000 Text:Sen
2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 64 69 6e 67 20 66 72 6f 
6d 20 4b 61 6e 6e 65 6c   ding from Kannel

2009-08-22 16:43:41 [4884] [6] DEBUG:      data: 20
2009-08-22 16:43:41 [4884] [6] DEBUG:    Octet string dump ends.
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU dump ends.
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP[xxx] handle_pdu, got DLR

2009-08-22 16:43:41 [4884] [6] DEBUG: DLR[mysql]: Looking for DLR 
smsc=xxx, ts=3, dst=84913465040, type=1
2009-08-22 16:43:41 [4884] [6] DEBUG: sql: SELECT mask, service, url, 
source, destination, boxc FROM dlr WHERE smsc='xxx' AND ts='3';
2009-08-22 16:43:41 [4884] [6] DEBUG: Found entry, row[0]=3, row[1]=SVVN, 
row[2]=http://localhost/~chau/xxx/dlr.php?sender=%p&recipient=%P&timestamp=%t&dlr=%d&bill=%A&&msgid=%F&outgoid=116, 
row[3]=1x00, row[4]=84913465040 row[5]=
2009-08-22 16:43:41 [4884] [6] DEBUG: DLR[mysql]: created DLR message for 
URL 
<http://localhost/~chau/xxx/dlr.php?sender=%p&recipient=%P&timestamp=%t&dlr=%d&bill=%A&&msgid=%F&outgoid=116>

2009-08-22 16:43:41 [4884] [6] DEBUG: removing DLR from database

2009-08-22 16:43:41 [4884] [6] DEBUG: sql: DELETE FROM dlr WHERE 
smsc='xxx' AND ts='3' LIMIT 1;

2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP[xxx]: Sending PDU:
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac001c90 dump:
2009-08-22 16:43:41 [4884] [6] DEBUG:   type_name: deliver_sm_resp

2009-08-22 16:43:41 [4884] [6] DEBUG:   command_id: 2147483653 = 
0x80000005
2009-08-22 16:43:41 [4884] [10] DEBUG: send_msg: sending msg to box: 
<127.0.0.1>

2009-08-22 16:43:41 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:43:41 [4884] [6] DEBUG:   sequence_number: 2 = 0x00000002
2009-08-22 16:43:41 [4884] [6] DEBUG:   message_id: NULL
2009-08-22 16:43:41 [4884] [6] DEBUG: SMPP PDU dump ends.

2009-08-22 16:43:41 [4884] [10] DEBUG: boxc_sender: sent message to 
<127.0.0.1>

2009-08-22 16:43:41 [4884] [9] DEBUG: boxc_receiver: got ack
2009-08-22 16:43:54 [4884] [8] DEBUG: Dumping 0 messages to store
2009-08-22 16:44:04 [4884] [6] DEBUG: SMPP[xxx]: Sending enquire link:
2009-08-22 16:44:04 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac001c10 dump:
2009-08-22 16:44:04 [4884] [6] DEBUG:   type_name: enquire_link
2009-08-22 16:44:04 [4884] [6] DEBUG:   command_id: 21 = 0x00000015
2009-08-22 16:44:04 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:44:04 [4884] [6] DEBUG:   sequence_number: 3 = 0x00000003
2009-08-22 16:44:04 [4884] [6] DEBUG: SMPP PDU dump ends.
2009-08-22 16:44:04 [4884] [6] DEBUG: SMPP[xxx]: Got PDU:
2009-08-22 16:44:04 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac000ef0 dump:
2009-08-22 16:44:04 [4884] [6] DEBUG:   type_name: enquire_link_resp

2009-08-22 16:44:04 [4884] [6] DEBUG:   command_id: 2147483669 = 
0x80000015

2009-08-22 16:44:04 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:44:04 [4884] [6] DEBUG:   sequence_number: 3 = 0x00000003
2009-08-22 16:44:04 [4884] [6] DEBUG: SMPP PDU dump ends.

2009-08-22 16:44:06 [4884] [9] DEBUG: boxc_receiver: heartbeat with load 
value 0 received
2009-08-22 16:44:12 [4884] [0] WARNING: Killing signal or HTTP admin 
command received, shutting down...

2009-08-22 16:44:12 [4884] [0] DEBUG: Shutting down Kannel...
2009-08-22 16:44:12 [4884] [0] DEBUG: shutting down smsc

2009-08-22 16:44:12 [4884] [0] DEBUG: Shutting down SMSCConn 
SMPP:192.168.71.71:3000/3000:smppclient:smpp (slow)

2009-08-22 16:44:12 [4884] [6] DEBUG: SMPP[xxx]: Sending unbind:
2009-08-22 16:44:12 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac000ef0 dump:
2009-08-22 16:44:12 [4884] [6] DEBUG:   type_name: unbind
2009-08-22 16:44:12 [4884] [6] DEBUG:   command_id: 6 = 0x00000006
2009-08-22 16:44:12 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:44:12 [4884] [6] DEBUG:   sequence_number: 4 = 0x00000004
2009-08-22 16:44:12 [4884] [6] DEBUG: SMPP PDU dump ends.
2009-08-22 16:44:12 [4884] [6] DEBUG: SMPP[xxx]: Got PDU:
2009-08-22 16:44:12 [4884] [6] DEBUG: SMPP PDU 0x7fa7ac000ef0 dump:
2009-08-22 16:44:12 [4884] [6] DEBUG:   type_name: unbind_resp

2009-08-22 16:44:12 [4884] [6] DEBUG:   command_id: 2147483654 = 
0x80000006

2009-08-22 16:44:12 [4884] [6] DEBUG:   command_status: 0 = 0x00000000
2009-08-22 16:44:12 [4884] [6] DEBUG:   sequence_number: 4 = 0x00000004
2009-08-22 16:44:12 [4884] [6] DEBUG: SMPP PDU dump ends.

2009-08-22 16:44:12 [4884] [6] DEBUG: SMPP[xxx]: io_thread: break and 
shutting down
2009-08-22 16:44:12 [4884] [6] DEBUG: Thread 6 
(gw/smsc/smsc_smpp.c:io_thread) terminates.
2009-08-22 16:44:12 [4884] [0] DEBUG: SMSCConn 
SMPP:192.168.71.71:3000/3000:smppclient:smpp shut down.

2009-08-22 16:44:12 [4884] [0] DEBUG: shutting down udp

2009-08-22 16:44:12 [4884] [4] DEBUG: Thread 4 
(gw/bb_boxc.c:sms_to_smsboxes) terminates.
2009-08-22 16:44:12 [4884] [10] DEBUG: send_msg: sending msg to box: 
<127.0.0.1>
2009-08-22 16:44:12 [4884] [10] DEBUG: Thread 10 
(gw/bb_boxc.c:boxc_sender) terminates.
2009-08-22 16:44:12 [4884] [9] INFO: Connection closed by the box 
<127.0.0.1>
2009-08-22 16:44:12 [4884] [9] DEBUG: Thread 9 (gw/bb_boxc.c:function) 
terminates.
2009-08-22 16:44:12 [4884] [7] DEBUG: Thread 7 
(gw/bb_smscconn.c:sms_router) terminates.
2009-08-22 16:44:13 [4884] [5] DEBUG: Thread 5 (gw/bb_boxc.c:smsboxc_run) 
terminates.
2009-08-22 16:44:13 [4884] [0] INFO: All flow threads have died, killing 
core
2009-08-22 16:44:13 [4884] [0] DEBUG: Waiting for 2 
(gwlib/http.c:server_thread) to terminate
2009-08-22 16:44:13 [4884] [3] DEBUG: HTTP: No clients with requests, 
quitting.
2009-08-22 16:44:13 [4884] [3] DEBUG: Thread 3 
(gw/bb_http.c:httpadmin_run) terminates.
2009-08-22 16:44:13 [4884] [2] DEBUG: Thread 2 
(gwlib/http.c:server_thread) terminates.
2009-08-22 16:44:13 [4884] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) 
terminates.

2009-08-22 16:44:13 [4884] [0] DEBUG: final clean-up for SMSCConn

2009-08-22 16:44:13 [4884] [0] DEBUG: smsbox MO concatenated message 
handling cleaned up

2009-08-22 16:44:13 [4884] [8] DEBUG: Dumping 0 messages to store

2009-08-22 16:44:13 [4884] [8] DEBUG: Thread 8 
(gw/bb_store_file.c:store_dumper) terminates.
2009-08-22 16:44:13 [4884] [0] INFO: Total WDP messages: received 0, sent 
0
2009-08-22 16:44:13 [4884] [0] INFO: Total SMS messages: received 1, sent 
1

2009-08-22 16:44:13 [4884] [0] DEBUG: Immutable octet strings: 225.

==> Dump from smsbox:

2009-08-22 16:43:36 [4895] [0] INFO: Debug_lvl = 0, log_file = <none>, 
log_lvl = 0

2009-08-22 16:43:36 [4895] [0] DEBUG: Kannel smsbox version `1.4.3'.
Build `Aug 22 2009 09:30:40', compiler `4.4.0 20090506 (Red Hat 4.4.0-4)'.

System Linux, release 2.6.29.6-217.2.8.fc11.x86_64, version #1 SMP Sat Aug 
15 01:06:26 EDT 2009, machine x86_64.

Hostname localhost.localdomain, IP 127.0.0.1.
Libxml version 2.7.3.
Compiled with MySQL 5.1.36, using MySQL 5.1.36.
Using native malloc.


2009-08-22 16:43:36 [4895] [0] INFO: Starting to log to file 
/home/chau/xxx/tmp/xxxsms.log level 1
2009-08-22 16:43:36 [4895] [0] INFO: Added logfile 
`/home/chau/xxx/tmp/xxxsms.log' with level `1'.
2009-08-22 16:43:36 [4895] [0] INFO: Logging accesses to 
'/home/chau/xxx/tmp/xxxsmsaccess.log'.
2009-08-22 16:43:36 [4895] [0] INFO: Started access logfile 
`/home/chau/xxx/tmp/xxxsmsaccess.log'.

2009-08-22 16:43:36 [4895] [0] INFO: HTTP: Opening server at port 15102.

2009-08-22 16:43:36 [4895] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) maps 
to pid 4895.
2009-08-22 16:43:36 [4895] [0] DEBUG: Started thread 1 
(gwlib/fdset.c:poller)
2009-08-22 16:43:36 [4895] [2] DEBUG: Thread 2 
(gwlib/http.c:server_thread) maps to pid 4895.
2009-08-22 16:43:36 [4895] [0] DEBUG: Started thread 2 
(gwlib/http.c:server_thread)

2009-08-22 16:43:36 [4895] [0] INFO: Set up send sms service at port 15102

2009-08-22 16:43:36 [4895] [3] DEBUG: Thread 3 
(gw/smsbox.c:sendsms_thread) maps to pid 4895.
2009-08-22 16:43:36 [4895] [0] DEBUG: Started thread 3 
(gw/smsbox.c:sendsms_thread)
2009-08-22 16:43:36 [4895] [0] 
DEBUG: ----------------------------------------------

2009-08-22 16:43:36 [4895] [0] DEBUG: Kannel smsbox version 1.4.3 starting
2009-08-22 16:43:36 [4895] [0] DEBUG:   dumping group (sendsms-user):
2009-08-22 16:43:36 [4895] [0] DEBUG: <name> = <SVVN>
2009-08-22 16:43:36 [4895] [0] DEBUG: <group> = <sendsms-user>
2009-08-22 16:43:36 [4895] [0] DEBUG: <username> = <svvn>
2009-08-22 16:43:36 [4895] [0] DEBUG: <password> = <xxx>

2009-08-22 16:43:36 [4895] [0] DEBUG: Started thread 4 
(gw/smsbox.c:obey_request_thread)
2009-08-22 16:43:36 [4895] [4] DEBUG: Thread 4 
(gw/smsbox.c:obey_request_thread) maps to pid 4895.
2009-08-22 16:43:36 [4895] [5] DEBUG: Thread 5 
(gw/smsbox.c:url_result_thread) maps to pid 4895.
2009-08-22 16:43:36 [4895] [0] DEBUG: Started thread 5 
(gw/smsbox.c:url_result_thread)
2009-08-22 16:43:36 [4895] [0] DEBUG: Started thread 6 
(gw/smsbox.c:http_queue_thread)
2009-08-22 16:43:36 [4895] [6] DEBUG: Thread 6 
(gw/smsbox.c:http_queue_thread) maps to pid 4895.
2009-08-22 16:43:36 [4895] [0] INFO: Connected to bearerbox at 127.0.0.1 
port 15101.
2009-08-22 16:43:36 [4895] [7] DEBUG: Thread 7 
(gw/heartbeat.c:heartbeat_thread) maps to pid 4895.
2009-08-22 16:43:36 [4895] [0] DEBUG: Started thread 7 
(gw/heartbeat.c:heartbeat_thread)
2009-08-22 16:43:41 [4895] [2] DEBUG: HTTP: Creating HTTPClient for 
`127.0.0.1'.
2009-08-22 16:43:41 [4895] [2] DEBUG: HTTP: Created HTTPClient area 
0x7fc89c000a80.
2009-08-22 16:43:41 [4895] [3] INFO: smsbox: Got HTTP request </sendsms> 
from <127.0.0.1>

2009-08-22 16:43:41 [4895] [3] INFO: sendsms used by <svvn>

2009-08-22 16:43:41 [4895] [3] INFO: sendsms sender:<svvn:1x00> 
(127.0.0.1) to:<84913465040> msg:<Sending from Kannel @ 22/08/2009 
16:43:41 +0700>
2009-08-22 16:43:41 [4895] [3] DEBUG: Stored UUID 
b10b1adf-71a0-4dbd-9228-4a94ffeab4c0
2009-08-22 16:43:41 [4895] [3] DEBUG: message length 47, sending 1 
messages

2009-08-22 16:43:41 [4895] [3] DEBUG: Status: 202 Answer: <Sent.>
2009-08-22 16:43:41 [4895] [3] DEBUG: Delayed reply - wait for bearerbox

2009-08-22 16:43:41 [4895] [0] DEBUG: Got ACK (0) of 
b10b1adf-71a0-4dbd-9228-4a94ffeab4c0
2009-08-22 16:43:41 [4895] [0] DEBUG: HTTP: Destroying HTTPClient area 
0x7fc89c000a80.
2009-08-22 16:43:41 [4895] [0] DEBUG: HTTP: Destroying HTTPClient for 
`127.0.0.1'.
2009-08-22 16:43:41 [4895] [4] INFO: Starting delivery report <SVVN> from 
<1x00>
2009-08-22 16:43:41 [4895] [8] DEBUG: Thread 8 (gwlib/fdset.c:poller) maps 
to pid 4895.
2009-08-22 16:43:41 [4895] [4] DEBUG: Started thread 8 
(gwlib/fdset.c:poller)
2009-08-22 16:43:41 [4895] [4] DEBUG: Started thread 9 
(gwlib/http.c:write_request_thread)
2009-08-22 16:43:41 [4895] [9] DEBUG: Thread 9 
(gwlib/http.c:write_request_thread) maps to pid 4895.

2009-08-22 16:43:41 [4895] [9] DEBUG: Queue contains 0 pending requests.

2009-08-22 16:43:41 [4895] [9] DEBUG: Parsing URL 
`http://localhost/~chau/xxx/dlr.php?sender=84913465040&recipient=1x00&timestamp=2009-08-22+09:43:41&dlr=1&bill=id%3A3+sub%3A001+dlvrd%3A001+submit+date%3A0908221649+done+date%3A0908221649+stat%3ADELIVRD+err%3A000+Text%3ASending+from+Kannel+&&msgid=3&outgoid=116':

2009-08-22 16:43:41 [4895] [9] DEBUG:   Scheme: http://
2009-08-22 16:43:41 [4895] [9] DEBUG:   Host: localhost
2009-08-22 16:43:41 [4895] [9] DEBUG:   Port: 80
2009-08-22 16:43:41 [4895] [9] DEBUG:   Username: (null)
2009-08-22 16:43:41 [4895] [9] DEBUG:   Password: (null)
2009-08-22 16:43:41 [4895] [9] DEBUG:   Path: /~chau/xxx/dlr.php

2009-08-22 16:43:41 [4895] [9] DEBUG:   Query: 
sender=84913465040&recipient=1x00&timestamp=2009-08-22+09:43:41&dlr=1&bill=id%3A3+sub%3A001+dlvrd%3A001+submit+date%3A0908221649+done+date%3A0908221649+stat%3ADELIVRD+err%3A000+Text%3ASending+from+Kannel+&&msgid=3&outgoid=116

2009-08-22 16:43:41 [4895] [9] DEBUG:   Fragment: (null)

2009-08-22 16:43:41 [4895] [9] DEBUG: HTTP: Opening connection to 
`localhost:80' (fd=28).

2009-08-22 16:43:41 [4895] [9] DEBUG: Socket connecting
2009-08-22 16:43:41 [4895] [8] DEBUG: Get info about connecting socket
2009-08-22 16:43:41 [4895] [8] DEBUG: HTTP: Sending request:
2009-08-22 16:43:41 [4895] [8] DEBUG: Octet string at 0x7fc8880008e0:
2009-08-22 16:43:41 [4895] [8] DEBUG:   len:  333
2009-08-22 16:43:41 [4895] [8] DEBUG:   size: 1024
2009-08-22 16:43:41 [4895] [8] DEBUG:   immutable: 0

2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 47 45 54 20 2f 7e 63 68 61 
75 2f 6d 6f 62 69 66   GET /~chau/mobif
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 6f 6e 65 2f 64 6c 72 2e 70 
68 70 3f 73 65 6e 64   one/dlr.php?send
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 65 72 3d 38 34 39 31 33 34 
36 35 30 34 30 26 72   er=84913465040&r
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 65 63 69 70 69 65 6e 74 3d 
31 78 30 30 26 74 69   ecipient=1x00&ti
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 6d 65 73 74 61 6d 70 3d 32 
30 30 39 2d 30 38 2d   mestamp=2009-08-
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 32 32 2b 30 39 3a 34 33 3a 
34 31 26 64 6c 72 3d   22+09:43:41&dlr=
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 31 26 62 69 6c 6c 3d 69 64 
25 33 41 33 2b 73 75   1&bill=id%3A3+su
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 62 25 33 41 30 30 31 2b 64 
6c 76 72 64 25 33 41   b%3A001+dlvrd%3A
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 30 30 31 2b 73 75 62 6d 69 
74 2b 64 61 74 65 25   001+submit+date%
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 33 41 30 39 30 38 32 32 31 
36 34 39 2b 64 6f 6e   3A0908221649+don
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 65 2b 64 61 74 65 25 33 41 
30 39 30 38 32 32 31   e+date%3A0908221
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 36 34 39 2b 73 74 61 74 25 
33 41 44 45 4c 49 56   649+stat%3ADELIV
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 52 44 2b 65 72 72 25 33 41 
30 30 30 2b 54 65 78   RD+err%3A000+Tex
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 74 25 33 41 53 65 6e 64 69 
6e 67 2b 66 72 6f 6d   t%3ASending+from
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 2b 4b 61 6e 6e 65 6c 2b 26 
26 6d 73 67 69 64 3d   +Kannel+&&msgid=
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 33 26 6f 75 74 67 6f 69 64 
3d 31 31 36 20 48 54   3&outgoid=116 HT
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 54 50 2f 31 2e 31 0d 0a 48 
6f 73 74 3a 20 6c 6f   TP/1.1..Host: lo
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 63 61 6c 68 6f 73 74 0d 0a 
43 6f 6e 6e 65 63 74   calhost..Connect
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 69 6f 6e 3a 20 6b 65 65 70 
2d 61 6c 69 76 65 0d   ion: keep-alive.
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 0a 55 73 65 72 2d 41 67 65 
6e 74 3a 20 4b 61 6e   .User-Agent: Kan
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 6e 65 6c 2f 31 2e 34 2e 33 
0d 0a 0d 0a            nel/1.4.3....

2009-08-22 16:43:41 [4895] [8] DEBUG: Octet string dump ends.
2009-08-22 16:43:41 [4895] [8] DEBUG: HTTP: Status line: <HTTP/1.1 200 OK>
2009-08-22 16:43:41 [4895] [8] DEBUG: HTTP: Received response:
2009-08-22 16:43:41 [4895] [8] DEBUG: Octet string at 0x7fc888001420:
2009-08-22 16:43:41 [4895] [8] DEBUG:   len:  174
2009-08-22 16:43:41 [4895] [8] DEBUG:   size: 1024
2009-08-22 16:43:41 [4895] [8] DEBUG:   immutable: 0

2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 44 61 74 65 3a 20 53 61 74 
2c 20 32 32 20 41 75   Date: Sat, 22 Au
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 67 20 32 30 30 39 20 30 39 
3a 34 33 3a 34 31 20   g 2009 09:43:41
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 47 4d 54 0d 0a 53 65 72 76 
65 72 3a 20 41 70 61   GMT..Server: Apa
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 63 68 65 2f 32 2e 32 2e 31 
31 20 28 46 65 64 6f   che/2.2.11 (Fedo
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 72 61 29 0d 0a 58 2d 50 6f 
77 65 72 65 64 2d 42   ra)..X-Powered-B
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 79 3a 20 50 48 50 2f 35 2e 
32 2e 39 0d 0a 43 6f   y: PHP/5.2.9..Co
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 6e 74 65 6e 74 2d 4c 65 6e 
67 74 68 3a 20 30 0d   ntent-Length: 0.
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 0a 43 6f 6e 6e 65 63 74 69 
6f 6e 3a 20 63 6c 6f   .Connection: clo
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 73 65 0d 0a 43 6f 6e 74 65 
6e 74 2d 54 79 70 65   se..Content-Type
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 3a 20 74 65 78 74 2f 68 74 
6d 6c 3b 20 63 68 61   : text/html; cha
2009-08-22 16:43:41 [4895] [8] DEBUG:   data: 72 73 65 74 3d 55 54 46 2d 
38 0d 0a 0d 0a         rset=UTF-8....

2009-08-22 16:43:41 [4895] [8] DEBUG: Octet string dump ends.
2009-08-22 16:44:12 [4895] [0] INFO: Bearerbox told us to die

2009-08-22 16:44:12 [4895] [0] INFO: Received (and handled?) 1 requests in 
31 seconds (0.03 per second)

2009-08-22 16:44:12 [4895] [0] INFO: Kannel smsbox terminating.

2009-08-22 16:44:12 [4895] [7] DEBUG: Thread 7 
(gw/heartbeat.c:heartbeat_thread) terminates.
2009-08-22 16:44:12 [4895] [0] DEBUG: Waiting for 2 
(gwlib/http.c:server_thread) to terminate
2009-08-22 16:44:12 [4895] [3] DEBUG: HTTP: No clients with requests, 
quitting.
2009-08-22 16:44:12 [4895] [3] DEBUG: Thread 3 
(gw/smsbox.c:sendsms_thread) terminates.
2009-08-22 16:44:12 [4895] [2] DEBUG: Thread 2 
(gwlib/http.c:server_thread) terminates.
2009-08-22 16:44:12 [4895] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) 
terminates.
2009-08-22 16:44:12 [4895] [0] DEBUG: Waiting for 4 
(gw/smsbox.c:obey_request_thread) to terminate
2009-08-22 16:44:12 [4895] [6] DEBUG: Thread 6 
(gw/smsbox.c:http_queue_thread) terminates.
2009-08-22 16:44:12 [4895] [4] DEBUG: Thread 4 
(gw/smsbox.c:obey_request_thread) terminates.
2009-08-22 16:44:12 [4895] [0] DEBUG: Waiting for 5 
(gw/smsbox.c:url_result_thread) to terminate
2009-08-22 16:44:12 [4895] [5] DEBUG: Thread 5 
(gw/smsbox.c:url_result_thread) terminates.
2009-08-22 16:44:12 [4895] [0] DEBUG: Waiting for 9 
(gwlib/http.c:write_request_thread) to terminate
2009-08-22 16:44:12 [4895] [9] DEBUG: Thread 9 
(gwlib/http.c:write_request_thread) terminates.
2009-08-22 16:44:12 [4895] [8] DEBUG: Thread 8 (gwlib/fdset.c:poller) 
terminates.

2009-08-22 16:44:12 [4895] [0] DEBUG: Immutable octet strings: 258.



























					Reply via email to