Weird problem: bind to carrier fails, kannel stops responding - but bind is still listed as 'online'

Giulio Harding <[email protected]>
Newsgroups gmane.comp.mobile.kannel.devel
Message-ID <[email protected]>
This is a moderately urgent problem, since it's recently cropped up  
on a bind to carrier that carries a reasonable amount of traffic, and  
after some investigation, we have NO idea what's going wrong. This  
has happened 3 or 4 times over the past month - the bind had been  
performing flawlessly up until this point. In previous occurrences of  
this problem, the problem has gone away after some time (e.g. a few  
hours, or a day or two), but we're worried the problem will reappear  
just when we're due to handle large peaks in traffic. (We've been  
lucky so far)

The problem is as follows: at some point, we noticed the bind had one  
MT in the store, and no MOs were arriving on that bind. However, the  
bind was still listed as 'online'. We tried restarting Kannel, and  
that bind would come up again, and the queued MT would be sent to the  
destination handset, but wouldn't leave the queue, and wouldn't be  
marked as sent by Kannel. Again, no MOs would arrive on that bind,  
even though it seemed to be up. Sometimes, one or two MOs might  
arrive, and one or two MTs might be successfully sent, but then that  
bind would seize up again, with an MT in the store, and no further  
MOs or MTs would be

A packet capture during a Kannel restart then shutdown showed that  
after the initial successful bind, there would be one or two  
successful submit_sms, but then nothing - no enquire_links, no  
responses to deliver_sms sent by the SMSC, etc. - just occasional TCP  
keep-alives. Each time Kannel is restarted, the same queued messages  
would be successfully submitted, but not removed from the queue.

Here's a sample packet capture summary:

No.     Time        Source                Destination            
Protocol Info
      26 15.747608   10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [SYN] Seq=0 Len=0 MSS=1360 TSV=2576408299  
TSER=0 WS=2
      30 15.788987   xxx.xx.xx.xx          10.110.123.31          
TCP      copysnap > 35085 [SYN, ACK] Seq=0 Ack=1 Win=61440 Len=0  
MSS=1436 WS=0
      31 15.788998   10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [ACK] Seq=1 Ack=1 Win=5440 Len=0
      32 15.789142   10.110.123.31         xxx.xx.xx.xx           
SMPP     SMPP Bind_transceiver
      42 15.830586   xxx.xx.xx.xx          10.110.123.31          
SMPP     SMPP Bind_transceiver - resp: "Ok"
      43 15.830595   10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [ACK] Seq=45 Ack=28 Win=5440 Len=0
      44 15.831265   10.110.123.31         xxx.xx.xx.xx           
SMPP     SMPP Submit_sm
      51 15.939520   xxx.xx.xx.xx          10.110.123.31          
TCP      copysnap > 35085 [ACK] Seq=28 Ack=175 Win=61266 Len=0
      54 16.016723   xxx.xx.xx.xx          10.110.123.31          
SMPP     SMPP Submit_sm - resp: "Ok"
      55 16.056163   10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [ACK] Seq=175 Ack=73 Win=5440 Len=0
      60 20.344091   xxx.xx.xx.xx          10.110.123.31          
SMPP     SMPP Deliver_sm
      61 20.344105   10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [ACK] Seq=175 Ack=145 Win=5440 Len=0
      80 80.089288   xxx.xx.xx.xx          10.110.123.31          
TCP      [TCP Keep-Alive] copysnap > 35085 [ACK] Seq=144 Ack=174  
Win=32768 Len=1
      81 80.089299   10.110.123.31         xxx.xx.xx.xx           
TCP      [TCP Keep-Alive ACK] 35085 > copysnap [ACK] Seq=175 Ack=145  
Win=5440 Len=0
     107 139.857528  xxx.xx.xx.xx          10.110.123.31          
TCP      [TCP Keep-Alive] copysnap > 35085 [ACK] Seq=144 Ack=174  
Win=32768 Len=1
     108 139.857543  10.110.123.31         xxx.xx.xx.xx           
TCP      [TCP Keep-Alive ACK] 35085 > copysnap [ACK] Seq=175 Ack=145  
Win=5440 Len=0
     109 153.240014  xxx.xx.xx.xx          10.110.123.31          
SMPP     SMPP Deliver_sm
     110 153.240029  10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [ACK] Seq=175 Ack=315 Win=6512 Len=0
     129 212.573429  xxx.xx.xx.xx          10.110.123.31          
TCP      [TCP Keep-Alive] copysnap > 35085 [ACK] Seq=314 Ack=174  
Win=32768 Len=1
     130 212.573442  10.110.123.31         xxx.xx.xx.xx           
TCP      [TCP Keep-Alive ACK] 35085 > copysnap [ACK] Seq=175 Ack=315  
Win=6512 Len=0
     156 272.340457  xxx.xx.xx.xx          10.110.123.31          
TCP      [TCP Keep-Alive] copysnap > 35085 [ACK] Seq=314 Ack=174  
Win=32768 Len=1
     157 272.340467  10.110.123.31         xxx.xx.xx.xx           
TCP      [TCP Keep-Alive ACK] 35085 > copysnap [ACK] Seq=175 Ack=315  
Win=6512 Len=0
     167 314.727055  xxx.xx.xx.xx          10.110.123.31          
SMPP     SMPP Deliver_sm
     168 314.727069  10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [ACK] Seq=175 Ack=383 Win=6512 Len=0
     178 337.665939  10.110.123.31         xxx.xx.xx.xx           
TCP      35085 > copysnap [RST, ACK] Seq=175 Ack=383 Win=6512 Len=0

You can see the successful transciever bind (packet #'s 32, 42), the  
successful submit_sm (44, 54), the ignored deliver_sm (60, and again  
at 109 and 167), all the TCP keep-alives, no enquire-links, and a  
final RST as kannel is restarted (no unbind?)

The TCP stream immediately after the restart, for the same bind is  
pretty much identical. Bind_transciever, submit_sm, then nothing.

The message in the queue is:

SMS ID					Type		Time			Sender		Receiver	SMSC ID	BOX ID	UDH	Message
----
aa37aeef-1db0-494b-bfdc-7f574f5a9263	MT-REPLY	2007-01-29 16:37:11	 
19xxxxxx	614xxxxxxxx	xxxx			<79 character text message that is being  
sent fine across all other binds, and was sent fine through this bind  
before the problem>

There are no messages in the bearer.log related to the problem bind.


So:

Firstly, are there any debug options or advanced logging I can turn  
on to try and find out what Kannel is doing with this bind? Secondly,  
does anyone have any ideas what the issue might be?

We're running Kannel version `cvs-20060727' - Build `Sep 21 2006  
14:42:06', compiler `3.4.6 20060404 (Red Hat 3.4.6-3)'. System Linux,  
release 2.6.9-42.0.2.ELsmp, version #1 SMP Wed Aug 23 13:38:27 BST  
2006, machine x86_64. Hostname smsgw2.appgw.mnetcorporation.com, IP  
10.110.123.31. Libxml version 2.6.16. Using native malloc.

We haven't yet had a chance to move to 1.4.1 (our test/build servers  
are being serviced) but from keeping an eye on the dev mailing list,  
I don't think we've missed any critical patches...? In any case,  
since this CVS build, we've had no problems until now.

Any assistance would be greatly appreciated!

--
Giulio Harding
Systems Administrator

m.Net Corporation
Level 2, 16 Leigh Street
Adelaide SA 5000, Australia

Tel: +61 8 8210 2041
Fax: +61 8 8211 9620
Mobile: 0432 876 733
MSN: [email protected]

http://www.mnetcorporation.com
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.