Well, I have lost you. However, smppbox doesn't have a store. So, if you are
saying that you restart it and sends additional SMS, these are coming from
somewhere else. Follow the log trail and you can find out who is to blame.
If it turns out it is smppbox, Rene is your man.
BR,
Nikos
----- Original Message -----
From: Emmanuel CHANSON
To: Nikos Balkanas
Cc: users
Sent: Thursday, October 14, 2010 2:21 AM
Subject: Re: Strange behavior on kannel (fakesmsc + bearerbox + opensmppbox
+ smppclient), more message than ordered sent from smppbox
Hum load testing of a SMS gateway connected to a http application that
answer back to each SMS.
Kannel system --> SMS GW Y --> Application Z (answer back SMS).
I want to inject SMS into this SMS GW Y that forward them to an application
and this application answer back for each SMS.
Link between Kannel and SMS GW Y that is here an smpp client is SMPP.
I keep fake SMSc to:
- 1st idea send and receive SMS (but maybe an issue with fakesmsc client
that does not send normal packet to opensmppbox)
- 2nd idea use smsbox cgi script and fakesmsc/fakesmsc client to receive SMS
Fakesmsc is not the problem in the second idea because I dont use it to
inject SMS.
There is something really strange with opensmppbox:
Test done with 5 SMS
2 additionnal SMS received 5 minutes after the last SMS sent.
Opensmppbox restart when receiving a bind transmitter from smpp client and
respond with a bind-resp then start to send additionnal SMS.
ackowledgement have been received for the last 5 SMS so it is not the
problem
Bearerbox - Received SMS: 0
Bearerbox - Sent SMS: 0
Access - Receive SMS: 5
Access - Sent SMS: 5
Smppbox - Deliver_sm: 7
Smppbox - Deliver_sm_resp: 7
Smppbox - Submit_sm: 7
Smppbox - Submit_sm_resp: 7
opensmppbox.log:
--------------------------
2010-10-14 09:50:45 [12368] [0] INFO: Added logfile
`/var/log/kannel/opensmppbox.log' with level `0'.
2010-10-14 09:50:45 [12368] [0] INFO: Waiting for SMPP connections on port
6201.
2010-10-14 09:50:47 [12368] [0] DEBUG: Started thread 1
(opensmppbox.c:function)
2010-10-14 09:50:47 [12368] [1] DEBUG: Thread 1 (opensmppbox.c:function)
maps to pid 12368.
2010-10-14 09:50:47 [12368] [1] INFO: Client connected from <163.176.17.238>
2010-10-14 09:50:47 [12368] [1] DEBUG: Connecting to <127.0.0.1>
2010-10-14 09:50:47 [12368] [1] INFO: Connected to bearerbox at localhost
port 13001.
2010-10-14 09:50:47 [12368] [1] DEBUG: Started thread 2
(opensmppbox.c:smpp_to_bearerbox)
2010-10-14 09:50:47 [12368] [2] DEBUG: Thread 2
(opensmppbox.c:smpp_to_bearerbox) maps to pid 12368.
2010-10-14 09:50:52 [12368] [0] DEBUG: Started thread 3
(opensmppbox.c:function)
2010-10-14 09:50:52 [12368] [3] DEBUG: Thread 3 (opensmppbox.c:function)
maps to pid 12368.
2010-10-14 09:50:52 [12368] [3] INFO: Client connected from <163.176.17.238>
2010-10-14 09:50:52 [12368] [3] DEBUG: Connecting to <127.0.0.1>
2010-10-14 09:50:52 [12368] [3] INFO: Connected to bearerbox at localhost
port 13001.
2010-10-14 09:50:52 [12368] [3] DEBUG: Started thread 4
(opensmppbox.c:smpp_to_bearerbox)
2010-10-14 09:50:52 [12368] [4] DEBUG: Thread 4
(opensmppbox.c:smpp_to_bearerbox) maps to pid 12368.
2010-10-14 09:50:52 [12368] [4] DEBUG: SMPP[smppbox]: Got PDU:
2010-10-14 09:50:52 [12368] [4] DEBUG: SMPP PDU 0x922aeb8 dump:
2010-10-14 09:50:52 [12368] [4] DEBUG: type_name: bind_transmitter
2010-10-14 09:50:52 [12368] [4] DEBUG: command_id: 2 = 0x00000002
2010-10-14 09:50:52 [12368] [4] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [4] DEBUG: sequence_number: 1 = 0x00000001
2010-10-14 09:50:52 [12368] [4] DEBUG: system_id: "mmg"
2010-10-14 09:50:52 [12368] [4] DEBUG: password: "mmg"
2010-10-14 09:50:52 [12368] [4] DEBUG: system_type: "mmg"
2010-10-14 09:50:52 [12368] [4] DEBUG: interface_version: 52 = 0x00000034
2010-10-14 09:50:52 [12368] [4] DEBUG: addr_ton: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [4] DEBUG: addr_npi: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [4] DEBUG: address_range: NULL
2010-10-14 09:50:52 [12368] [4] DEBUG: SMPP PDU dump ends.
2010-10-14 09:50:52 [12368] [4] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-14 09:50:52 [12368] [4] DEBUG: SMPP PDU 0x922f008 dump:
2010-10-14 09:50:52 [12368] [4] DEBUG: type_name: bind_transmitter_resp
2010-10-14 09:50:52 [12368] [4] DEBUG: command_id: 2147483650 = 0x80000002
2010-10-14 09:50:52 [12368] [4] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [4] DEBUG: sequence_number: 1 = 0x00000001
2010-10-14 09:50:52 [12368] [4] DEBUG: system_id: "opensmppbox"
2010-10-14 09:50:52 [12368] [4] DEBUG: SMPP PDU dump ends.
2010-10-14 09:50:52 [12368] [2] DEBUG: SMPP[smppbox]: Got PDU:
2010-10-14 09:50:52 [12368] [2] DEBUG: SMPP PDU 0xb5701d08 dump:
2010-10-14 09:50:52 [12368] [2] DEBUG: type_name: bind_receiver
2010-10-14 09:50:52 [12368] [2] DEBUG: command_id: 1 = 0x00000001
2010-10-14 09:50:52 [12368] [2] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [2] DEBUG: sequence_number: 1 = 0x00000001
2010-10-14 09:50:52 [12368] [2] DEBUG: system_id: "mmg"
2010-10-14 09:50:52 [12368] [2] DEBUG: password: "mmg"
2010-10-14 09:50:52 [12368] [2] DEBUG: system_type: "mmg"
2010-10-14 09:50:52 [12368] [2] DEBUG: interface_version: 52 = 0x00000034
2010-10-14 09:50:52 [12368] [2] DEBUG: addr_ton: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [2] DEBUG: addr_npi: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [2] DEBUG: address_range: NULL
2010-10-14 09:50:52 [12368] [2] DEBUG: SMPP PDU dump ends.
2010-10-14 09:50:52 [12368] [2] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-14 09:50:52 [12368] [2] DEBUG: SMPP PDU 0xb5701f70 dump:
2010-10-14 09:50:52 [12368] [2] DEBUG: type_name: bind_receiver_resp
2010-10-14 09:50:52 [12368] [2] DEBUG: command_id: 2147483649 = 0x80000001
2010-10-14 09:50:52 [12368] [2] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:50:52 [12368] [2] DEBUG: sequence_number: 1 = 0x00000001
2010-10-14 09:50:52 [12368] [2] DEBUG: system_id: "opensmppbox"
2010-10-14 09:50:52 [12368] [2] DEBUG: SMPP PDU dump ends.
2010-10-14 09:51:36 [12368] [3] INFO: We received an SMS message.
2010-10-14 09:51:36 [12368] [3] DEBUG: message length 5, sending 1 message
2010-10-14 09:51:36 [12368] [3] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-14 09:51:36 [12368] [3] DEBUG: SMPP PDU 0xb5702968 dump:
2010-10-14 09:51:36 [12368] [3] DEBUG: type_name: deliver_sm
2010-10-14 09:51:36 [12368] [3] DEBUG: command_id: 5 = 0x00000005
2010-10-14 09:51:36 [12368] [3] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: sequence_number: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: service_type: NULL
2010-10-14 09:51:36 [12368] [3] DEBUG: source_addr_ton: 2 = 0x00000002
2010-10-14 09:51:36 [12368] [3] DEBUG: source_addr_npi: 1 = 0x00000001
2010-10-14 09:51:36 [12368] [3] DEBUG: source_addr: "5656"
2010-10-14 09:51:36 [12368] [3] DEBUG: dest_addr_ton: 2 = 0x00000002
2010-10-14 09:51:36 [12368] [3] DEBUG: dest_addr_npi: 1 = 0x00000001
2010-10-14 09:51:36 [12368] [3] DEBUG: destination_addr: "1065"
2010-10-14 09:51:36 [12368] [3] DEBUG: esm_class: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: protocol_id: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: priority_flag: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: schedule_delivery_time: NULL
2010-10-14 09:51:36 [12368] [3] DEBUG: validity_period: NULL
2010-10-14 09:51:36 [12368] [3] DEBUG: registered_delivery: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: replace_if_present_flag: 0 =
0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: data_coding: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: sm_default_msg_id: 0 = 0x00000000
2010-10-14 09:51:36 [12368] [3] DEBUG: sm_length: 5 = 0x00000005
2010-10-14 09:51:36 [12368] [3] DEBUG: short_message: "SMS-1"
2010-10-14 09:51:36 [12368] [3] DEBUG: SMPP PDU dump ends.
2010-10-14 09:51:36 [12368] [1] INFO: We received an SMS message.
2010-10-14 09:51:36 [12368] [1] DEBUG: message length 5, sending 1 message
2010-10-14 09:51:36 [12368] [1] DEBUG: SMPP[mmg]: Sending PDU:
...
sending the 5 SMS
...
2010-10-14 09:51:47 [12368] [4] DEBUG: Octet string dump ends.
2010-10-14 09:51:47 [12368] [4] DEBUG: sms.binfo:
2010-10-14 09:51:47 [12368] [4] DEBUG: sms.msg_left: -1
2010-10-14 09:51:47 [12368] [4] DEBUG: sms.split_parts: (nil)
2010-10-14 09:51:47 [12368] [4] DEBUG: sms.priority: 0
2010-10-14 09:51:47 [12368] [4] DEBUG: sms.resend_try: -1
2010-10-14 09:51:47 [12368] [4] DEBUG: sms.resend_time: -1
2010-10-14 09:51:47 [12368] [4] DEBUG: sms.meta_data:
2010-10-14 09:51:47 [12368] [4] DEBUG: Octet string at 0x922f028:
2010-10-14 09:51:47 [12368] [4] DEBUG: len: 6
2010-10-14 09:51:47 [12368] [4] DEBUG: size: 1024
2010-10-14 09:51:47 [12368] [4] DEBUG: immutable: 0
2010-10-14 09:51:47 [12368] [4] DEBUG: data: 3f 73 6d 70 70 3f
?smpp?
2010-10-14 09:51:47 [12368] [4] DEBUG: Octet string dump ends.
2010-10-14 09:51:47 [12368] [4] DEBUG: Msg object ends.
2010-10-14 09:51:47 [12368] [3] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-14 09:51:47 [12368] [3] DEBUG: SMPP PDU 0x922e5d0 dump:
2010-10-14 09:51:47 [12368] [3] DEBUG: type_name: submit_sm_resp
2010-10-14 09:51:47 [12368] [3] DEBUG: command_id: 2147483652 = 0x80000004
2010-10-14 09:51:47 [12368] [3] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:51:47 [12368] [3] DEBUG: sequence_number: 6 = 0x00000006
2010-10-14 09:51:47 [12368] [3] DEBUG: message_id: "0e6646e5"
2010-10-14 09:51:47 [12368] [3] DEBUG: SMPP PDU dump ends.
...
end: 5 SMS sent but 5 minutes later 2 SMS are sent again
...
2010-10-14 09:56:40 [12368] [2] DEBUG: Thread 2
(opensmppbox.c:smpp_to_bearerbox) terminates.
2010-10-14 09:56:40 [12368] [1] DEBUG: Thread 1 (opensmppbox.c:function)
terminates.
2010-10-14 09:56:40 [12368] [0] DEBUG: Started thread 5
(opensmppbox.c:function)
2010-10-14 09:56:40 [12368] [5] DEBUG: Thread 5 (opensmppbox.c:function)
maps to pid 12368.
2010-10-14 09:56:40 [12368] [5] INFO: Client connected from <163.176.17.238>
2010-10-14 09:56:40 [12368] [5] DEBUG: Connecting to <127.0.0.1>
2010-10-14 09:56:40 [12368] [5] INFO: Connected to bearerbox at localhost
port 13001.
2010-10-14 09:56:40 [12368] [5] DEBUG: Started thread 6
(opensmppbox.c:smpp_to_bearerbox)
2010-10-14 09:56:40 [12368] [6] DEBUG: Thread 6
(opensmppbox.c:smpp_to_bearerbox) maps to pid 12368.
2010-10-14 09:56:46 [12368] [6] DEBUG: SMPP[smppbox]: Got PDU:
2010-10-14 09:56:46 [12368] [6] DEBUG: SMPP PDU 0xb5701d08 dump:
2010-10-14 09:56:46 [12368] [6] DEBUG: type_name: bind_receiver
2010-10-14 09:56:46 [12368] [6] DEBUG: command_id: 1 = 0x00000001
2010-10-14 09:56:46 [12368] [6] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:56:46 [12368] [6] DEBUG: sequence_number: 1 = 0x00000001
2010-10-14 09:56:46 [12368] [6] DEBUG: system_id: "mmg"
2010-10-14 09:56:46 [12368] [6] DEBUG: password: "mmg"
2010-10-14 09:56:46 [12368] [6] DEBUG: system_type: "mmg"
2010-10-14 09:56:46 [12368] [6] DEBUG: interface_version: 52 = 0x00000034
2010-10-14 09:56:46 [12368] [6] DEBUG: addr_ton: 0 = 0x00000000
2010-10-14 09:56:46 [12368] [6] DEBUG: addr_npi: 0 = 0x00000000
2010-10-14 09:56:46 [12368] [6] DEBUG: address_range: NULL
2010-10-14 09:56:46 [12368] [6] DEBUG: SMPP PDU dump ends.
2010-10-14 09:56:46 [12368] [6] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-14 09:56:46 [12368] [6] DEBUG: SMPP PDU 0xb5702900 dump:
2010-10-14 09:56:46 [12368] [6] DEBUG: type_name: bind_receiver_resp
2010-10-14 09:56:46 [12368] [6] DEBUG: command_id: 2147483649 = 0x80000001
2010-10-14 09:56:46 [12368] [6] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:56:46 [12368] [6] DEBUG: sequence_number: 1 = 0x00000001
2010-10-14 09:56:46 [12368] [6] DEBUG: system_id: "opensmppbox"
2010-10-14 09:56:46 [12368] [6] DEBUG: SMPP PDU dump ends.
2010-10-14 09:56:49 [12368] [4] DEBUG: Thread 4
(opensmppbox.c:smpp_to_bearerbox) terminates.
2010-10-14 09:56:49 [12368] [3] DEBUG: Thread 3 (opensmppbox.c:function)
terminates.
2010-10-14 09:56:49 [12368] [5] INFO: We received an SMS message.
2010-10-14 09:56:49 [12368] [5] DEBUG: message length 5, sending 1 message
2010-10-14 09:56:49 [12368] [5] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-14 09:56:49 [12368] [5] DEBUG: SMPP PDU 0xb6d02378 dump:
2010-10-14 09:56:49 [12368] [5] DEBUG: type_name: deliver_sm
2010-10-14 09:56:49 [12368] [5] DEBUG: command_id: 5 = 0x00000005
2010-10-14 09:56:49 [12368] [5] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: sequence_number: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: service_type: NULL
2010-10-14 09:56:49 [12368] [5] DEBUG: source_addr_ton: 2 = 0x00000002
2010-10-14 09:56:49 [12368] [5] DEBUG: source_addr_npi: 1 = 0x00000001
2010-10-14 09:56:49 [12368] [5] DEBUG: source_addr: "5656"
2010-10-14 09:56:49 [12368] [5] DEBUG: dest_addr_ton: 2 = 0x00000002
2010-10-14 09:56:49 [12368] [5] DEBUG: dest_addr_npi: 1 = 0x00000001
2010-10-14 09:56:49 [12368] [5] DEBUG: destination_addr: "1065"
2010-10-14 09:56:49 [12368] [5] DEBUG: esm_class: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: protocol_id: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: priority_flag: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: schedule_delivery_time: NULL
2010-10-14 09:56:49 [12368] [5] DEBUG: validity_period: NULL
2010-10-14 09:56:49 [12368] [5] DEBUG: registered_delivery: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: replace_if_present_flag: 0 =
0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: data_coding: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: sm_default_msg_id: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: sm_length: 5 = 0x00000005
2010-10-14 09:56:49 [12368] [5] DEBUG: short_message: "SMS-5"
2010-10-14 09:56:49 [12368] [5] DEBUG: SMPP PDU dump ends.
2010-10-14 09:56:49 [12368] [5] INFO: We received an SMS message.
2010-10-14 09:56:49 [12368] [5] DEBUG: message length 5, sending 1 message
2010-10-14 09:56:49 [12368] [5] DEBUG: SMPP[mmg]: Sending PDU:
2010-10-14 09:56:49 [12368] [5] DEBUG: SMPP PDU 0xb6d02478 dump:
2010-10-14 09:56:49 [12368] [5] DEBUG: type_name: deliver_sm
2010-10-14 09:56:49 [12368] [5] DEBUG: command_id: 5 = 0x00000005
2010-10-14 09:56:49 [12368] [5] DEBUG: command_status: 0 = 0x00000000
2010-10-14 09:56:49 [12368] [5] DEBUG: sequence_number: 1 = 0x00000001
2010-10-14 09:56:49 [12368] [5] DEBUG: service_type: NULL
2010-10-14 09:56:49 [12368] [5] DEBUG: source_addr_ton: 2 = 0x00000002
2010-10-14 09:56:49 [12368] [5] DEBUG: source_addr_npi: 1 = 0x00000001
...
2010/10/14 Nikos Balkanas <nbalka...@gmail.com>
This is a different thing from what you were asking:
SMPP AO -> smbbbox -> bb -> loopback -> bb -> smppbox -> SMPP AT
Why keep FAKE smsc in the loop? What are you trying to do?
BR,
Nikos
----- Original Message ----- From: Emmanuel CHANSON
To: Nikos Balkanas ; users
Sent: Thursday, October 14, 2010 1:42 AM
Subject: Re: Strange behavior on kannel (fakesmsc + bearerbox + opensmppbox
+ smppclient), more message than ordered sent from smppbox
Arf... I sent this mail too fast...
I receive 5 minutes later additionnal SMS too...using smsbox
So little bit disappointed here...
Emmanuel
2010/10/14 Emmanuel CHANSON <emmanuelchan...@gmail.com>
Ok Nikos,
I followed your suggestion and tried using smsbox CGI script that should
send normal packet to opensmppbox, in this case I used a different
architecture:
cgi --> smsbox --> bearerbox <---> loopback smsc ---> opensmppbox <---> smpp
client
and when my smpp client answer back:
smpp client ---> opensmppbox <---> Fake SMSC ---> bearerbox ---> fake smsc
client
It seems to to the trick and I dont have any more additionnal SMS sent from
opensmppbox :)
The thing is with fakesmsc client I could control the throuput of SMS sent.
Do you think throuput parameter works with loopback smsc ?
Otherwise I can use a delay in my cgi script :).
In any case thanks to have pointed this issue with fakesmsc/fakesmsc client
that seems to send malformed packet.
I succeed to build my lab using all this kannel modules :)
Emmanuel
2010/10/14 Nikos Balkanas <nbalka...@gmail.com>
Emmanuel,
You are running FAKE smsc in a non-standard way. It will only work when the
fakesmsc client is connected, and when sending from the client, it is meant
to send them back to the client. Instead you are redirecting to smppbox. I
don't know if that will work. I think that the client doesn't send normal
packets to FAKE smsc. It would stand to reason that fakesmsc doesn't respond
with normal packages to the client, or in this case smppbox. Poor smppbox
could get fits over it ;-). Check your packets and smppbox logs.
BR,
Nikos
----- Original Message ----- From: Emmanuel CHANSON
To: Nikos Balkanas ; users
Sent: Thursday, October 14, 2010 12:32 AM
Subject: Re: Strange behavior on kannel (fakesmsc + bearerbox + opensmppbox
+ smppclient), more message than ordered sent from smppbox
I am still trying to understand the issue.
Running a test where fakesmsc sent 20+50+500 SMS I got a freeze on smppbox
after lets's 5 minutes:
smppbox only sent 394 SMS to smppclient
# ./stat.sh
Bearerbox - Received SMS: 570
Bearerbox - Sent SMS: 294
Access - Receive SMS: 570
Access - Sent SMS: 294
Smppbox - Deliver_sm: 394
Smppbox - Deliver_sm_resp: 394
Smppbox - Submit_sm: 294
Smppbox - Submit_sm_resp: 294
#
Suddenly I saw all the remaining SMS sent from smppbox to smppclient in one
two seconds, and 100 SMS more than what I have ordered (with message from
the first (20 SMS) and second (50 SMS) test.
# ./stat.sh
Bearerbox - Received SMS: 570
Bearerbox - Sent SMS: 394
Access - Receive SMS: 570
Access - Sent SMS: 394
Smppbox - Deliver_sm: 670
Smppbox - Deliver_sm_resp: 670
Smppbox - Submit_sm: 394
Smppbox - Submit_sm_resp: 394
#
At the end I got 100 unordered SMS sent arrived on fakesmsc (because smppbox
sent these new 100 SMS to my smppclient and answer back for each SMS
received):
Bearerbox - Received SMS: 570
Bearerbox - Sent SMS: 670
Access - Receive SMS: 570
Access - Sent SMS: 670
Smppbox - Deliver_sm: 670
Smppbox - Deliver_sm_resp: 670
Smppbox - Submit_sm: 670
Smppbox - Submit_sm_resp: 670
Please can someone confirm this behavior ?
It is an issue and load testing can not be done using SMPPbox
Or something is wrong in my Kannel architecture.
Can you give me some pointers in order to investiguate more if no one can
reproduce this ?
Regards,
Emmanuel
2010/10/13 Emmanuel CHANSON <emmanuelchan...@gmail.com>
Yes Nikos,
I downloaded and installed kannel & opensmppbox this week from SVN site.
Emmanuel
2010/10/13 Nikos Balkanas <nbalka...@gmail.com>
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
