Strange SIP dialog

Hello

I have an * 1.6.1.20, with chan_ss7 and E1 to a ericsson switch. My sip clients make calls to the PSTN via the SS7 link.

With one pbx (astra intelligate) that I just connected, I am getting very strange results.

Here is the dialog - traced with wireshark

Client / Asterisk

INVITE ->
<- UNAUTH
<- UNAUTH
<- UNAUTH
<- UNAUTH
<- UNAUTH
ACK ->
INVITE ->
<- TRYING
ACK ->
ACK ->
ACK ->
ACK ->
<- Session in Progress 183
(RTP flow starts)
<- Ringing 180
<- OK 200
<- OK 200
<- OK 200
<- OK 200
<- OK 200
<- OK 200
RTP one way, from client to asterisk - no more rtp trafic from asterisk to client
ICMP Host unreachable
-> BYE
<- Call leg does not exist, 481

On the CLI, I get a no reply to critical packet, call hang up… but it appears as it the the remote end terminating the call.

My first question would be… why would asterisk resend initially 5 times the ‘UNAUTH’ messages, within 1.5 second ?

What can be causing this scenario ?

Many thanks for the help

J.

Where is your wireshark? On Asterisk server?
Can you make some test extension with echo? Or record/playback?

Thanks for the answer,

The wireshark is on the asterisk server, which I control. I have little access/control to client site.

I have recorded the conversation on the server (mixmonitor), and the audio is fine, both ways, and clearly shows that both parties can hear each other.

The ICMP indicates that you have a flakey network.

Also, for some reason, Asterisk seems to be getting a long way behind. Are you trying to use a VM?

Without knowing which exchange each packet relates to, it is a bit difficult to properly re-construct the dialogues.

Many thanks for the help !

the server is not a VM, it runs on dell poweredge, with centos 5.3. I have tried to attached the dialog as a file but could see the link (I must be blind) so its copied & pasted here.

What tickles me is that my server communicates correctly with other client / pbx, just this one is messy. I therefore assume my network end is correct. So why is it my side that first resends a packet 4 times ?

Rgds,

J.

edited - removed lenghty useless dump !

The timing would be very useful (from the log file, rather than the console). It looks like the remote side as been using much too short a timeout when waiting for ACKs.

Hi

Here is a screen dump of ws with the timing (click on the image to see the right side of the screen)

Any comments welcome !

Tks,

J.

Please activate Asterisk with -vvvc (for extended verbose) and post the output of the console.

I actually had to disable this account as the customer was being impacted.

Any suggestion for a tool that I could run on the client network to see if something is polluting the SIP messages ?

Thanks for your help,

J.

If I understand correctly the problem might be a combination between Asterisk & the client. I.e. not sure this is merely a client issue.

Since this client is no more in production, maybe you can plug it in a test environment so we will be able to analyze its impact on Asterisk ?

I would say the problem was entirely on the non-Asterisk side (which is acting as a UAS (user agent server) in this case), and even then, should only result in excess traffic.

However, you keep providing incomplete traces. E.g., in the wire shark trace, I can see the UAS has sent OKs at intervals of only a few milliseconds, but I can’t see the INVITE, to see if it started doing this immediately.

Hi

First of all, many thanks for the valuable help provided here. I do appreciate this.

I have tried to “extract” the packets from wireshark in a format that can be read. I am posting here below the results.

I also went to the client premises, and tried to make a number of calls with a softphone instead of his pbx. They all went well.

My guess is either something is wrong with the pbx itself (An Aastra 5000 - any clues ?) or with the client network, which only happens once in a while - and not when I was there.

Anyway, I am not sure it makes sense to keep asking help on this issue, I am posting the traces just in case someone has been tickled and wants to see them !

Thanks for your support,

