Calls not disconnecting [481 Call leg/transaction does not]

Some calls are not getting disconnected properly. I also think this is why some of our calls get dropped. Here is the trixbox output:

[Aug 10 08:03:32] VERBOSE[7497] logger.c: – Called nexVortex/18001231234
[Aug 10 08:03:35] VERBOSE[7497] logger.c: – SIP/nexVortex-086572b0 is making progress passing it to SIP/206-b7381b88
[Aug 10 08:03:38] VERBOSE[7497] logger.c: – SIP/nexVortex-086572b0 answered SIP/206-b7381b88
[Aug 10 08:04:11] ERROR[3173] chan_sip.c: FONALITY: dialoglist is in an infinite loop: dialoglist=86becb8, dialog->next=86572b0, dialog=86becb8

then I manually close the connection

[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/206-b7381b88”, “hangupcall,”) in new stack
[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/206-b7381b88”, “1?skiprg”) in new stack
[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Goto (macro-hangupcall,s,4)
[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Executing [s@macro-hangupcall:4] GotoIf(“SIP/206-b7381b88”, “1?skipblkvm”) in new stack
[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Goto (macro-hangupcall,s,7)
[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Executing [s@macro-hangupcall:7] GotoIf(“SIP/206-b7381b88”, “1?theend”) in new stack
[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Goto (macro-hangupcall,s,9)
[Aug 10 08:16:36] VERBOSE[7497] logger.c: – Executing [s@macro-hangupcall:9] Hangup(“SIP/206-b7381b88”, “”) in new stack
[Aug 10 08:16:36] VERBOSE[7497] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/206-b7381b88’ in macro ‘hangupcall’
[Aug 10 08:16:36] VERBOSE[7497] logger.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/206-b7381b88’
[Aug 10 08:16:36] VERBOSE[7497] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/206-b7381b88’ in macro ‘dialout-trunk’
[Aug 10 08:16:36] VERBOSE[7497] logger.c: == Spawn extension (from-internal, 819727590111, 5) exited non-zero on ‘SIP/206-b7381b88’
[Aug 10 08:16:36] VERBOSE[7499] logger.c: == End MixMonitor Recording SIP/206-b7381b88
[Aug 10 08:16:36] WARNING[3164] pbx.c: FONALITY: This thread has already held the conlock, skip locking
[Aug 10 08:17:08] WARNING[3173] chan_sip.c: Trying to destroy "72b722c05b04d75e232dccde601a33fb@68.193.163.10", not found in dialog list?!?!
[Aug 10 08:17:08] WARNING[3173] chan_sip.c: Trying to destroy "1f21d13e-11c70e5d@192.168.1.113", not found in dialog list?!?!

I contacted our provider, nexvortex and they did a SIP trace:

We pulled a SIP trace(copied below) and we were able to see a BYE message sent from our proxy to your Asterisk PBX. Your box gets the BYE but does not send a 200 OK instead sends us but 481 Call leg/transaction does not exist message and things that the call is gone. Please engage the Fonality support on this issue and feel free to pass them the SIP trace below:

U 2010/08/10 12:03:32.295148 68.193.163.10:60005 -> my.ip.address:5060
INVITE sip:18001231234@my.ip.address SIP/2.0…Via: SIP/2.0/UDP 68.193.163.1
0:5060;branch=z9hG4bK76546180;rport…Max-Forwards: 70…From: “Steve
sip:206@68.193.163.10;tag=as65ce9e2e…To: <sip:18001231234@my.ip.address

…Contact: sip:206@68.193.163.10…Call-ID: 72b722c05b04d75e232dccde
601a33fb@68.193.163.10…CSeq: 103 INVITE…User-Agent: c PBX 1.6.0.10
-FONCORE-r40…Proxy-Authorization: Digest username=“myusername”, realm=“nexv
ortex.com”, algorithm=MD5, uri=“sip:18001231234@my.ip.address”, nonce=“4c61
4140e3b083e227151869102e0253c3e2f489”, response=“1e30cd40919c3249a604af73c2
334e08”…Date: Tue, 10 Aug 2010 12:03:32 GMT…

U 2010/08/10 12:03:32.336429 my.ip.address:5060 -> 68.193.163.10:60005
SIP/2.0 100 trying – your call is important to us…Via: SIP/2.0/UDP 68.193
.163.10:5060;branch=z9hG4bK76546180;rport=60005…From: "Steve"
sip:206@68.193.163.10;tag=as65ce9e2e…To: sip:18001231234@my.ip.address
…Call-ID: 72b722c05b04d75e232dccde601a33fb@68.193.163.10…CSeq: 103 INVITE
…Server: Sip EXpress router (0.9.6 (i386/linux))…Content-Length: 0…Warni
ng: 392 my.ip.address:5060 “Noisy feedback tells: pid=29263 req_src_ip=68.1
93.163.10 req_src_port=60005 in_uri=sip:18001231234@my.ip.address out_uri=s
ip:18001231234@67.16.110.141 via_cnt==1”…

U 2010/08/10 12:03:38.756578 my.ip.address:5060 -> 68.193.163.10:60005
SIP/2.0 200 OK…Via: SIP/2.0/UDP 68.193.163.10:5060;branch=z9hG4bK76546180;
rport=60005…From: “Steve” sip:206@68.193.163.10;tag=as65ce9e
2e…To: sip:18001231234@my.ip.address;tag=gK079dd06d…Call-ID: 72b722c05b
04d75e232dccde601a33fb@68.193.163.10…CSeq: 103 INVITE…Record-Route: <sip:
18001231234@my.ip.address:5060;nat=yes;ftag=as65ce9e2e;lr=on>…Accept: appl
ication/sdp, application/isup, application/dtmf, application/dtmf-relay, m
ultipart/mixed…Contact: sip:18001231234@67.16.110.141:5060…Allow: INVIT
E,ACK,CANCEL,BYE,REGISTER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,
OPTIONS…Require: timer…Supported: timer,replaces…

call connected, our Proxy sent you a 200 OK


U 2010/08/10 12:03:38.776062 68.193.163.10:60005 -> my.ip.address:5060
ACK sip:18001231234@67.16.110.141:5060 SIP/2.0…Via: SIP/2.0/UDP 68.193.163
.10:5060;branch=z9hG4bK7b8ae69d;rport…Route: <sip:18001231234@my.ip.address
:5060;nat=yes;ftag=as65ce9e2e;lr=on>…Max-Forwards: 70…From: “Steve
sip:206@68.193.163.10;tag=as65ce9e2e…To: <sip:18001231234@my.ip.address

;tag=gK079dd06d…Contact: sip:206@68.193.163.10…Call-ID: 72b722c
05b04d75e232dccde601a33fb@68.193.163.10…CSeq: 103 ACK…User-Agent: Asteris
k PBX 1.6.0.10-FONCORE-r40…Content-Length: 0…


the call was terminated from 18001231234 (PSTN connect) side

BYE sip:206@68.193.163.10:60005 SIP/2.0…Via: SIP/2.0/UDP 67.16.110.141:506
0;branch=z9hG4bK07B93f30e8dc3e4649c…From: sip:18001231234@my.ip.address;
tag=gK079dd06d…To: “Steve” sip:206@68.193.163.10;tag=as65ce9
e2e…Call-ID: 72b722c05b04d75e232dccde601a33fb@68.193.163.10…CSeq: 16465 B
YE…Max-Forwards: 70…Route: <sip:18001231234@my.ip.address:5060;nat=yes;ft
ag=as65ce9e2e;lr=on>…Content-Length: 0…


U 2010/08/10 12:05:51.203200 my.ip.address:5060 -> 68.193.163.10:60005
BYE sip:206@68.193.163.10:60005 SIP/2.0…Record-Route: <sip:206@my.ip.address
:5060;nat=yes;ftag=gK079dd06d;lr=on>…Via: SIP/2.0/UDP my.ip.address:5060
;branch=z9hG4bK6fd8.076d37a7.0…Via: SIP/2.0/UDP 67.16.110.141:5060;branch=
z9hG4bK07B93f30e8dc3e4649c…From: sip:18001231234@my.ip.address;tag=gK079
dd06d…To: “Steve” sip:206@68.193.163.10;tag=as65ce9e2e…Call
-ID: 72b722c05b04d75e232dccde601a33fb@68.193.163.10…CSeq: 16465 BYE…Max-F
orwards: 16…Content-Length: 0…

BYE message was sent from our proxy server to your Asterisk PBX


U 2010/08/10 12:05:51.224074 68.193.163.10:60005 -> my.ip.address:5060
SIP/2.0 481 Call leg/transaction does not exist…Via: SIP/2.0/UDP my.ipaddress
:5060;branch=z9hG4bK6fd8.076d37a7.0;received=my.ip.address…Via: SIP/2.
0/UDP 67.16.110.141:5060;branch=z9hG4bK07B93f30e8dc3e4649c…From: <sip:1972
7590111@my.ip.address>;tag=gK079dd06d…To: “Steve” <sip:206@68.
193.163.10>;tag=as65ce9e2e…Call-ID: 72b722c05b04d75e232dccde601a33fb@68.19
3.163.10…CSeq: 16465 BYE…User-Agent: Asterisk PBX 1.6.0.10-FONCORE-r40…A
llow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY…Supporte
d: replaces, timer…Content-Length: 0…

your system responded with 481 Call leg/transaction does not exist


U 2010/08/10 12:16:36.319892 68.193.163.10:60005 -> my.ip.address:5060
BYE sip:18001231234@67.16.110.141:5060 SIP/2.0…Via: SIP/2.0/UDP 68.193.163
.10:5060;branch=z9hG4bK02aab9fc;rport…Route: <sip:18001231234@my.ip.address
:5060;nat=yes;ftag=as65ce9e2e;lr=on>…Max-Forwards: 70…From: “Steve
sip:206@68.193.163.10;tag=as65ce9e2e…To: <sip:18001231234@my.ip.address

;tag=gK079dd06d…Call-ID: 72b722c05b04d75e232dccde601a33fb@68.193.1
63.10…CSeq: 104 BYE…User-Agent: Asterisk PBX 1.6.0.10-FONCORE-r40…Proxy-
Authorization: Digest username=“myusername”, realm=“nexvortex.com”, algorith
m=MD5, uri=“sip:18001231234@67.16.110.141:5060”, nonce=“4c614140e3b083e2271
51869102e0253c3e2f489”, response=“bb7a45ca01965fc86dc8470dd0e39c9d”…X-Aste
risk-HangupCause: Normal Clearing…X-Asterisk-HangupCauseCode: 16…Content-
Length: 0…

this is when after manually disconnect the call

I posted on the trixbox forums without any response. Please let me know if anyone can help.

Thanks

Exactly which version is this? This line looks like it is the result of an unofficial change, but also as though it is the key to the problem:

If this is a Fonality special, you need to take it up with them.

Version
Asterisk 1.6.0.10-FONCORE-r40 built by root @ revisor.trixbox.com on a i686 running Linux on 2009-11-17 01:21:37 UTC

Ok thanks