Hi Stipe, I made the stress test again with my operator. This time I set loglevel to 0, I changed throughput and max-pending-submits; but this did not resolve the issue, the only difference is the problem takes place in different messages, for example:
sequence number: 17074 sequence number: 17075 sequence number: 17076 sequence number: 17077 sequence number (_resp) : 4775 ***error*** sequence number: 17078 sequence number (_resp) : 4776 ***error*** sequence number: 17079 .... sequence number: 17191 sequence number: 17192 sequence number: 17193 sequence number (_resp) : 4777 ***error*** sequence number: 17194 sequence number: 17195 sequence number (_resp) : 4778 ***error*** (I´m attaching part of the log showing where the problem starts) The values I used in my test where: Test 1 Throughput = 7 max-pending-submits = 60 Test 2 Throughput = 20 max-pending-submits = 60 Test 1 Throughput = 10 max-pending-submits = 60 The only difference is the sequence number where the problem occurs, with the different throughput and max-pending-submits combination. After doing several tests with the operator, I decided to test kannel with a SMSC simulator (Logica's SMSC Simulator), sending even more messages than the operator sent me in the test (Actually I sent up to 200 msgs/sec), kannel didn't have any problem. I compared the sequences numbers, and checked that Kannel accepted and answered correctly, this discard a race-condition, I think it's a problem in the SMSC side, but they insist that it's in my side, I'd like to ask you what can I ask the operator to check in their SMSC, and solve this issue? Any clue will be highly appreciated. Thanks for your help. Mario -----Mensaje original----- De: Stipe Tolj [mailto:[EMAIL PROTECTED] Enviado el: Jueves, 15 de Septiembre de 2005 8:50 Para: [EMAIL PROTECTED] CC: [email protected] Asunto: Re: devel Digest, Vol 21, Issue 7 Mario Noboa wrote: > Hi Stipe, few days ago i did a stress test with an operator, kannel worked > very well with 30 msg/s. But i had problems with more than 40 msg/s in a > smpp conexion. I set throughput=6 and max-pending-submits=50 but didn't > work. > > This error appears for each messange sent: > > 2005-09-02 11:15:51 [11943] [11] WARNING: SMPP[COM]: SMSC sent > submit_sm_resp with wrong sequence number 0x0001001d > > I have a CPU system with 2 Gb and 1200 MHz. How would i configure kannel for > this stress test? Hi Mario, now in terms of this WARNING, it means, Kannel received an submit_sm_resp PDU from the SMPP SMSC with a sequence number that was not within the dictonary of "still open" sequence number PDUs. Obviously there may be 2 possible reasons: a) a race-condition within the Kannel handling. Actually bearerbox transmitting the submit_sm PDU and receiving the _resp PDU "faster" then being able to drop the message in the "still open dictonary". Which is almost uncertain, due to the amount of only 50 msg/sec. b) a problem on the SMSC side itself. Which seems more reasonable. I'd suggest that you do various tests on there again and try to circle in the problem scope. I do assume that you may not be able to reproduce the effect on a determenestic base, right? Stipe mailto:stolj_{at}_wapme-group.de ------------------------------------------------------------------- Wapme Systems AG Vogelsanger Weg 80 40470 Düsseldorf, NRW, Germany phone: +49.211.74845.0 fax: +49.211.74845.299 mailto:info_{at}_wapme-systems.de http://www.wapme-systems.de/ -------------------------------------------------------------------
2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced source addr ton = 4, source add npi = 6 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced dest addr ton = 1, dest add npi = 1 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Sending PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: submit_sm 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 17076 = 0x000042b4 2005-10-28 10:43:52 [1702] [7] DEBUG: service_type: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_ton: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_npi: 6 = 0x00000006 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr: "52600" 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_ton: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: got ack 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_npi: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: destination_addr: "573113839941" 2005-10-28 10:43:52 [1702] [7] DEBUG: esm_class: 3 = 0x00000003 2005-10-28 10:43:52 [1702] [7] DEBUG: protocol_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: priority_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: schedule_delivery_time: NULL 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: sms received 2005-10-28 10:43:52 [1702] [7] DEBUG: validity_period: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: registered_delivery: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: replace_if_present_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: data_coding: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_length: 9 = 0x00000009 2005-10-28 10:43:52 [1702] [7] DEBUG: short_message: "Respuesta" 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Got PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: deliver_sm 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 5 = 0x00000005 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 6503 = 0x00001967 2005-10-28 10:43:52 [1702] [7] DEBUG: service_type: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_ton: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_npi: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr: "573113839941" 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_ton: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_npi: 6 = 0x00000006 2005-10-28 10:43:52 [1702] [7] DEBUG: destination_addr: "52600" 2005-10-28 10:43:52 [1702] [7] DEBUG: esm_class: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: protocol_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: priority_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: schedule_delivery_time: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: validity_period: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: registered_delivery: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: replace_if_present_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: data_coding: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_length: 8 = 0x00000008 2005-10-28 10:43:52 [1702] [7] DEBUG: short_message: "loopback" 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [11] DEBUG: send_msg: sending msg to box: <127.0.0.1> 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: got ack 2005-10-28 10:43:52 [1702] [12] DEBUG: send_msg: sending msg to box: <127.0.0.1> 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: sms received 2005-10-28 10:43:52 [1702] [12] DEBUG: boxc_sender: sent message to <127.0.0.1> 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Sending PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e2a1b8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: deliver_sm_resp 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 2147483653 = 0x80000005 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 6503 = 0x00001967 2005-10-28 10:43:52 [1702] [7] DEBUG: message_id: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced source addr ton = 4, source add npi = 6 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced dest addr ton = 1, dest add npi = 1 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Sending PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: submit_sm 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 17077 = 0x000042b5 2005-10-28 10:43:52 [1702] [11] DEBUG: send_msg: sending msg to box: <127.0.0.1> 2005-10-28 10:43:52 [1702] [7] DEBUG: service_type: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_ton: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_npi: 6 = 0x00000006 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr: "52600" 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_ton: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_npi: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: destination_addr: "573113839941" 2005-10-28 10:43:52 [1702] [7] DEBUG: esm_class: 3 = 0x00000003 2005-10-28 10:43:52 [1702] [7] DEBUG: protocol_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: priority_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: schedule_delivery_time: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: validity_period: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: registered_delivery: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: got ack 2005-10-28 10:43:52 [1702] [7] DEBUG: replace_if_present_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: data_coding: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_length: 9 = 0x00000009 2005-10-28 10:43:52 [1702] [7] DEBUG: short_message: "Respuesta" 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: sms received 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Got PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: submit_sm_resp 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 2147483652 = 0x80000004 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 4775 = 0x000012a7 2005-10-28 10:43:52 [1702] [7] DEBUG: message_id: "000ea0b0" 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [7] WARNING: SMPP[COMCEL]: SMSC sent submit_sm_resp with wrong sequence number 0x000012a7 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced source addr ton = 4, source add npi = 6 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced dest addr ton = 1, dest add npi = 1 2005-10-28 10:43:52 [1702] [11] DEBUG: send_msg: sending msg to box: <127.0.0.1> 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Sending PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: submit_sm 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 17078 = 0x000042b6 2005-10-28 10:43:52 [1702] [7] DEBUG: service_type: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_ton: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_npi: 6 = 0x00000006 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr: "52600" 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_ton: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: got ack 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_npi: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: destination_addr: "573113839941" 2005-10-28 10:43:52 [1702] [7] DEBUG: esm_class: 3 = 0x00000003 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: sms received 2005-10-28 10:43:52 [1702] [7] DEBUG: protocol_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: priority_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: schedule_delivery_time: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: validity_period: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: registered_delivery: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: replace_if_present_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: data_coding: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_length: 9 = 0x00000009 2005-10-28 10:43:52 [1702] [7] DEBUG: short_message: "Respuesta" 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Got PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: submit_sm_resp 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 2147483652 = 0x80000004 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 4776 = 0x000012a8 2005-10-28 10:43:52 [1702] [7] DEBUG: message_id: "000ea0b1" 2005-10-28 10:43:52 [1702] [11] DEBUG: send_msg: sending msg to box: <127.0.0.1> 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [7] WARNING: SMPP[COMCEL]: SMSC sent submit_sm_resp with wrong sequence number 0x000012a8 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced source addr ton = 4, source add npi = 6 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced dest addr ton = 1, dest add npi = 1 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Sending PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: submit_sm 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 17079 = 0x000042b7 2005-10-28 10:43:52 [1702] [7] DEBUG: service_type: NULL 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: got ack 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_ton: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_npi: 6 = 0x00000006 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr: "52600" 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: sms received 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_ton: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_npi: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: destination_addr: "573113839941" 2005-10-28 10:43:52 [1702] [7] DEBUG: esm_class: 3 = 0x00000003 2005-10-28 10:43:52 [1702] [7] DEBUG: protocol_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: priority_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: schedule_delivery_time: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: validity_period: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: registered_delivery: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: replace_if_present_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: data_coding: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_length: 9 = 0x00000009 2005-10-28 10:43:52 [1702] [7] DEBUG: short_message: "Respuesta" 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends. 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced source addr ton = 4, source add npi = 6 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Manually forced dest addr ton = 1, dest add npi = 1 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP[COMCEL]: Sending PDU: 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU 0x41e4dea8 dump: 2005-10-28 10:43:52 [1702] [7] DEBUG: type_name: submit_sm 2005-10-28 10:43:52 [1702] [7] DEBUG: command_id: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: command_status: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sequence_number: 17080 = 0x000042b8 2005-10-28 10:43:52 [1702] [7] DEBUG: service_type: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_ton: 4 = 0x00000004 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr_npi: 6 = 0x00000006 2005-10-28 10:43:52 [1702] [7] DEBUG: source_addr: "52600" 2005-10-28 10:43:52 [1702] [11] DEBUG: send_msg: sending msg to box: <127.0.0.1> 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_ton: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [7] DEBUG: dest_addr_npi: 1 = 0x00000001 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: got ack 2005-10-28 10:43:52 [1702] [7] DEBUG: destination_addr: "573113839941" 2005-10-28 10:43:52 [1702] [7] DEBUG: esm_class: 3 = 0x00000003 2005-10-28 10:43:52 [1702] [7] DEBUG: protocol_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [11] DEBUG: boxc_receiver: sms received 2005-10-28 10:43:52 [1702] [7] DEBUG: priority_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: schedule_delivery_time: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: validity_period: NULL 2005-10-28 10:43:52 [1702] [7] DEBUG: registered_delivery: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: replace_if_present_flag: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: data_coding: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_default_msg_id: 0 = 0x00000000 2005-10-28 10:43:52 [1702] [7] DEBUG: sm_length: 9 = 0x00000009 2005-10-28 10:43:52 [1702] [7] DEBUG: short_message: "Respuesta" 2005-10-28 10:43:52 [1702] [7] DEBUG: SMPP PDU dump ends.