J.[code]No. Time Source Sport Destination Dport Protocol Info
5 15:20:18.676745 192.168.1.1 sip 81.248.125.40 11698 SIP Request: OPTIONS sip:2617308609@192.168.10.9;line=AIDE78D159C926C16F
6 15:20:18.808598 81.248.125.40 11698 192.168.1.1 sip SIP Status: 200 OK
17 15:20:46.750115 81.248.125.40 11698 192.168.1.1 sip SIP Request: REGISTER sip:sip.myhost.com
18 15:20:46.750325 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized (0 bindings)
19 15:20:46.916847 81.248.125.40 11698 192.168.1.1 sip SIP Request: REGISTER sip:sip.myhost.com
20 15:20:46.917569 192.168.1.1 sip 81.248.125.40 11698 SIP Request: OPTIONS sip:2617308609@192.168.10.9;line=AIDE78D159C926C16F
21 15:20:46.917623 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 200 OK (1 bindings)
22 15:20:47.059317 81.248.125.40 11698 192.168.1.1 sip SIP Status: 200 OK
41 15:21:23.675592 81.248.125.40 11698 192.168.1.1 sip SIP/SDP Request: INVITE sip:0596508383@sip.myhost.com, with session description
42 15:21:23.676119 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized
46 15:21:23.958052 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized
47 15:21:24.240050 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized
50 15:21:24.803132 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized
51 15:21:25.932020 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized
52 15:21:28.026859 81.248.125.40 11698 192.168.1.1 sip SIP Request: ACK sip:0596508383@sip.myhost.com
53 15:21:28.127400 81.248.125.40 11698 192.168.1.1 sip SIP/SDP Request: INVITE sip:0596508383@sip.myhost.com, with session description
54 15:21:28.127591 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 100 Trying
56 15:21:28.145294 81.248.125.40 11698 192.168.1.1 sip SIP Request: ACK sip:0596508383@sip.myhost.com
57 15:21:28.197565 81.248.125.40 11698 192.168.1.1 sip SIP Request: ACK sip:0596508383@sip.myhost.com
58 15:21:28.249751 81.248.125.40 11698 192.168.1.1 sip SIP Request: ACK sip:0596508383@sip.myhost.com
59 15:21:28.301993 81.248.125.40 11698 192.168.1.1 sip SIP Request: ACK sip:0596508383@sip.myhost.com
69 15:21:29.297305 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 183 Session Progress, with session description
373 15:21:32.509100 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 180 Ringing
453 15:21:33.297420 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
476 15:21:33.516807 81.248.125.40 11698 192.168.1.1 sip UDP Source port: 11698 Destination port: sip
485 15:21:33.579378 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
500 15:21:33.735669 81.248.125.40 11698 192.168.1.1 sip UDP Source port: 11698 Destination port: sip
515 15:21:33.861390 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
531 15:21:34.022722 81.248.125.40 11698 192.168.1.1 sip UDP Source port: 11698 Destination port: sip
574 15:21:34.425383 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
589 15:21:34.577088 81.248.125.40 11698 192.168.1.1 sip UDP Source port: 11698 Destination port: sip
688 15:21:35.552567 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
704 15:21:35.703476 81.248.125.40 11698 192.168.1.1 sip UDP Source port: 11698 Destination port: sip
916 15:21:37.808513 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
932 15:21:37.964482 81.248.125.40 11698 192.168.1.1 sip UDP Source port: 11698 Destination port: sip
1320 15:21:41.808699 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
1336 15:21:41.966478 81.248.125.40 11698 192.168.1.1 sip UDP Source port: 11698 Destination port: sip
1803 15:21:47.059103 192.168.1.1 sip 81.248.125.40 11698 SIP Request: OPTIONS sip:2617308609@192.168.10.9;line=AIDE78D159C926C16F
1809 15:21:47.191293 81.248.125.40 11698 192.168.1.1 sip SIP Status: 200 OK
2168 15:21:54.428316 81.248.125.40 11698 192.168.1.1 sip SIP Request: BYE sip:0596508383@sip.myhost.com
2169 15:21:54.428435 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 481 Call leg/transaction does not exist
2177 15:22:09.715394 81.248.125.40 11698 192.168.1.1 sip SIP/SDP Request: INVITE sip:0596508383@sip.myhost.com, with session description
2178 15:22:09.715843 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized
2180 15:22:09.841846 81.248.125.40 11698 192.168.1.1 sip SIP Request: ACK sip:0596508383@sip.myhost.com
2182 15:22:09.944315 81.248.125.40 11698 192.168.1.1 sip SIP/SDP Request: INVITE sip:0596508383@sip.myhost.com, with session description
2183 15:22:09.944663 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 100 Trying
2195 15:22:11.112152 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 183 Session Progress, with session description
2448 15:22:13.847248 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 180 Ringing
2525 15:22:14.607215 192.168.1.1 sip 81.248.125.40 11698 SIP/SDP Status: 200 OK, with session description
2549 15:22:14.833669 81.248.125.40 11698 192.168.1.1 sip SIP Request: ACK sip:0596508383@194.51.133.82
2583 15:22:15.133100 81.248.125.40 11698 192.168.1.1 sip SIP Request: REGISTER sip:sip.myhost.com
2585 15:22:15.133325 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 401 Unauthorized (0 bindings)
2600 15:22:15.295627 81.248.125.40 11698 192.168.1.1 sip SIP Request: REGISTER sip:sip.myhost.com
2603 15:22:15.297624 192.168.1.1 sip 81.248.125.40 11698 SIP Request: OPTIONS sip:2617308609@192.168.10.9;line=AIDE78D159C926C16F
2604 15:22:15.297665 192.168.1.1 sip 81.248.125.40 11698 SIP Status: 200 OK (1 bindings)
2618 15:22:15.434088 81.248.125.40 11698 192.168.1.1 sip SIP Status: 200 OK

