Re: Not ACKED message found, will retransmit

Thu, 05 Mar 2009 06:19:04 -0800 

Hmm, sorry, no idea. Seems like kannel forgets about the ack...
A hotfix would be to set "wait-ack-expire = 0x02" in the smsc group. That would make kannel waiting "forever" for the ACK and never retry. Very dirty hack, but should do the job until someone comes around with a better solution... 

Regards
Falko

Am 05.03.2009 um 13:37 schrieb hafez ahmad:


Sorry, thats the correct

2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU 0xa732ad00 dump:
2009-03-03 21:00:16 [2825] [14] DEBUG:   type_name: submit_sm
2009-03-03 21:00:16 [2825] [14] DEBUG:   command_id: 4 = 0x00000004
2009-03-03 21:00:16 [2825] [14] DEBUG: command_status: 0 = 0x00000000 2009-03-03 21:00:16 [2825] [14] DEBUG: sequence_number: 3684 = 0x00000e64 
2009-03-03 21:00:16 [2825] [14] DEBUG:   service_type: "VVVVV"
2009-03-03 21:00:16 [2825] [14] DEBUG: source_addr_ton: 5 = 0x00000005 2009-03-03 21:00:16 [2825] [14] DEBUG: source_addr_npi: 0 = 0x00000000 
2009-03-03 21:00:16 [2825] [14] DEBUG:   source_addr: "T2ME"
2009-03-03 21:00:16 [2825] [14] DEBUG:   dest_addr_ton: 1 = 0x00000001
2009-03-03 21:00:16 [2825] [14] DEBUG:   dest_addr_npi: 1 = 0x00000001
2009-03-03 21:00:16 [2825] [14] DEBUG: destination_addr: "XXXXXXXXXXXX" 
2009-03-03 21:00:16 [2825] [14] DEBUG:   esm_class: 67 = 0x00000043
2009-03-03 21:00:16 [2825] [14] DEBUG:   protocol_id: 0 = 0x00000000
2009-03-03 21:00:16 [2825] [14] DEBUG:   priority_flag: 0 = 0x00000000
2009-03-03 21:00:16 [2825] [14] DEBUG:   schedule_delivery_time: NULL
2009-03-03 21:00:16 [2825] [14] DEBUG:   validity_period: NULL
2009-03-03 21:00:16 [2825] [14] DEBUG: registered_delivery: 0 = 0x00000000 2009-03-03 21:00:16 [2825] [14] DEBUG: replace_if_present_flag: 0 = 0x00000000 
2009-03-03 21:00:16 [2825] [14] DEBUG:   data_coding: 8 = 0x00000008
2009-03-03 21:00:16 [2825] [14] DEBUG: sm_default_msg_id: 0 = 0x00000000 
2009-03-03 21:00:16 [2825] [14] DEBUG:   sm_length: 140 = 0x0000008c
2009-03-03 21:00:16 [2825] [14] DEBUG:   short_message:
2009-03-03 21:00:16 [2825] [14] DEBUG:    Octet string at 0xa732af00:
2009-03-03 21:00:16 [2825] [14] DEBUG:      len:  140
2009-03-03 21:00:16 [2825] [14] DEBUG:      size: 1024
2009-03-03 21:00:16 [2825] [14] DEBUG:      immutable: 0
2009-03-03 21:00:16 [2825] [14] DEBUG: data: 05 00 03 83 04 01 06 23 06 47 06 45 00 20 06 48 .......#.G.E. .H 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 35 06 41 06 27 06 2a 00 20 06 4a 06 48 06 33 .5.A.'.*. .J.H.3 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 41 00 20 06 27 06 44 06 34 06 31 06 41 06 27 .A. .'.D.4.1.A.' 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 21 00 20 06 44 06 39 06 44 06 27 06 2c 00 20 .!. .D.9.D.'.,. 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 27 06 44 06 43 06 48 06 44 06 4a 06 33 06 2a .'.D.C.H.D.J.3.* 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 31 06 48 06 44 00 3a 00 20 06 2a 06 24 06 2e .1.H.D.:. .*.$.. 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 30 00 20 06 46 06 33 06 28 00 20 06 45 06 2a .0. .F.3.(. .E.* 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 33 06 27 06 48 06 4a 06 29 00 20 06 45 06 46 .3.'.H.J.). .E.F 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 00 20 06 27 06 44 06 44 06 48 06 32 . .'.D.D.H.2 
2009-03-03 21:00:16 [2825] [14] DEBUG:    Octet string dump ends.
2009-03-03 21:00:16 [2825] [14] DEBUG: more_messages_to_send: 1 = 0x00000001 
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU dump ends.




