Disconected while checking VM = Retransmission timeout

Asterisk 1.8.6 on CentOS 5.5
HW Sip phone
While checking the VM I get disconnected 50% of the time, the other 50% I can check VM just fine.
Checking asterisk logs reveals:

[Oct 4 10:31:20] VERBOSE[7170] file.c: -- <SIP/305-0000000d> Playing 'vm-password.ulaw' (language 'en') [Oct 4 10:31:20] WARNING[3826] chan_sip.c: Retransmission timeout reached on transmission 4052949456-81 for seqno 2 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions Packet timed out after 6400ms with no response [Oct 4 10:31:20] WARNING[3826] chan_sip.c: Hanging up call 4052949456-81 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+ Retransmissions). [Oct 4 10:31:20] VERBOSE[7170] pbx.c: -- Executing [h@from-internal:1] Hang up("SIP/305-0000000d", "") in new stack

I checked the forum and most people having similar problems are trying to access asterisk from outside (NAT issues + reinvite).
My HW Sip phone and asterisk server are both sitting on the same internal network though.

You should also have read that a SIP trace is needed to diagnose this sort of thing.

At a guess, you are not getting an ACK back to the 200 OK.

Please, see below the SIP trace:

[code]—
[Oct 4 17:28:11] VERBOSE[343] chan_sip.c:
<— SIP read from UDP:192.168.1.6:5060 —>
ACK sip:*97@192.168.1.1:5060 SIP/2.0
From: “305” sip:305@mydomain.lan:5060;tag=zip2x2_3293646527-228
To: “*97” sip:*97@192.168.1.1:5060;tag=as72653547
Call-ID: 3293642876-228
CSeq: 2 ACK
Via: SIP/2.0/UDP 0.0.0.305:5060
Contact: 305 sip:305@0.0.0.305:5060
Authorization: Digest username=“305”,realm=“asterisk”,nonce=“2fd84ff7”,uri=“sip:*97@192.168.1.1:5060”, response=“4a8e003655ee9e4b125d3fa4d04d1225”, algorithm=MD5
Content-Length: 0

