Hi,
Do you use latest smppbox svn? I remember that sometime back it had some ACK
issues and bb would resend SMS. But it has been fixed since.
BR,
Nikos
----- Original Message -----
From: Emmanuel CHANSON
To: users
Sent: Wednesday, October 13, 2010 7:21 AM
Subject: Strange behavior on kannel (fakesmsc + bearerbox + opensmppbox +
smppclient), more message than ordered sent from smppbox
Using Fakesmsc and Opensmppbox for load testing of an SMPP application I
notice strange behavior of Kannel (surrely bad configuration, I hope)
Fakesmsc <--> Bearerbox <--> Opensmppbox <--> Smpp client
Config file at the end:
Test: When I send 1 SMS from Fakesmsc (5656) to my SMPP application (1065)
this application answer back with a SMS to the original sender. ie for 1 SMS
sent from fakesmsc 1 should be received.
From fakesmsc I send 50 SMS with this command:
# /usr/bin/fakesmsc -r 10001 -H 127.0.0.1 -i 0.2 -m 50 "5656 1065 text 50
SMS"
Below output from a script that parse the log file under /var/log:
So I see exactly the 50 SMS sent to my smpp application (50 SMS also on its
side)
# /usr/bin/fakesmsc -r 10001 -H 127.0.0.1 -i 0.2 -m 50 "5656 1065 text 50
SMS"
2010-10-13 14:31:08 [29344] [0] INFO: Debug_lvl = -1, log_file = <none>,
log_lvl = 0
2010-10-13 14:31:08 [29344] [0] INFO: Host 127.0.0.1 Port 10001 interval
0.200 max-messages 50
2010-10-13 14:31:08 [29344] [0] INFO: fakesmsc starting
2010-10-13 14:31:08 [29344] [0] DEBUG: Connecting to <127.0.0.1>
2010-10-13 14:31:08 [29344] [0] DEBUG: fakesmsc: sent message 1
2010-10-13 14:31:08 [29344] [0] DEBUG: fakesmsc: sent message 2
...
2010-10-13 14:31:18 [29344] [0] DEBUG: fakesmsc: sent message 49
2010-10-13 14:31:18 [29344] [0] INFO: fakesmsc: sent message 50
2010-10-13 14:31:19 [29344] [0] DEBUG: Got message 1: <1065 5656 text 50
SMS>
2010-10-13 14:31:20 [29344] [0] DEBUG: Got message 2: <1065 5656 text 50
SMS>
...
2010-10-13 14:32:07 [29344] [0] DEBUG: Got message 49: <1065 5656 text 50
SMS>
2010-10-13 14:32:08 [29344] [0] INFO: Got message 50: <1065 5656 text 50
SMS>
# ./stat.sh
Bearerbox - Received SMS: 50 (cat bearerbox.log | grep "new
message" | wc -l)
Bearerbox - Sent SMS: 50 (cat bearerbox.log | grep
"sending message" | wc -l)
Access - Receive SMS: 50 (cat access.log | grep "Receive
SMS" | wc -l)
Access - Sent SMS: 50 (cat access.log | grep "Sent
SMS" | wc -l)
Smppbox - Deliver_sm: 50 (cat opensmppbox.log | grep
"deliver_sm" | wc -l)
Smppbox - Submit_sm: 50 (cat opensmppbox.log | grep
"submit_sm" | wc -l)
But some minutes after I see new messages sent from kannel (not from
fakesmsc), 31 more !!
...
2010-10-13 14:37:31 [29344] [0] DEBUG: Got message 51: <1065 5656 text 50
SMS>
2010-10-13 14:37:32 [29344] [0] DEBUG: Got message 52: <1065 5656 text 50
SMS>
...
2010-10-13 14:38:00 [29344] [0] DEBUG: Got message 80: <1065 5656 text 50
SMS>
2010-10-13 14:38:01 [29344] [0] DEBUG: Got message 81: <1065 5656 text 50
SMS>
I close fakesmsc:
^C2010-10-13 14:55:59 [29344] [0] INFO: fakesmsc: 50 messages sent and 81
received
2010-10-13 14:55:59 [29344] [0] INFO: fakesmsc: total running time 1490.5
seconds
2010-10-13 14:55:59 [29344] [0] INFO: fakesmsc: from first to last sent
message 9.8 s, 5.0 msgs/s
2010-10-13 14:55:59 [29344] [0] INFO: fakesmsc: from first to last received
message 402.0 s, 0.2 msgs/s
2010-10-13 14:55:59 [29344] [0] INFO: fakesmsc: terminating
#
logs parsed by the script stat.sh
# ./stat.sh
Bearerbox - Received SMS: 50
Bearerbox - Sent SMS: 81 --> bearerbox sent 31 new messages to
fakesmsc !!!!
Access - Receive SMS: 50
Access - Sent SMS: 81 --> 31 new messages logged in access.log
Smppbox - Deliver_sm: 81 --> smppbox received these 31 new
messages forward them to smpp client
Smppbox - Submit_sm: 81 --> and smppclient answer back with 31
new message going to fakesmsc
From where comes theses messages ?
It seems it is smppbox that seems to receive 31 new messages but from where
????!
I check in detail opensmppbox.log: Ifound that smppbox shutdown and
restarted after the 50 messages have been sent at 14:32, 4 minutes later it
restarted:
2010-10-13 14:32:08 [25805] [267] DEBUG: message_id: "b91ac635"
2010-10-13 14:32:08 [25805] [267] DEBUG: SMPP PDU dump ends.
2010-10-13 14:36:21 [25805] [266] DEBUG: Thread 266
(opensmppbox.c:smpp_to_bearerbox) terminates.
2010-10-13 14:36:21 [25805] [265] DEBUG: Thread 265 (opensmppbox.c:function)
terminates.
2010-10-13 14:36:21 [25805] [0] DEBUG: Started thread 269
(opensmppbox.c:function)
2010-10-13 14:36:21 [25805] [269] DEBUG: Thread 269 (opensmppbox.c:function)
maps to pid 25805.
2010-10-13 14:36:21 [25805] [269] INFO: Client connected from
<163.176.17.238>
2010-10-13 14:36:21 [25805] [269] DEBUG: Connecting to <127.0.0.1>
2010-10-13 14:36:21 [25805] [269] INFO: Connected to bearerbox at localhost
port 13001.
2010-10-13 14:36:21 [25805] [269] DEBUG: Started thread 270
(opensmppbox.c:smpp_to_bearerbox)
2010-10-13 14:36:21 [25805] [270] DEBUG: Thread 270
(opensmppbox.c:smpp_to_bearerbox) maps to pid 25805.
2010-10-13 14:36:26 [25805] [270] DEBUG: SMPP[smppbox]: Got PDU:
2010-10-13 14:36:26 [25805] [270] DEBUG: SMPP PDU 0xb2f814b0 dump:
2010-10-13 14:36:26 [25805] [270] DEBUG: type_name: bind_receiver
2010-10-13 14:36:26 [25805] [270] DEBUG: command_id: 1 = 0x00000001
2010-10-13 14:36:26 [25805] [270] DEBUG: command_status: 0 = 0x00000000
2010-10-13 14:36:26 [25805] [270] DEBUG: sequence_number: 1 = 0x00000001
2010-10-13 14:36:26 [25805] [270] DEBUG: system_id: "mmg"
2010-10-13 14:36:26 [25805] [270] DEBUG: password: "mmg"
2010-10-13 14:36:26 [25805] [270] DEBUG: system_type: "mmg"
2010-10-13 14:36:26 [25805] [270] DEBUG: interface_version: 52 =
0x00000034
2010-10-13 14:36:26 [25805] [270] DEBUG: addr_ton: 0 = 0x00000000
2010-10-13 14:36:26 [25805] [270] DEBUG: addr_npi: 0 = 0x00000000
2010-10-13 14:36:26 [25805] [270] DEBUG: address_range: NULL
2010-10-13 14:36:26 [25805] [270] DEBUG: SMPP PDU dump ends.
2010-10-13 14:36:26 [25805] [270] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-13 14:36:26 [25805] [270] DEBUG: SMPP PDU 0xb2f82258 dump:
2010-10-13 14:36:26 [25805] [270] DEBUG: type_name: bind_receiver_resp
2010-10-13 14:36:26 [25805] [270] DEBUG: command_id: 2147483649 =
0x80000001
2010-10-13 14:36:26 [25805] [270] DEBUG: command_status: 0 = 0x00000000
2010-10-13 14:36:26 [25805] [270] DEBUG: sequence_number: 1 = 0x00000001
2010-10-13 14:36:26 [25805] [270] DEBUG: system_id: "opensmppbox"
2010-10-13 14:36:26 [25805] [270] DEBUG: SMPP PDU dump ends.
2010-10-13 14:37:10 [25805] [268] DEBUG: Thread 268
(opensmppbox.c:smpp_to_bearerbox) terminates.
2010-10-13 14:37:10 [25805] [267] DEBUG: Thread 267 (opensmppbox.c:function)
terminates.
2010-10-13 14:37:10 [25805] [269] INFO: We received an SMS message.
2010-10-13 14:37:10 [25805] [269] DEBUG: message length 6, sending 1 message
2010-10-13 14:37:10 [25805] [269] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-13 14:37:10 [25805] [269] DEBUG: SMPP PDU 0xb2f855d0 dump:
2010-10-13 14:37:10 [25805] [269] DEBUG: type_name: deliver_sm
2010-10-13 14:37:10 [25805] [269] DEBUG: command_id: 5 = 0x00000005
2010-10-13 14:37:10 [25805] [269] DEBUG: command_status: 0 = 0x00000000
2010-10-13 14:37:10 [25805] [269] DEBUG: sequence_number: 0 = 0x00000000
2010-10-13 14:37:10 [25805] [269] DEBUG: service_type: NULL
2010-10-13 14:37:10 [25805] [269] DEBUG: source_addr_ton: 2 = 0x00000002
2010-10-13 14:37:10 [25805] [269] DEBUG: source_addr_npi: 1 = 0x00000001
2010-10-13 14:37:10 [25805] [269] DEBUG: source_addr: "5656"
2010-10-13 14:37:10 [25805] [269] DEBUG: dest_addr_ton: 2 = 0x00000002
2010-10-13 14:37:10 [25805] [269] DEBUG: dest_addr_npi: 1 = 0x00000001
2010-10-13 14:37:10 [25805] [269] DEBUG: destination_addr: "1065"
Config file:
kannel;conf:
...
# SMSC Fake
group = smsc
smsc = fake
smsc-id = "FakeSMSC-1"
allowed-smsc-id = "FakeSMSC-1"
host = localhost
port = 10001
group = smsbox-route
smsbox-id = mmg
smsc-id = FakeSMSC-1
opensmppbox.conf:
...
group = core
dlr-storage = mysql
# this group defines your opensmppbox
group = opensmppbox
# our boxc type
opensmppbox-id = smppbox
# the port to listen on for smpp connections
opensmppbox-port = 6201
# we connect to the following host as a box
bearerbox-host = localhost
bearerbox-port = 13001
log-level = 0
log-file = /var/log/kannel/opensmppbox.log
our-system-id = opensmppbox
route-to-smsc = FakeSMSC-1
# see sample smpplogins.txt
smpp-logins = "/etc/kannel/smpplogins.txt"
smpplogins.txt
mmg mmg mmg
Regards,
Emmanuel