[/code]

There seems to be a big delay before Asterisk sees the response, then it answers them quickly.

One theory is that there a dodgy DNS configuration that is forcing Asterisk to re-lookup a domain name (excessively short time to live), combined with sluggish responses to DNS requests.

Otherwise you need to provide debug output from Asterisk itself.

There may be some sort of partial deadlock, but I’d expect that to affect everybody.

Note there is nothing obviously wrong with the order of the events - there are no causality violations, any missing packets, or any excess ones, other than what would be explained by the packet getting backlogged in an internal queue.

David,

What I dont get is why does my asterisk send 5 x Unauthorized after it receives the first invite (every half second or so)

It seems that the remote (client inviting) is slow to ACK the first invite, but Asterisk only waits 0.283 secs before resending the invite - While my T1 is set to 500ms -

J.

     41 15:21:23.675592 81.248.125.40         11698  192.168.1.1           sip    SIP/SDP  Request: INVITE sip:0596508383@sip.myhost.com, with session description
     42 15:21:23.676119 192.168.1.1           sip    81.248.125.40         11698  SIP      Status: 401 Unauthorized
     46 15:21:23.958052 192.168.1.1           sip    81.248.125.40         11698  SIP      Status: 401 Unauthorized
     47 15:21:24.240050 192.168.1.1           sip    81.248.125.40         11698  SIP      Status: 401 Unauthorized
     50 15:21:24.803132 192.168.1.1           sip    81.248.125.40         11698  SIP      Status: 401 Unauthorized
     51 15:21:25.932020 192.168.1.1           sip    81.248.125.40         11698  SIP      Status: 401 Unauthorized
     52 15:21:28.026859 81.248.125.40         11698  192.168.1.1           sip    SIP      Request: ACK sip:0596508383@sip.myhost.com

OK I got the two sides mixed up. If your side is sending the multiple unauthorised’s, it is because the other side is failing to send an ACK promptly. There is a reasonable delay between them.

In that case, there is network congestion, or a processing delay at the remote side. If there is a DNS problem, it will with your DNS, e.g. you have a very short TTL, to compensate for an unstable address, but your DNS server is overloaded, or poorly connected.

SIP reliable responses are repeated, at escalating intervals, until either a maximum number is reached, or an ACK is received.

Asterisk is responding properly to an extremely late ACK.

Many thanks for your patience !!!

I’ll investigate network congestion - and mostly, dns issue !

Thanks again,

J.