Re: Not ACKED message found, will retransmit

Mon, 09 Mar 2009 16:32:40 -0700

By the way, I just realised: "transmitter and receiver"? Are you using SMPP 3.3 instead of 3.4? Have you configured the receiver and transmitter in the same SMSC group? Normal SMPP 3.4 shouldn't have transmitter and receiver but only one transceiver. If you use 3.3 with divided transmitter and receiver connection, you need to configure both inside the same smsc-group, otherwise kannel cannot associate the ACK. (Well, no smsc I have seen so far could do this...) 

Falko

Am 10.03.2009 um 00:26 schrieb Falko Ziemann:
I just saw this behavior once before. There a service provider routed the ACK to another large account. So I send the message on "MYMTCONN1" and received the ACK on "MYMTCONN2". That's not the case, or? I can't see it from the log, the first line where kannel states the connection name is missing.
But I really don't have a idea what this problem should have to do with keep alives. Are you loosing the connection between the submit and the ACK? 

Falko

Am 09.03.2009 um 21:13 schrieb Nikos Balkanas:
Well, there is an "enquire-link-interval" which you could tweak. It defaults to 30". 

BR,
Nikos
----- Original Message -----
From: hafez ahmad
To: Falko Ziemann
Cc: [email protected]
Sent: Monday, March 09, 2009 3:43 PM
Subject: Re: Not ACKED message found, will retransmit

Dears,
I still have the same problem, Any Ideas? , by they my operator advice me that " use “ESME_QRYLINK” on both transmitter and receiver to keep the connection live" may be that related to this error . 

Please advice.

Regards,
Hafez
On Thu, Mar 5, 2009 at 4:17 PM, Falko Ziemann <[email protected]> wrote: 
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













--
Hafez A.Ahmad
Amman-Jordan
mobile:962-785259011
          962-795708728
http://blog.hafezadnan.com

Reply via email to