2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP[MYMTCONN]: Got PDU:
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU 0xa732ad00 dump:
2009-03-03 21:00:16 [2825] [14] DEBUG:   type_name: submit_sm_resp
2009-03-03 21:00:16 [2825] [14] DEBUG: command_id: 2147483652 = 0x80000004 2009-03-03 21:00:16 [2825] [14] DEBUG: command_status: 0 = 0x00000000 2009-03-03 21:00:16 [2825] [14] DEBUG: sequence_number: 3684 = 0x00000e64 
2009-03-03 21:00:16 [2825] [14] DEBUG:   message_id: "4129216897"
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU dump ends.


Regards,
Hafez
On Thu, Mar 5, 2009 at 1:14 PM, Falko Ziemann <[email protected]> wrote: 
Nope .... take a closer look:

submit_sm:

sequence_number: 3684 = 0x00000e64


submit_sm_resp:

sequence_number: 3680 = 0x00000e60
That's not the ACK for the message you have posted but for 4 messages earlier. 

Regards
Falko

Am 05.03.2009 um 12:10 schrieb hafez ahmad:


Dear falko,
Thanks for reply I check the submit_sm_respon and I think everything works fine, Please advice, this is my log 

2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU 0xa732ad00 dump:
2009-03-03 21:00:16 [2825] [14] DEBUG:   type_name: submit_sm
2009-03-03 21:00:16 [2825] [14] DEBUG:   command_id: 4 = 0x00000004
2009-03-03 21:00:16 [2825] [14] DEBUG: command_status: 0 = 0x00000000 2009-03-03 21:00:16 [2825] [14] DEBUG: sequence_number: 3684 = 0x00000e64 
2009-03-03 21:00:16 [2825] [14] DEBUG:   service_type: "VVVVV"
2009-03-03 21:00:16 [2825] [14] DEBUG: source_addr_ton: 5 = 0x00000005 2009-03-03 21:00:16 [2825] [14] DEBUG: source_addr_npi: 0 = 0x00000000 
2009-03-03 21:00:16 [2825] [14] DEBUG:   source_addr: "T2ME"
2009-03-03 21:00:16 [2825] [14] DEBUG: dest_addr_ton: 1 = 0x00000001 2009-03-03 21:00:16 [2825] [14] DEBUG: dest_addr_npi: 1 = 0x00000001 2009-03-03 21:00:16 [2825] [14] DEBUG: destination_addr: "XXXXXXXXXXXX" 
2009-03-03 21:00:16 [2825] [14] DEBUG:   esm_class: 67 = 0x00000043
2009-03-03 21:00:16 [2825] [14] DEBUG:   protocol_id: 0 = 0x00000000
2009-03-03 21:00:16 [2825] [14] DEBUG: priority_flag: 0 = 0x00000000 
2009-03-03 21:00:16 [2825] [14] DEBUG:   schedule_delivery_time: NULL
2009-03-03 21:00:16 [2825] [14] DEBUG:   validity_period: NULL
2009-03-03 21:00:16 [2825] [14] DEBUG: registered_delivery: 0 = 0x00000000 2009-03-03 21:00:16 [2825] [14] DEBUG: replace_if_present_flag: 0 = 0x00000000 
2009-03-03 21:00:16 [2825] [14] DEBUG:   data_coding: 8 = 0x00000008
2009-03-03 21:00:16 [2825] [14] DEBUG: sm_default_msg_id: 0 = 0x00000000 
2009-03-03 21:00:16 [2825] [14] DEBUG:   sm_length: 140 = 0x0000008c
2009-03-03 21:00:16 [2825] [14] DEBUG:   short_message:
2009-03-03 21:00:16 [2825] [14] DEBUG:    Octet string at 0xa732af00:
2009-03-03 21:00:16 [2825] [14] DEBUG:      len:  140
2009-03-03 21:00:16 [2825] [14] DEBUG:      size: 1024
2009-03-03 21:00:16 [2825] [14] DEBUG:      immutable: 0
2009-03-03 21:00:16 [2825] [14] DEBUG: data: 05 00 03 83 04 01 06 23 06 47 06 45 00 20 06 48 .......#.G.E. .H 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 35 06 41 06 27 06 2a 00 20 06 4a 06 48 06 33 .5.A.'.*. .J.H.3 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 41 00 20 06 27 06 44 06 34 06 31 06 41 06 27 .A. .'.D.4.1.A.' 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 21 00 20 06 44 06 39 06 44 06 27 06 2c 00 20 .!. .D.9.D.'.,. 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 27 06 44 06 43 06 48 06 44 06 4a 06 33 06 2a .'.D.C.H.D.J.3.* 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 31 06 48 06 44 00 3a 00 20 06 2a 06 24 06 2e .1.H.D.:. .*.$.. 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 30 00 20 06 46 06 33 06 28 00 20 06 45 06 2a .0. .F.3.(. .E.* 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 06 33 06 27 06 48 06 4a 06 29 00 20 06 45 06 46 .3.'.H.J.). .E.F 2009-03-03 21:00:16 [2825] [14] DEBUG: data: 00 20 06 27 06 44 06 44 06 48 06 32 . .'.D.D.H.2 
2009-03-03 21:00:16 [2825] [14] DEBUG:    Octet string dump ends.
2009-03-03 21:00:16 [2825] [14] DEBUG: more_messages_to_send: 1 = 0x00000001 
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU dump ends.
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP[MYMTCONN]: Got PDU:
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU 0xa732ad00 dump:
2009-03-03 21:00:16 [2825] [14] DEBUG:   type_name: submit_sm_resp
2009-03-03 21:00:16 [2825] [14] DEBUG: command_id: 2147483652 = 0x80000004 2009-03-03 21:00:16 [2825] [14] DEBUG: command_status: 0 = 0x00000000 2009-03-03 21:00:16 [2825] [14] DEBUG: sequence_number: 3680 = 0x00000e60 
2009-03-03 21:00:16 [2825] [14] DEBUG:   message_id: "4129215894"
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP PDU dump ends.
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP[MYMTCONN]: Manually forced source addr ton = 5, source add npi = 1 2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP[MYMTCONN]: Manually forced dest addr ton = 1, dest add npi = 1 
2009-03-03 21:00:16 [2825] [14] DEBUG: SMPP[MYMTCONN]: Sending PDU:


BR,
Hafez
On Thu, Mar 5, 2009 at 11:49 AM, Falko Ziemann <[email protected]> wrote: It looks like your SMPP service provider hasn't send a correct ACK for the message but delivered it. Please take a look in the smpp-logfile, what you provider answered to the submit_sm. Strongly looks like an error on your providers side. 

Regards
Falko

Am 05.03.2009 um 10:40 schrieb hafez ahmad:


Hi All,


Hope your all doing well, I have the following warning in my logs,
2009-03-04 16:45:56 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<62>sec. ago, SEQ<11674>, DST<+999999999999> 2009-03-04 16:47:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<88>sec. ago, SEQ<11684>, DST<+988888888888> 2009-03-04 16:47:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<88>sec. ago, SEQ<11685>, DST<+999999999999> 2009-03-04 16:47:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<88>sec. ago, SEQ<11686>, DST<+999999999999> 2009-03-04 16:47:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<88>sec. ago, SEQ<11682>, DST<+999999999999> 2009-03-04 16:47:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<88>sec. ago, SEQ<11683>, DST<+988888888888> 2009-03-04 16:48:54 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<90>sec. ago, SEQ<11693>, DST<+999999999999> 2009-03-04 16:48:54 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<89>sec. ago, SEQ<11694>, DST<+999999999999> 2009-03-04 16:48:54 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<89>sec. ago, SEQ<11695>, DST<+988888888888> 2009-03-04 16:48:54 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<90>sec. ago, SEQ<11691>, DST<+988888888888> 2009-03-04 16:48:54 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<90>sec. ago, SEQ<11692>, DST<+999999999999> 2009-03-04 16:50:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<90>sec. ago, SEQ<11701>, DST<+988888888888> 2009-03-04 16:50:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<90>sec. ago, SEQ<11702>, DST<+988888888888> 2009-03-04 16:50:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<89>sec. ago, SEQ<11703>, DST<+999999999999> 2009-03-04 16:50:24 [2825] [14] WARNING: SMPP[MT_CONNICTION]: Not ACKED message found, will retransmit. SENT<90>sec. ago, SEQ<11699>, DST<+999999999999>
some users like the user +999999999999, received the SMS 2 times and every time he is billed, I search about the problem and I found the following code: 

case SMPP_WAITACK_REQUEUE: /* requeue */
    smpp_msg = dict_remove(smpp->sent_msgs, key);
    if (smpp_msg != NULL) {
warning(0, "SMPP[%s]: Not ACKED message found, will retransmit." 
                   " SENT<%ld>sec. ago, SEQ<%s>, DST<%s>",
                   octstr_get_cstr(smpp->conn->id),
                   (long)difftime(now, smpp_msg->sent_time) ,
                   octstr_get_cstr(key),
                   octstr_get_cstr(smpp_msg->msg->sms.receiver));
bb_smscconn_send_failed(smpp->conn, smpp_msg->msg, SMSCCONN_FAILED_TEMPORARILY,NULL); 
        smpp_msg_destroy(smpp_msg, 0);
        (*pending_submits)--;
    }
As I understand from the code that the connection was down so kannel requeue the SMS, is that right? and how can I be sure that the user will get the SMS only one time? please advice. 


BR,
Hafez

Reply via email to