<------------->
[Oct 4 17:28:11] VERBOSE[343] chan_sip.c: — (9 headers 0 lines) —
[Oct 4 17:28:11] WARNING[343] chan_sip.c: Retransmission timeout reached on transmission 3293642876-228 for seqno 2 (Critical

Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[Oct 4 17:28:11] WARNING[343] chan_sip.c: Hanging up call 3293642876-228 - no reply to our critical packet (see

https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
[Oct 4 17:28:11] WARNING[21393] app_voicemail.c: Unable to read password
[Oct 4 17:28:11] VERBOSE[21393] pbx.c: – Executing [h@from-internal:1] Hangup(“SIP/305-000001bd”, “”) in new stack
[Oct 4 17:28:11] VERBOSE[21393] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/305-000001bd’
[Oct 4 17:28:11] VERBOSE[21393] chan_sip.c: Scheduling destruction of SIP dialog ‘3293642876-228’ in 6400 ms (Method: INVITE)
[Oct 4 17:28:11] VERBOSE[21393] chan_sip.c: set_destination: Parsing sip:305@0.0.0.305:5060 for address/port to send to
[Oct 4 17:28:11] VERBOSE[21393] chan_sip.c: set_destination: set destination to 0.0.0.305:5060
[Oct 4 17:28:11] VERBOSE[21393] chan_sip.c: Reliably Transmitting (NAT) to 192.168.1.6:5060:
BYE sip:305@0.0.0.305:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3b07d99a;rport
Max-Forwards: 70
From: “*97” sip:*97@192.168.1.1:5060;tag=as5ddaa908
To: “305” sip:305@mydomain.lan:5060;tag=zip2x2_3293646527-228
Call-ID: 3293642876-228
CSeq: 102 BYE
User-Agent: FPBX-2.9.0(1.8.6.0)
Proxy-Authorization: Digest username=“305”, realm=“asterisk”, algorithm=MD5, uri=“sip:192.168.1.1:5060”, nonce="", response="9cda75cf2eb58e6fdfdaa74ad7ec4146"
X-Asterisk-HangupCause: Protocol error, unspecified
X-Asterisk-HangupCauseCode: 111
Content-Length: 0


[Oct 4 17:28:11] VERBOSE[343] chan_sip.c:
<— SIP read from UDP:192.168.1.6:5060 —>
SIP/2.0 200 OK
From: “*97” sip:*97@192.168.1.1:5060;tag=as5ddaa908
To: “305” sip:305@mydomain.lan:5060;tag=zip2x2_3293646527-228
Call-ID: 3293642876-228
CSeq: 102 BYE
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3b07d99a;rport=5060
Contact: 305 sip:305@0.0.0.305:5060
Allow: INVITE,BYE,CANCEL,ACK,OPTIONS,REGISTER,NOTIFY,MESSAGE,REFER
Content-Length: 0[/code]

You have 2 options:

  1. Fix the phone setup so it provides correct network info to asterisk
  2. Tell asterisk to disregard the garbage the phone is sending by changing nat=no to nat=yes.

Can you please elaborate on option #1?
I set up a tftp server and dhcp server on the same computer that asterisk is installed.
When I plug HW Sip phone to the network, it gets its ip from the dhcp server and config file with all the setting, including SIP settings, from the tftp server.
As I mentioned I can call out and receive calls just fine. The only problem is that not always, but quite often *97 gets disconnected.

Your phone sends wrong Via: and Contact: headers. Asterisk normally trusts those unless you set nat=force_rport or nat=yes

May be I misunderstood you, but if I remove nat setting from asterisk, I have no audio when phone rings.
Details:
As I mentioned, both asterisk server (192.168.1.1) and HW Sip phone (192.168.1.6) are on the same LAN.
Asterisk extension 305 configuration:

secret: mysecret canreinvite: no host: dynamic type: friend nat: yes encryption: no dial: SIP/305
SIP HW phone SIP configuration:

DEVICE_ID=305 AUTH_PASSWORD=mysecret USE_PROXY=Yes REGISTER_W_PROXY=Yes PROXY_ADDR=192.168.1.1 PROXY_PORT=5060 REGISTRAR_ADDR=192.168.1.1 REGISTRAR_PORT=5060
Dial out = works, dial in = works, *97 = VM = works 50% of the time.

Sometimes VIA is sent correctly:

sometimes wrong:

To be honest with you sometimes even with wrong VIA I can pick messages just fine:

<-------------> [Oct 5 23:10:33] VERBOSE[343] chan_sip.c: --- (9 headers 0 lines) --- [Oct 5 23:10:33] VERBOSE[343] chan_sip.c: <--- SIP read from UDP:192.168.1.1:5060 ---> ACK sip:*97@192.168.1.1:5060 SIP/2.0 From: "305" <sip:305@mydomain.lan:5060>;tag=zip2x2_2867836884-43 To: "*97" <sip:*97@192.168.1.1:5060>;tag=as31cb96e1 Call-ID: 2867834568-43 CSeq: 2 ACK Via: SIP/2.0/UDP 0.0.0.305:5060 Contact: 305 <sip:305@0.0.0.305:5060> Authorization: Digest username="305",realm="asterisk",nonce="6245b61b",uri="sip:*97@192.168.1.1:5060",response="a6b3bc4bc3412ab0bf3018cb0cc9b6d9",algorithm=MD5 Content-Length: 0 ... [Oct 5 23:10:34] VERBOSE[31972] pbx.c: -- Goto (macro-get-vmcontext,s,300) [Oct 5 23:10:34] VERBOSE[31972] pbx.c: -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/305-000001f6", "") in new stack [Oct 5 23:10:34] VERBOSE[31972] pbx.c: -- Executing [*97@from-internal:5] Set("SIP/305-000001f6", "VMBOXEXISTSSTATUS=SUCCESS") in new stack [Oct 5 23:10:34] VERBOSE[31972] pbx.c: -- Executing [*97@from-internal:6] GotoIf("SIP/305-000001f6", "1?mbexist") in new stack [Oct 5 23:10:34] VERBOSE[31972] pbx.c: -- Goto (from-internal,*97,106) [Oct 5 23:10:34] VERBOSE[31972] pbx.c: -- Executing [*97@from-internal:106] VoiceMailMain("SIP/305-000001f6", "305@default") in new stack [Oct 5 23:10:34] VERBOSE[31972] file.c: -- <SIP/305-000001f6> Playing 'vm-password.ulaw' (language 'en')

If I try to put nat = NO - RFC3581 or nat = never - no RFC3581
I get no audio even though the phone rings.

You should probably upgrade your phone. ZULTYS declared bankruptcy in 2006 :wink:

What’s your point exactly? Filling for chapter 11 is not exactly going out of business. That’s the way for big companies to start fresh after they screw up other people’s money. Delta airlines in 2006, GM in 2009, MGM in 2010. Should I continue?
Right after filing for chapter 11, Zultys, was bought at auction by a company founded by a group of its former engineers. Check their web site, they are alive and kicking, and just celebrated their 10th anniversary. In fact, it is the only company I know to provide an all-in-one IP business phone system that integrates voice, video, data and mobility.

Going back to the problem I am having. You made two points which I am trying to verify/confirm/fix if possible.

[quote]1. Fix the phone setup so it provides correct network info to asterisk
2. Tell asterisk to disregard the garbage the phone is sending by changing nat=no to nat=yes.[/quote]

An extension in Asterisk is configured (and always has been) with nat=yes. I try other options like “no” and “never” and they give me no sound as expected/predicted.
The phone indeed sometimes sends 0.0.0.305 where 305 is a device id, instead of 192.168.1.6, but I am not sure how this is relevant as asterisk suppose to ignore it (nat=yes). In fact, I believe it does ignore it as I can make and receive calls just fine, except I cannot use *97 feature reliable 100% of the time.

It’s gotta be something else?

If it is not a secret, what is the model of your phone ?

Can you provide full SIP trace which includes both sides of the conversation w/failed retransmissions and couple this with tcpdump to make sure asterisk logs the correct info when the call fails ?

Based on the information you provided asterisk is doing the right thing, the problem seems to be the phone.
Nothing $100 worth of hardware would not solve 8)