Interesting...I am surprised this hasn't come up before. I can see a
possible reason for doing things this way, i.e. to match dlrs with original
submission in access long and dlr_url, but it is not necessary to do so, and
infact it is an error. This doesn't matter as long as you don't have an
smppbox in line, but it also means that all traffic through smppbox has this
reversion, which would lead to mismatched dlrs upstream...
Smsbox will need to have this reversion fixed as well...
How come *ever* dlrs got matched upstream through smppbox? Nobody noticed
before?
BR,
Nikos
----- Original Message -----
From: Rene Kluwen
To: 'Didac Royo'
Cc: [email protected]
Sent: Wednesday, March 02, 2011 4:56 PM
Subject: RE: OpenSMPP+Kannel: DLR: (dst & src) are expected INVETED in the
deliver_sm (but remains as in submit_sm)
Viewing this log, it seems that your sms gateway is doing things right.
Somewhere along the line, bearerbox OR opensmppbox reverses the addresses.
Looking at the code, I cannot see which one is doing things wrong. Both seem
to be doing things allrighty…
Judging from your bearerbox log:
Ψ 2011-03-01 16:50:04 Receive DLR [SMSC:GMS] [SVC:ismsad] [ACT:sit2]
[BINF:] [FID:110301S00d1a44c] [META:?smpp?dlr_err=000&] [from:Info]
[to:+34695839615] [flags:-1:-1:-1:-1:1] [msg:111:id:110301S00d1a44c sub:000
dlvrd:000 submit date:1103011650 done date:1103011650 stat:DELIVRD err:000
text: ] [udh:0:]
It seems that smsc smpp is doing things wrong. On line 1487 and line 1545 of
smsc_smpp.c, where the function handle_dlr() is called, this function
replaces source_addr with destination_address.
Or maybe otherwise: dlr_find is called and returns the msg structure with
the original source_addr and dest_addr still in place.
Maybe somebody with some more knowledge of the smpp driver can shed a light
on this?
== Rene
From: Dνdac Royo [mailto:[email protected]]
Sent: Wednesday, 02 March, 2011 12:35
To: Rene Kluwen
Cc: [email protected]
Subject: Re: OpenSMPP+Kannel: DLR: (dst & src) are expected INVETED in the
deliver_sm (but remains as in submit_sm)
Hi Rene,
I think this is the log you are looking for. Can you see what is happening
from this log snipped? thanks
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP[PROVIDER]: Sending PDU:
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP PDU 0x797cf0 dump:
2011-03-01 16:50:00 [608] [7] DEBUG: type_name: submit_sm
2011-03-01 16:50:00 [608] [7] DEBUG: command_id: 4 = 0x00000004
2011-03-01 16:50:00 [608] [7] DEBUG: command_status: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: sequence_number: 12 = 0x0000000c
2011-03-01 16:50:00 [608] [7] DEBUG: service_type: NULL
2011-03-01 16:50:00 [608] [7] DEBUG: source_addr_ton: 5 = 0x00000005
2011-03-01 16:50:00 [608] [7] DEBUG: source_addr_npi: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: source_addr: "Info"
2011-03-01 16:50:00 [608] [7] DEBUG: dest_addr_ton: 1 = 0x00000001
2011-03-01 16:50:00 [608] [7] DEBUG: dest_addr_npi: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: destination_addr: "34695839615"
2011-03-01 16:50:00 [608] [7] DEBUG: esm_class: 3 = 0x00000003
2011-03-01 16:50:00 [608] [7] DEBUG: protocol_id: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: priority_flag: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: schedule_delivery_time: NULL
2011-03-01 16:50:00 [608] [7] DEBUG: validity_period: NULL
2011-03-01 16:50:00 [608] [7] DEBUG: registered_delivery: 1 = 0x00000001
2011-03-01 16:50:00 [608] [7] DEBUG: replace_if_present_flag: 0 =
0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: data_coding: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: sm_length: 10 = 0x0000000a
2011-03-01 16:50:00 [608] [7] DEBUG: short_message: "test 16:48"
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP PDU dump ends.
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP[PROVIDER]: throughput (1.00,50.00)
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP[PROVIDER]: throughput (1.00,50.00)
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP[PROVIDER]: Got PDU:
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP PDU 0x797cf0 dump:
2011-03-01 16:50:00 [608] [7] DEBUG: type_name: submit_sm_resp
2011-03-01 16:50:00 [608] [7] DEBUG: command_id: 2147483652 = 0x80000004
2011-03-01 16:50:00 [608] [7] DEBUG: command_status: 0 = 0x00000000
2011-03-01 16:50:00 [608] [7] DEBUG: sequence_number: 12 = 0x0000000c
2011-03-01 16:50:00 [608] [7] DEBUG: message_id: "110301S00d1a44c"
2011-03-01 16:50:00 [608] [7] DEBUG: SMPP PDU dump ends.
2011-03-01 16:50:04 [608] [7] DEBUG: SMPP[PROVIDER]: Got PDU:
2011-03-01 16:50:04 [608] [7] DEBUG: SMPP PDU 0x797500 dump:
2011-03-01 16:50:04 [608] [7] DEBUG: type_name: deliver_sm
2011-03-01 16:50:04 [608] [7] DEBUG: command_id: 5 = 0x00000005
2011-03-01 16:50:04 [608] [7] DEBUG: command_status: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: sequence_number: 21274986 =
0x0144a16a
2011-03-01 16:50:04 [608] [7] DEBUG: service_type: NULL
2011-03-01 16:50:04 [608] [7] DEBUG: source_addr_ton: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: source_addr_npi: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: source_addr: "34695839615"
2011-03-01 16:50:04 [608] [7] DEBUG: dest_addr_ton: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: dest_addr_npi: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: destination_addr: "Info"
2011-03-01 16:50:04 [608] [7] DEBUG: esm_class: 4 = 0x00000004
2011-03-01 16:50:04 [608] [7] DEBUG: protocol_id: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: priority_flag: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: schedule_delivery_time: NULL
2011-03-01 16:50:04 [608] [7] DEBUG: validity_period: NULL
2011-03-01 16:50:04 [608] [7] DEBUG: registered_delivery: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: replace_if_present_flag: 0 =
0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: data_coding: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000
2011-03-01 16:50:04 [608] [7] DEBUG: sm_length: 111 = 0x0000006f
2011-03-01 16:50:04 [608] [7] DEBUG: short_message:
2011-03-01 16:50:04 [608] [7] DEBUG: Octet string at 0x795bf0:
2011-03-01 16:50:04 [608] [7] DEBUG: len: 111
2011-03-01 16:50:04 [608] [7] DEBUG: size: 112
2011-03-01 16:50:04 [608] [7] DEBUG: immutable: 0
2011-03-01 16:50:04 [608] [7] DEBUG: data: 69 64 3a 31 31 30 33 30 31
53 30 30 64 31 61 34 id:110301S00d1a4
2011-03-01 16:50:04 [608] [7] DEBUG: data: 34 63 20 73 75 62 3a 30 30
30 20 64 6c 76 72 64 4c sub:000 dlvrd
2011-03-01 16:50:04 [608] [7] DEBUG: data: 3a 30 30 30 20 73 75 62 6d
69 74 20 64 61 74 65 :000 submit date
2011-03-01 16:50:04 [608] [7] DEBUG: data: 3a 31 31 30 33 30 31 31 36
35 30 20 64 6f 6e 65 :1103011650 done
2011-03-01 16:50:04 [608] [7] DEBUG: data: 20 64 61 74 65 3a 31 31 30
33 30 31 31 36 35 30 date:1103011650
2011-03-01 16:50:04 [608] [7] DEBUG: data: 20 73 74 61 74 3a 44 45 4c
49 56 52 44 20 65 72 stat:DELIVRD er
2011-03-01 16:50:04 [608] [7] DEBUG: data: 72 3a 30 30 30 20 74 65 78
74 3a 20 20 20 20 r:000 text:
2011-03-01 16:50:04 [608] [7] DEBUG: Octet string dump ends.
2011-03-01 16:50:04 [608] [7] DEBUG: SMPP PDU dump ends.
On Wed, Mar 2, 2011 at 8:05 AM, Rene Kluwen <[email protected]> wrote:
In these logs, I don’t find the submit_sm / deliver_sm to your down stream
smsc.
From: Dνdac Royo [mailto:[email protected]]
Sent: Tuesday, 01 March, 2011 20:59
To: Rene Kluwen
Cc: [email protected]
Subject: Re: OpenSMPP+Kannel: DLR: (dst & src) are expected INVETED in the
deliver_sm (but remains as in submit_sm)
Hi Rene,
Thanks for your quick reply.
I've also considered an issue at SMSC end, but I routed the SMS to a
different SMSC and the observed behaviour is the same.
I'm attaching the bearerbox.log (with debug level and the corresponding
opensmppbox.log)
thanks for your support
----------------
bearerbox.log:
2011-03-01 20:34:31 [25446] [18] INFO: Connection closed by the box
<127.0.0.1>
2011-03-01 20:34:31 [25446] [0] WARNING: Killing signal or HTTP admin
command received, shutting down...
2011-03-01 20:34:31 [25446] [20] INFO: Connection closed by the box
<127.0.0.1>
2011-03-01 20:34:31 [25446] [22] INFO: Connection closed by the box
<127.0.0.1>
2011-03-01 20:34:31 [25446] [24] INFO: Connection closed by the box
<127.0.0.1>
2011-03-01 20:34:41 [4921] [0] INFO: Added logfile
`/var/log/kannel/bearerbox.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] INFO: Started access logfile
`/var/log/kannel/bearerbox.access'.
2011-03-01 20:34:41 [4921] [0] INFO: HTTP: Opening server at port 13000.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 1
(gwlib/fdset.c:poller)
2011-03-01 20:34:41 [4921] [1] DEBUG: Thread 1 (gwlib/fdset.c:poller) maps
to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 2
(gwlib/http.c:server_thread)
2011-03-01 20:34:41 [4921] [2] DEBUG: Thread 2 (gwlib/http.c:server_thread)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [2] DEBUG: HTTP: Including port 13000, fd 8 for
polling in server thread
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 3
(gw/bb_http.c:httpadmin_run)
2011-03-01 20:34:41 [4921] [3] DEBUG: Thread 3 (gw/bb_http.c:httpadmin_run)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: starting smsbox connection module
2011-03-01 20:34:41 [4921] [0] INFO: BOXC: 'smsbox-max-pending' not set,
using default (100).
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 4
(gw/bb_boxc.c:sms_to_smsboxes)
2011-03-01 20:34:41 [4921] [4] DEBUG: Thread 4
(gw/bb_boxc.c:sms_to_smsboxes) maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 5
(gw/bb_boxc.c:smsboxc_run)
2011-03-01 20:34:41 [4921] [5] DEBUG: Thread 5 (gw/bb_boxc.c:smsboxc_run)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] INFO: Set SMS resend frequency to 60 seconds.
2011-03-01 20:34:41 [4921] [0] INFO: SMS resend retry set to unlimited.
2011-03-01 20:34:41 [4921] [0] DEBUG: MO concatenated message handling
enabled
2011-03-01 20:34:41 [4921] [0] INFO: DLR rerouting for smsc id <ruteral>
disabled.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 6
(gw/smsc/smsc_smpp.c:io_thread)
2011-03-01 20:34:41 [4921] [6] DEBUG: Thread 6
(gw/smsc/smsc_smpp.c:io_thread) maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] INFO: Set throughput to 50.000 for smsc id
<GMS>
2011-03-01 20:34:41 [4921] [0] INFO: DLR rerouting for smsc id <GMS>
disabled.
2011-03-01 20:34:41 [4921] [0] INFO: Added logfile `/var/log/kannel/GMS.log'
with level `0'.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 7
(gw/smsc/smsc_smpp.c:io_thread)
2011-03-01 20:34:41 [4921] [7] DEBUG: Thread 7
(gw/smsc/smsc_smpp.c:io_thread) maps to pid 4921.
2011-03-01 20:34:41 [4921] [7] INFO: Logging thread `7' to logfile
`/var/log/kannel/GMS.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] INFO: Set throughput to 8.000 for smsc id
<amdtelecom>
2011-03-01 20:34:41 [4921] [0] INFO: DLR rerouting for smsc id <amdtelecom>
disabled.
2011-03-01 20:34:41 [4921] [0] INFO: Added logfile
`var/log/kannel/amdtelecom.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] WARNING: SMPP: receive-port for transceiver
mode defined, ignoring.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 8
(gw/smsc/smsc_smpp.c:io_thread)
2011-03-01 20:34:41 [4921] [8] DEBUG: Thread 8
(gw/smsc/smsc_smpp.c:io_thread) maps to pid 4921.
2011-03-01 20:34:41 [4921] [8] INFO: Logging thread `8' to logfile
`var/log/kannel/amdtelecom.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] INFO: Set throughput to 25.000 for smsc id
<ruteralsms>
2011-03-01 20:34:41 [4921] [0] INFO: DLR rerouting for smsc id <ruteralsms>
disabled.
2011-03-01 20:34:41 [4921] [0] INFO: Added logfile
`var/log/kannel/ruteralsms.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] WARNING: SMPP: receive-port for transceiver
mode defined, ignoring.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 9
(gw/smsc/smsc_smpp.c:io_thread)
2011-03-01 20:34:41 [4921] [9] DEBUG: Thread 9
(gw/smsc/smsc_smpp.c:io_thread) maps to pid 4921.
2011-03-01 20:34:41 [4921] [9] INFO: Logging thread `9' to logfile
`var/log/kannel/ruteralsms.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] INFO: Set throughput to 25.000 for smsc id
<eco-ruteralsms>
2011-03-01 20:34:41 [4921] [0] INFO: DLR rerouting for smsc id
<eco-ruteralsms> disabled.
2011-03-01 20:34:41 [4921] [0] INFO: Added logfile
`var/log/kannel/eco-ruteralsms.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] WARNING: SMPP: receive-port for transceiver
mode defined, ignoring.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 10
(gw/smsc/smsc_smpp.c:io_thread)
2011-03-01 20:34:41 [4921] [10] DEBUG: Thread 10
(gw/smsc/smsc_smpp.c:io_thread) maps to pid 4921.
2011-03-01 20:34:41 [4921] [10] INFO: Logging thread `10' to logfile
`var/log/kannel/eco-ruteralsms.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] INFO: Set throughput to 25.000 for smsc id
<smswarehouse>
2011-03-01 20:34:41 [4921] [0] INFO: DLR rerouting for smsc id
<smswarehouse> disabled.
2011-03-01 20:34:41 [4921] [0] INFO: Added logfile
`var/log/kannel/smswarehouse.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] WARNING: SMPP: receive-port for transceiver
mode defined, ignoring.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 11
(gw/smsc/smsc_smpp.c:io_thread)
2011-03-01 20:34:41 [4921] [11] DEBUG: Thread 11
(gw/smsc/smsc_smpp.c:io_thread) maps to pid 4921.
2011-03-01 20:34:41 [4921] [11] INFO: Logging thread `11' to logfile
`var/log/kannel/smswarehouse.log' with level `0'.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 12
(gw/bb_smscconn.c:sms_router)
2011-03-01 20:34:41 [4921] [0] DEBUG: starting UDP sender/receiver module
2011-03-01 20:34:41 [4921] [0] INFO: Adding interface *
2011-03-01 20:34:41 [4921] [0] DEBUG: udpc_create: Bound to UDP
<0.0.0.0:9200>
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 13
(gw/bb_udp.c:udp_receiver)
2011-03-01 20:34:41 [4921] [13] DEBUG: Thread 13 (gw/bb_udp.c:udp_receiver)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 14
(gw/bb_udp.c:udp_sender)
2011-03-01 20:34:41 [4921] [14] DEBUG: Thread 14 (gw/bb_udp.c:udp_sender)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: udpc_create: Bound to UDP
<0.0.0.0:9201>
2011-03-01 20:34:41 [4921] [12] DEBUG: Thread 12
(gw/bb_smscconn.c:sms_router) maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 15
(gw/bb_udp.c:udp_receiver)
2011-03-01 20:34:41 [4921] [15] DEBUG: Thread 15 (gw/bb_udp.c:udp_receiver)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 16
(gw/bb_udp.c:udp_sender)
2011-03-01 20:34:41 [4921] [16] DEBUG: Thread 16 (gw/bb_udp.c:udp_sender)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [0] DEBUG: starting wapbox connection module
2011-03-01 20:34:41 [4921] [0] ERROR: Missing wapbox-port variable, cannot
start WAP
2011-03-01 20:34:41 [4921] [0] DEBUG: starting WDP router
2011-03-01 20:34:41 [4921] [0] DEBUG: Started thread 17
(gw/bearerbox.c:wdp_router)
2011-03-01 20:34:41 [4921] [17] DEBUG: Thread 17 (gw/bearerbox.c:wdp_router)
maps to pid 4921.
2011-03-01 20:34:41 [4921] [0]
INFO: ----------------------------------------
2011-03-01 20:34:41 [4921] [17] DEBUG: udp_die: removing producers from
udp-lists
2011-03-01 20:34:41 [4921] [0] INFO: Kannel bearerbox II version
svn-runknown starting
2011-03-01 20:34:41 [4921] [17] DEBUG: Thread 17 (gw/bearerbox.c:wdp_router)
terminates.
2011-03-01 20:34:41 [4921] [0] INFO: MAIN: Start-up done, entering mainloop
2011-03-01 20:34:41 [4921] [6] DEBUG: Connecting to <62.82.216.69>
2011-03-01 20:34:41 [4921] [6] DEBUG: interface_version: 52 = 0x00000034
2011-03-01 20:34:41 [4921] [6] DEBUG: addr_ton: 0 = 0x00000000
2011-03-01 20:34:41 [4921] [6] DEBUG: addr_npi: 0 = 0x00000000
2011-03-01 20:34:41 [4921] [6] DEBUG: address_range: NULL
2011-03-01 20:34:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:34:41 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:34:41 [4921] [6] DEBUG: SMPP PDU 0x7a27d0 dump:
2011-03-01 20:34:41 [4921] [6] DEBUG: type_name: bind_transceiver_resp
2011-03-01 20:34:41 [4921] [6] DEBUG: command_id: 2147483657 = 0x80000009
2011-03-01 20:34:41 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:34:41 [4921] [6] DEBUG: sequence_number: 1 = 0x00000001
2011-03-01 20:34:41 [4921] [6] DEBUG: system_id: NULL
2011-03-01 20:34:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:34:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:34:42 [4921] [5] INFO: Client connected from <127.0.0.1>
2011-03-01 20:34:42 [4921] [5] DEBUG: Started thread 18
(gw/bb_boxc.c:function)
2011-03-01 20:34:42 [4921] [18] DEBUG: Thread 18 (gw/bb_boxc.c:function)
maps to pid 4921.
2011-03-01 20:34:42 [4921] [18] DEBUG: Started thread 19
(gw/bb_boxc.c:boxc_sender)
2011-03-01 20:34:42 [4921] [19] DEBUG: Thread 19 (gw/bb_boxc.c:boxc_sender)
maps to pid 4921.
2011-03-01 20:34:43 [4921] [5] INFO: Client connected from <127.0.0.1>
2011-03-01 20:34:43 [4921] [5] DEBUG: Started thread 20
(gw/bb_boxc.c:function)
2011-03-01 20:34:43 [4921] [20] DEBUG: Thread 20 (gw/bb_boxc.c:function)
maps to pid 4921.
2011-03-01 20:34:43 [4921] [20] DEBUG: Started thread 21
(gw/bb_boxc.c:boxc_sender)
2011-03-01 20:34:43 [4921] [21] DEBUG: Thread 21 (gw/bb_boxc.c:boxc_sender)
maps to pid 4921.
2011-03-01 20:34:44 [4921] [20] DEBUG: boxc_receiver: got boxc_id <TELKIA>
from <127.0.0.1>
2011-03-01 20:34:44 [4921] [5] INFO: Client connected from <127.0.0.1>
2011-03-01 20:34:44 [4921] [5] DEBUG: Started thread 22
(gw/bb_boxc.c:function)
2011-03-01 20:34:44 [4921] [22] DEBUG: Thread 22 (gw/bb_boxc.c:function)
maps to pid 4921.
2011-03-01 20:34:44 [4921] [22] DEBUG: Started thread 23
(gw/bb_boxc.c:boxc_sender)
2011-03-01 20:34:44 [4921] [23] DEBUG: Thread 23 (gw/bb_boxc.c:boxc_sender)
maps to pid 4921.
2011-03-01 20:34:44 [4921] [22] DEBUG: boxc_receiver: got boxc_id <TELKIA>
from <127.0.0.1>
2011-03-01 20:34:46 [4921] [5] INFO: Client connected from <127.0.0.1>
2011-03-01 20:34:46 [4921] [5] DEBUG: Started thread 24
(gw/bb_boxc.c:function)
2011-03-01 20:34:46 [4921] [24] DEBUG: Thread 24 (gw/bb_boxc.c:function)
maps to pid 4921.
2011-03-01 20:34:46 [4921] [24] DEBUG: Started thread 25
(gw/bb_boxc.c:boxc_sender)
2011-03-01 20:34:46 [4921] [25] DEBUG: Thread 25 (gw/bb_boxc.c:boxc_sender)
maps to pid 4921.
2011-03-01 20:34:46 [4921] [24] DEBUG: boxc_receiver: got boxc_id <ISMSAD>
from <127.0.0.1>
2011-03-01 20:34:51 [4921] [2] DEBUG: HTTP: Creating HTTPClient for
`77.211.66.16'.
2011-03-01 20:34:51 [4921] [2] DEBUG: HTTP: Created HTTPClient area
0x78ef70.
2011-03-01 20:34:51 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP[ruteral]: Sending enquire link:
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:35:11 [4921] [6] DEBUG: type_name: enquire_link
2011-03-01 20:35:11 [4921] [6] DEBUG: command_id: 21 = 0x00000015
2011-03-01 20:35:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:35:11 [4921] [6] DEBUG: sequence_number: 2 = 0x00000002
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:35:11 [4921] [6] DEBUG: type_name: enquire_link_resp
2011-03-01 20:35:11 [4921] [6] DEBUG: command_id: 2147483669 = 0x80000015
2011-03-01 20:35:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:35:11 [4921] [6] DEBUG: sequence_number: 2 = 0x00000002
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:35:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:35:28 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:30 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:31 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:32 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:33 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:34 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:35 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:37 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:38 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:39 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:40 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP[ruteral]: Sending enquire link:
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:35:41 [4921] [6] DEBUG: type_name: enquire_link
2011-03-01 20:35:41 [4921] [6] DEBUG: command_id: 21 = 0x00000015
2011-03-01 20:35:41 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:35:41 [4921] [6] DEBUG: sequence_number: 3 = 0x00000003
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:35:41 [4921] [6] DEBUG: type_name: enquire_link_resp
2011-03-01 20:35:41 [4921] [6] DEBUG: command_id: 2147483669 = 0x80000015
2011-03-01 20:35:41 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:35:41 [4921] [6] DEBUG: sequence_number: 3 = 0x00000003
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:35:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:35:41 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:42 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:43 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:44 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:45 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:47 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:48 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:49 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:50 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:51 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:53 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:54 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:54 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:55 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:57 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:58 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:35:59 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:00 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:00 [4921] [24] DEBUG: boxc_receiver: sms received
2011-03-01 20:36:00 [4921] [24] DEBUG: send_msg: sending msg to boxc:
<ISMSAD>
2011-03-01 20:36:02 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:02 [4921] [25] DEBUG: send_msg: sending msg to boxc:
<ISMSAD>
2011-03-01 20:36:02 [4921] [25] DEBUG: boxc_sender: sent message to
<127.0.0.1>
2011-03-01 20:36:03 [4921] [24] DEBUG: boxc_receiver: got ack
2011-03-01 20:36:03 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:04 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:06 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:07 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:08 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:11 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP[ruteral]: Sending enquire link:
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:36:11 [4921] [6] DEBUG: type_name: enquire_link
2011-03-01 20:36:11 [4921] [6] DEBUG: command_id: 21 = 0x00000015
2011-03-01 20:36:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:36:11 [4921] [6] DEBUG: sequence_number: 4 = 0x00000004
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:36:11 [4921] [6] DEBUG: type_name: enquire_link_resp
2011-03-01 20:36:11 [4921] [6] DEBUG: command_id: 2147483669 = 0x80000015
2011-03-01 20:36:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:36:11 [4921] [6] DEBUG: sequence_number: 4 = 0x00000004
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:36:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:36:13 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:14 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:15 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:16 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:17 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:18 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:20 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:21 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:22 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:23 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:25 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:27 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:27 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:28 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:30 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:31 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:32 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:33 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:34 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:35 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:35 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:37 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:37 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:38 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:40 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:41 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP[ruteral]: Sending enquire link:
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP PDU 0x79b050 dump:
2011-03-01 20:36:41 [4921] [6] DEBUG: type_name: enquire_link
2011-03-01 20:36:41 [4921] [6] DEBUG: command_id: 21 = 0x00000015
2011-03-01 20:36:41 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:36:41 [4921] [6] DEBUG: sequence_number: 5 = 0x00000005
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP PDU 0x79b050 dump:
2011-03-01 20:36:41 [4921] [6] DEBUG: type_name: enquire_link_resp
2011-03-01 20:36:41 [4921] [6] DEBUG: command_id: 2147483669 = 0x80000015
2011-03-01 20:36:41 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:36:41 [4921] [6] DEBUG: sequence_number: 5 = 0x00000005
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:36:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:36:42 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:36:43 [4921] [3] DEBUG: HTTP: Resetting HTTPClient for
`77.211.66.16'.
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP[ruteral]: Sending enquire link:
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP PDU 0x79b050 dump:
2011-03-01 20:37:11 [4921] [6] DEBUG: type_name: enquire_link
2011-03-01 20:37:11 [4921] [6] DEBUG: command_id: 21 = 0x00000015
2011-03-01 20:37:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:37:11 [4921] [6] DEBUG: sequence_number: 6 = 0x00000006
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP PDU 0x79b050 dump:
2011-03-01 20:37:11 [4921] [6] DEBUG: type_name: enquire_link_resp
2011-03-01 20:37:11 [4921] [6] DEBUG: command_id: 2147483669 = 0x80000015
2011-03-01 20:37:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:37:11 [4921] [6] DEBUG: sequence_number: 6 = 0x00000006
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:37:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP[ruteral]: Sending enquire link:
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP PDU 0x79b050 dump:
2011-03-01 20:37:41 [4921] [6] DEBUG: type_name: enquire_link
2011-03-01 20:37:41 [4921] [6] DEBUG: command_id: 21 = 0x00000015
2011-03-01 20:37:41 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:37:41 [4921] [6] DEBUG: sequence_number: 7 = 0x00000007
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP PDU 0x79b050 dump:
2011-03-01 20:37:41 [4921] [6] DEBUG: type_name: enquire_link_resp
2011-03-01 20:37:41 [4921] [6] DEBUG: command_id: 2147483669 = 0x80000015
2011-03-01 20:37:41 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:37:41 [4921] [6] DEBUG: sequence_number: 7 = 0x00000007
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:37:41 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:37:43 [4921] [1] DEBUG: Timeout for fd:75 appeares.
2011-03-01 20:37:43 [4921] [1] DEBUG: HTTP: Destroying HTTPClient area
0x78ef70.
2011-03-01 20:37:43 [4921] [1] DEBUG: HTTP: Destroying HTTPClient for
`77.211.66.16'.
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP[ruteral]: Sending enquire link:
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:38:11 [4921] [6] DEBUG: type_name: enquire_link
2011-03-01 20:38:11 [4921] [6] DEBUG: command_id: 21 = 0x00000015
2011-03-01 20:38:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:38:11 [4921] [6] DEBUG: sequence_number: 8 = 0x00000008
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP PDU dump ends.
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP[ruteral]: throughput (0.00,0.00)
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP[ruteral]: Got PDU:
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP PDU 0x79b020 dump:
2011-03-01 20:38:11 [4921] [6] DEBUG: type_name: enquire_link_resp
2011-03-01 20:38:11 [4921] [6] DEBUG: command_id: 2147483669 = 0x80000015
2011-03-01 20:38:11 [4921] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:38:11 [4921] [6] DEBUG: sequence_number: 8 = 0x00000008
2011-03-01 20:38:11 [4921] [6] DEBUG: SMPP PDU dump ends.
----------------
opensmppbox.log:
2011-03-01 20:34:02 [25472] [6] DEBUG: DLR[internal]: Adding DLR
smsc=ISMSAD, ts=228cdf9b, src=Info, dst=+34637788288, mask=19, boxc=ISMSAD
2011-03-01 20:34:02 [25472] [5] DEBUG: SMPP[ISMSAD]: Sending PDU:
2011-03-01 20:34:02 [25472] [5] DEBUG: SMPP PDU 0x73b4b0 dump:
2011-03-01 20:34:02 [25472] [5] DEBUG: type_name: submit_sm_resp
2011-03-01 20:34:02 [25472] [5] DEBUG: command_id: 2147483652 = 0x80000004
2011-03-01 20:34:02 [25472] [5] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:34:02 [25472] [5] DEBUG: sequence_number: 2750 = 0x00000abe
2011-03-01 20:34:02 [25472] [5] DEBUG: message_id: "228cdf9b"
2011-03-01 20:34:02 [25472] [5] DEBUG: SMPP PDU dump ends.
2011-03-01 20:34:05 [25472] [5] INFO: We received an SMS message.
2011-03-01 20:34:05 [25472] [5] DEBUG: DLR[internal]: Looking for DLR
smsc=ISMSAD, ts=228cdf9b, dst=+34637788288, type=1
2011-03-01 20:34:05 [25472] [5] DEBUG: DLR[internal]: created DLR message
for URL <228cdf9b>
2011-03-01 20:34:05 [25472] [5] DEBUG: new group created `smpp'
2011-03-01 20:34:05 [25472] [5] DEBUG: group=`smpp' key=`dlr_err'
value=`000'
2011-03-01 20:34:05 [25472] [5] DEBUG: SMPP[ISMSAD]: Sending PDU:
2011-03-01 20:34:05 [25472] [5] DEBUG: SMPP PDU 0x73fd40 dump:
2011-03-01 20:34:05 [25472] [5] DEBUG: type_name: deliver_sm
2011-03-01 20:34:05 [25472] [5] DEBUG: command_id: 5 = 0x00000005
2011-03-01 20:34:05 [25472] [5] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: sequence_number: 1 = 0x00000001
2011-03-01 20:34:05 [25472] [5] DEBUG: service_type: NULL
2011-03-01 20:34:05 [25472] [5] DEBUG: source_addr_ton: 2 = 0x00000002
2011-03-01 20:34:05 [25472] [5] DEBUG: source_addr_npi: 1 = 0x00000001
2011-03-01 20:34:05 [25472] [5] DEBUG: source_addr: "Info"
2011-03-01 20:34:05 [25472] [5] DEBUG: dest_addr_ton: 1 = 0x00000001
2011-03-01 20:34:05 [25472] [5] DEBUG: dest_addr_npi: 1 = 0x00000001
2011-03-01 20:34:05 [25472] [5] DEBUG: destination_addr: "34637788288"
2011-03-01 20:34:05 [25472] [5] DEBUG: esm_class: 4 = 0x00000004
2011-03-01 20:34:05 [25472] [5] DEBUG: protocol_id: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: priority_flag: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: schedule_delivery_time: NULL
2011-03-01 20:34:05 [25472] [5] DEBUG: validity_period: NULL
2011-03-01 20:34:05 [25472] [5] DEBUG: registered_delivery: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: replace_if_present_flag: 0 =
0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: data_coding: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: sm_default_msg_id: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: sm_length: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [5] DEBUG: short_message:
2011-03-01 20:34:05 [25472] [5] DEBUG: Octet string at 0x73a190:
2011-03-01 20:34:05 [25472] [5] DEBUG: len: 112
2011-03-01 20:34:05 [25472] [5] DEBUG: size: 1024
2011-03-01 20:34:05 [25472] [5] DEBUG: immutable: 0
2011-03-01 20:34:05 [25472] [5] DEBUG: data: 69 64 3a 32 32 38 63 64 66
39 62 20 73 75 62 3a id:228cdf9b sub:
2011-03-01 20:34:05 [25472] [5] DEBUG: data: 30 30 31 20 64 6c 76 72 64
3a 30 30 31 20 73 75 001 dlvrd:001 su
2011-03-01 20:34:05 [25472] [5] DEBUG: data: 62 6d 69 74 20 64 61 74 65
3a 31 31 30 33 30 31 bmit date:110301
2011-03-01 20:34:05 [25472] [5] DEBUG: data: 32 30 33 34 20 64 6f 6e 65
20 64 61 74 65 3a 31 2034 done date:1
2011-03-01 20:34:05 [25472] [5] DEBUG: data: 31 30 33 30 31 32 30 33 34
20 73 74 61 74 3a 44 103012034 stat:D
2011-03-01 20:34:05 [25472] [5] DEBUG: data: 45 4c 49 56 52 44 20 65 72
72 3a 30 30 30 20 74 ELIVRD err:000 t
2011-03-01 20:34:05 [25472] [5] DEBUG: data: 65 78 74 3a 20 20 20 20 20
20 20 20 20 20 20 20 ext:
2011-03-01 20:34:05 [25472] [5] DEBUG: Octet string dump ends.
2011-03-01 20:34:05 [25472] [5] DEBUG: message_state: 2 = 0x00000002
2011-03-01 20:34:05 [25472] [5] DEBUG: receipted_message_id: "228cdf9b"
2011-03-01 20:34:05 [25472] [5] DEBUG: dlr_err: "000"
2011-03-01 20:34:05 [25472] [5] DEBUG: SMPP PDU dump ends.
2011-03-01 20:34:05 [25472] [5] ERROR: SMPP: Unknown TLV `dlr_err', don't
send.
2011-03-01 20:34:05 [25472] [6] DEBUG: SMPP[ISMSAD]: Got PDU:
2011-03-01 20:34:05 [25472] [6] DEBUG: SMPP PDU 0x73fd40 dump:
2011-03-01 20:34:05 [25472] [6] DEBUG: type_name: deliver_sm_resp
2011-03-01 20:34:05 [25472] [6] DEBUG: command_id: 2147483653 = 0x80000005
2011-03-01 20:34:05 [25472] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 20:34:05 [25472] [6] DEBUG: sequence_number: 1 = 0x00000001
2011-03-01 20:34:05 [25472] [6] DEBUG: message_id: NULL
2011-03-01 20:34:05 [25472] [6] DEBUG: SMPP PDU dump ends.
----------------
On Tue, Mar 1, 2011 at 7:06 PM, Rene Kluwen <[email protected]> wrote:
Looks like the downstream SMSC (GMS in your case) turns things around.
Could you post some bearerbox logs of the offending message with log-level =
0?
== Rene
From: [email protected] [mailto:[email protected]] On Behalf
Of Dνdac Royo
Sent: Tuesday, 01 March, 2011 18:47
To: [email protected]
Subject: OpenSMPP+Kannel: DLR: (dst & src) are expected INVETED in the
deliver_sm (but remains as in submit_sm)
Hi Users,
I need your help.
We have a problem in our Kannel + openSMPPbox. The values of parameters: dst
& src are expected INVETED in the deliver_sm, I'm I correct?
In the logs source_addr & destination_addr have the same in both submit_sm
and deliver_sm operations (when we expect them inverted in the deliver_sm)
This is our log for the submit_sm:
2011-03-01 16:50:00 [634] [6] DEBUG: SMPP[ISMSAD]: Got PDU:
2011-03-01 16:50:00 [634] [6] DEBUG: SMPP PDU 0x73b700 dump:
2011-03-01 16:50:00 [634] [6] DEBUG: type_name: submit_sm
2011-03-01 16:50:00 [634] [6] DEBUG: command_id: 4 = 0x00000004
2011-03-01 16:50:00 [634] [6] DEBUG: command_status: 0 = 0x00000000
2011-03-01 16:50:00 [634] [6] DEBUG: sequence_number: 1404 = 0x0000057c
2011-03-01 16:50:00 [634] [6] DEBUG: service_type: NULL
2011-03-01 16:50:00 [634] [6] DEBUG: source_addr_ton: 5 = 0x00000005
2011-03-01 16:50:00 [634] [6] DEBUG: source_addr_npi: 0 = 0x00000000
2011-03-01 16:50:00 [634] [6] DEBUG: source_addr: "Info"
2011-03-01 16:50:00 [634] [6] DEBUG: dest_addr_ton: 1 = 0x00000001
2011-03-01 16:50:00 [634] [6] DEBUG: dest_addr_npi: 1 = 0x00000001
2011-03-01 16:50:00 [634] [6] DEBUG: destination_addr: "34695839615"
2011-03-01 16:50:00 [634] [6] DEBUG: esm_class: 3 = 0x00000003
2011-03-01 16:50:00 [634] [6] DEBUG: protocol_id: 0 = 0x00000000
2011-03-01 16:50:00 [634] [6] DEBUG: priority_flag: 0 = 0x00000000
2011-03-01 16:50:00 [634] [6] DEBUG: schedule_delivery_time: NULL
2011-03-01 16:50:00 [634] [6] DEBUG: validity_period: NULL
2011-03-01 16:50:00 [634] [6] DEBUG: registered_delivery: 1 = 0x00000001
2011-03-01 16:50:00 [634] [6] DEBUG: replace_if_present_flag: 0 =
0x00000000
2011-03-01 16:50:00 [634] [6] DEBUG: data_coding: 0 = 0x00000000
2011-03-01 16:50:00 [634] [6] DEBUG: sm_default_msg_id: 0 = 0x00000000
2011-03-01 16:50:00 [634] [6] DEBUG: sm_length: 10 = 0x0000000a
2011-03-01 16:50:00 [634] [6] DEBUG: short_message: "test 16:48"
2011-03-01 16:50:00 [634] [6] DEBUG: SMPP PDU dump ends.
and this is our log for the deiver_sm:
2011-03-01 16:50:04 [634] [5] DEBUG: SMPP[ISMSAD]: Sending PDU:
2011-03-01 16:50:04 [634] [5] DEBUG: SMPP PDU 0x73fd30 dump:
2011-03-01 16:50:04 [634] [5] DEBUG: type_name: deliver_sm
2011-03-01 16:50:04 [634] [5] DEBUG: command_id: 5 = 0x00000005
2011-03-01 16:50:04 [634] [5] DEBUG: command_status: 0 = 0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: sequence_number: 1 = 0x00000001
2011-03-01 16:50:04 [634] [5] DEBUG: service_type: NULL
2011-03-01 16:50:04 [634] [5] DEBUG: source_addr_ton: 2 = 0x00000002
2011-03-01 16:50:04 [634] [5] DEBUG: source_addr_npi: 1 = 0x00000001
2011-03-01 16:50:04 [634] [5] DEBUG: source_addr: "Info"
2011-03-01 16:50:04 [634] [5] DEBUG: dest_addr_ton: 1 = 0x00000001
2011-03-01 16:50:04 [634] [5] DEBUG: dest_addr_npi: 1 = 0x00000001
2011-03-01 16:50:04 [634] [5] DEBUG: destination_addr: "34695839615"
2011-03-01 16:50:04 [634] [5] DEBUG: esm_class: 4 = 0x00000004
2011-03-01 16:50:04 [634] [5] DEBUG: protocol_id: 0 = 0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: priority_flag: 0 = 0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: schedule_delivery_time: NULL
2011-03-01 16:50:04 [634] [5] DEBUG: validity_period: NULL
2011-03-01 16:50:04 [634] [5] DEBUG: registered_delivery: 0 = 0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: replace_if_present_flag: 0 =
0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: data_coding: 0 = 0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: sm_default_msg_id: 0 = 0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: sm_length: 0 = 0x00000000
2011-03-01 16:50:04 [634] [5] DEBUG: short_message:
2011-03-01 16:50:04 [634] [5] DEBUG: Octet string at 0x73a350:
2011-03-01 16:50:04 [634] [5] DEBUG: len: 112
2011-03-01 16:50:04 [634] [5] DEBUG: size: 1024
2011-03-01 16:50:04 [634] [5] DEBUG: immutable: 0
2011-03-01 16:50:04 [634] [5] DEBUG: data: 69 64 3a 33 30 37 32 30 66
30 36 20 73 75 62 3a id:30720f06 sub:
2011-03-01 16:50:04 [634] [5] DEBUG: data: 30 30 31 20 64 6c 76 72 64
3a 30 30 31 20 73 75 001 dlvrd:001 su
2011-03-01 16:50:04 [634] [5] DEBUG: data: 62 6d 69 74 20 64 61 74 65
3a 31 31 30 33 30 31 bmit date:110301
2011-03-01 16:50:04 [634] [5] DEBUG: data: 31 36 35 30 20 64 6f 6e 65
20 64 61 74 65 3a 31 1650 done date:1
2011-03-01 16:50:04 [634] [5] DEBUG: data: 31 30 33 30 31 31 36 35 30
20 73 74 61 74 3a 44 103011650 stat:D
2011-03-01 16:50:04 [634] [5] DEBUG: data: 45 4c 49 56 52 44 20 65 72
72 3a 30 30 30 20 74 ELIVRD err:000 t
2011-03-01 16:50:04 [634] [5] DEBUG: data: 65 78 74 3a 20 20 20 20 20
20 20 20 20 20 20 20 ext:
2011-03-01 16:50:04 [634] [5] DEBUG: Octet string dump ends.
2011-03-01 16:50:04 [634] [5] DEBUG: message_state: 2 = 0x00000002
2011-03-01 16:50:04 [634] [5] DEBUG: receipted_message_id: "30720f06"
2011-03-01 16:50:04 [634] [5] DEBUG: dlr_err: "000"
2011-03-01 16:50:04 [634] [5] DEBUG: SMPP PDU dump ends.
2011-03-01 16:50:04 [634] [5] ERROR: SMPP: Unknown TLV `dlr_err', don't
send.
and looking at bearerbox.access...
2011-03-01 16:50:00 Sent SMS [SMSC:GMS] [SVC:ismsad] [ACT:] [BINF:]
[FID:110301S00d1a44c] [META:?smpp?] [from:Info] [to:+34695839615]
[flags:-1:0:-1:0:19] [msg:10:test 16:48] [udh:0:]
2011-03-01 16:50:04 Receive DLR [SMSC:GMS] [SVC:ismsad] [ACT:sit2] [BINF:]
[FID:110301S00d1a44c] [META:?smpp?dlr_err=000&] [from:Info]
[to:+34695839615] [flags:-1:-1:-1:-1:1] [msg:111:id:110301S00d1a44c sub:000
dlvrd:000 submit date:1103011650 done date:1103011650 stat:DELIVRD err:000
text: ] [udh:0:]
What I'm doing wrong?
is there any known issue?
Any help is appreciated! please help!
Thanks guys!
Didac
