Problem with SIP BYE message

I am writing a SIP server, and I have it taking calls and then connecting them to a voip phone, the problem is when you hang up the voip phone, there's something wrong with the forwarding of the BYE message where my cell phone doesn't end the call.

Here is the SIP message log (I replaced my server's phone number with 1234 and my cell phone's phone number with 5678, my server's IP has been replaced with x's and my voip phone's IP has been replaced with y's) -

Incoming from 174.37.45.134:5060 - 
INVITE sip:1234@174.37.45.134:5060;rinstance=f10c56ae7fb62958 SIP/2.0
Record-Route: <sip:174.37.45.134;lr=on;ftag=VPSF506071629460>
Record-Route: <sip:67.228.177.9;lr=on;ftag=VPSF506071629460>
Record-Route: <sip:216.82.224.202;lr;ftag=VPSF506071629460>
Record-Route: <sip:4.79.212.229;lr;ftag=VPSF506071629460>
Via: SIP/2.0/UDP 174.37.45.134;branch=z9hG4bK9767.ad406992.0
Via: SIP/2.0/UDP 67.228.177.9;rport=5060;branch=z9hG4bK9767.760c9624.0
Via: SIP/2.0/UDP 216.82.224.202;rport=5060;received=216.82.224.202;branch=z9hG4bK9767.823f8e12.0
Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bK9767.723f8e12.0
Via: SIP/2.0/UDP 4.79.212.229;branch=z9hG4bK9767.e30c5303.0
Via: SIP/2.0/UDP 4.68.250.148:5060;branch=z9hG4bK506071629460-1256581032616
f: "Carro Ramon"  <sip:5678@4.68.250.148>;tag=VPSF506071629460
t: <sip:+11234@4.79.212.229:5060>
i: MIAMGC0120091027172219041244@209.244.63.32
CSeq: 1 INVITE
m: <sip:+15678@4.68.250.148:5060;transport=udp;nat=yes>
Max-Forwards: 64
c: application/sdp
Content-Length: 192

v=0
o=- 1256664139 1256664140 IN IP4 209.开发者_JAVA百科247.22.135
s=-
c=IN IP4 174.37.45.134
t=0 0
m=audio 55540 RTP/AVP 0 18 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=nortpproxy:yes

Outgoing to 174.37.45.134:5060 - 
SIP/2.0 180 Ringing
CSeq: 1 INVITE
Call-ID: MIAMGC0120091027172219041244@209.244.63.32
Contact: <sip:+15678@4.68.250.148:5060;transport=udp;nat=yes>
From: "Carro Ramon"  <sip:5678@4.68.250.148>;tag=VPSF506071629460
Max-Forwards: 70
Record-Route: <sip:174.37.45.134;lr=on;ftag=VPSF506071629460>, <sip:67.228.177.9;lr=on;ftag=VPSF506071629460>, <sip:216.82.224.202;lr;ftag=VPSF506071629460>, <sip:4.79.212.229;lr;ftag=VPSF506071629460>
To: <sip:+11234@4.79.212.229:5060>;tag=dAmXcBGL
Via: SIP/2.0/UDP 174.37.45.134;branch=z9hG4bK9767.ad406992.0, SIP/2.0/UDP 67.228.177.9;rport=5060;branch=z9hG4bK9767.760c9624.0, SIP/2.0/UDP 216.82.224.202;rport=5060;received=216.82.224.202;branch=z9hG4bK9767.823f8e12.0, SIP/2.0/UDP 216.82.224.202;branch=z9hG4bK9767.723f8e12.0, SIP/2.0/UDP 4.79.212.229;branch=z9hG4bK9767.e30c5303.0, SIP/2.0/UDP 4.68.250.148:5060;branch=z9hG4bK506071629460-1256581032616
Content-Length: 0

Outgoing to 174.37.45.134:5060 - 
SIP/2.0 200 OK
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
CSeq: 1 INVITE
Call-ID: MIAMGC0120091027172219041244@209.244.63.32
Contact: <sip:+15678@4.68.250.148:5060;transport=udp;nat=yes>
Content-Type: application/sdp
From: "Carro Ramon"  <sip:5678@4.68.250.148>;tag=VPSF506071629460
Max-Forwards: 70
Record-Route: <sip:174.37.45.134;lr=on;ftag=VPSF506071629460>, <sip:67.228.177.9;lr=on;ftag=VPSF506071629460>, <sip:216.82.224.202;lr;ftag=VPSF506071629460>, <sip:4.79.212.229;lr;ftag=VPSF506071629460>
To: <sip:+11234@4.79.212.229:5060>;tag=BYFeP7T1
Via: SIP/2.0/UDP 174.37.45.134;branch=z9hG4bK9767.ad406992.0, SIP/2.0/UDP 67.228.177.9;rport=5060;branch=z9hG4bK9767.760c9624.0, SIP/2.0/UDP 216.82.224.202;rport=5060;received=216.82.224.202;branch=z9hG4bK9767.823f8e12.0, SIP/2.0/UDP 216.82.224.202;branch=z9hG4bK9767.723f8e12.0, SIP/2.0/UDP 4.79.212.229;branch=z9hG4bK9767.e30c5303.0, SIP/2.0/UDP 4.68.250.148:5060;branch=z9hG4bK506071629460-1256581032616
Content-Length: 206

v=0
o=Zoiper_user 0 0 IN IP4 xx.xx.xxx.xx
s=Zoiper_session
c=IN IP4 xx.xx.xxx.xx
t=0 0
m=audio 8000 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

Incoming from 174.37.45.134:5060 - 
ACK sip:+15678@xx.xx.xxx.xx:5060;transport=udp SIP/2.0
Record-Route: <sip:174.37.45.134;lr=on;ftag=VPSF506071629460>
Record-Route: <sip:67.228.177.9;lr=on;ftag=VPSF506071629460>
Record-Route: <sip:216.82.224.202;lr;ftag=VPSF506071629460>
Via: SIP/2.0/UDP 174.37.45.134;branch=z9hG4bK9767.ad406992.2
Via: SIP/2.0/UDP 67.228.177.9;rport=5060;branch=z9hG4bK9767.760c9624.2
Via: SIP/2.0/UDP 216.82.224.202;rport=5060;received=216.82.224.202;branch=z9hG4bK9767.723f8e12.2
Via: SIP/2.0/UDP 4.79.212.229;branch=z9hG4bK9767.e30c5303.2
Via: SIP/2.0/UDP 4.68.250.148:5060;branch=z9hG4bK506071629460-1256581032653
From: "CARRO RAMON    "  <sip:+15678@4.68.250.148;isup-oli=0>;tag=VPSF506071629460
To: <sip:+11234@4.79.212.229:5060>;tag=BYFeP7T1
Call-ID: MIAMGC0120091027172219041244@209.244.63.32
CSeq: 1 ACK
Contact: <sip:4.68.250.148:5060;transport=udp>
Max-Forwards: 66
Content-Length: 0

Outgoing to yyy.yyy.yy.yyy:1024 - 
INVITE sip:3998@192.168.1.121 SIP/2.0
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
CSeq: 1 INVITE
Call-ID: AW6zfKQ8RWl71MipIe4X1WWKfw7xGGR9@chat.seohosting.com
Contact: <sip:5678@xx.xx.xxx.xx>;transport=UDP
Content-Type: application/sdp
From: "(null)" <sip:5678@xx.xx.xxx.xx>;transport=UDP;tag=7b2add35
Max-Forwards: 70
To: <sip:3998@xx.xx.xxx.xx>
User-Agent: Zoiper rev.4186
Via: SIP/2.0/UDP xx.xx.xxx.xx:5060
Content-Length: 206

v=0
o=Zoiper_user 0 0 IN IP4 xx.xx.xxx.xx
s=Zoiper_session
c=IN IP4 xx.xx.xxx.xx
t=0 0
m=audio 8000 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

Incoming from yyy.yyy.yy.yyy:1024 - 
SIP/2.0 100 Trying
To: <sip:3998@xx.xx.xxx.xx>
From: "(null)" <sip:5678@xx.xx.xxx.xx>;transport=UDP;tag=7b2add35
Call-ID: AW6zfKQ8RWl71MipIe4X1WWKfw7xGGR9@chat.seohosting.com
CSeq: 1 INVITE
Via: SIP/2.0/UDP xx.xx.xxx.xx:5060
Server: Linksys/SPA941-5.1.8
Content-Length: 0


Incoming from yyy.yyy.yy.yyy:1024 - 
SIP/2.0 180 Ringing
To: <sip:3998@xx.xx.xxx.xx>;tag=53cca4372c533924i0
From: "(null)" <sip:5678@xx.xx.xxx.xx>;transport=UDP;tag=7b2add35
Call-ID: AW6zfKQ8RWl71MipIe4X1WWKfw7xGGR9@chat.seohosting.com
CSeq: 1 INVITE
Via: SIP/2.0/UDP xx.xx.xxx.xx:5060
Server: Linksys/SPA941-5.1.8
Content-Length: 0

Incoming from yyy.yyy.yy.yyy:1024 - 
SIP/2.0 200 OK
To: <sip:3998@xx.xx.xxx.xx>;tag=53cca4372c533924i0
From: "(null)" <sip:5678@xx.xx.xxx.xx>;transport=UDP;tag=7b2add35
Call-ID: AW6zfKQ8RWl71MipIe4X1WWKfw7xGGR9@chat.seohosting.com
CSeq: 1 INVITE
Via: SIP/2.0/UDP xx.xx.xxx.xx:5060
Contact: "3998" <sip:3998@192.168.1.121:5060>
Server: Linksys/SPA941-5.1.8
Content-Length: 212
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
Content-Type: application/sdp

v=0
o=- 49591664 49591664 IN IP4 192.168.1.121
s=-
c=IN IP4 192.168.1.121
t=0 0
m=audio 16432 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

Outgoing to yyy.yyy.yy.yyy:1024 - 
ACK sip:3998@192.168.1.121 SIP/2.0
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
CSeq: 1 ACK
Call-ID: AW6zfKQ8RWl71MipIe4X1WWKfw7xGGR9@chat.seohosting.com
Contact: <sip:5678@xx.xx.xxx.xx>;transport=UDP
From: "(null)" <sip:5678@xx.xx.xxx.xx>;transport=UDP;tag=7b2add35
Max-Forwards: 70
To: <sip:3998@xx.xx.xxx.xx>;tag=53cca4372c533924i0
User-Agent: Zoiper rev.4186
Via: SIP/2.0/UDP xx.xx.xxx.xx:5060
Content-Length: 0

Incoming from yyy.yyy.yy.yyy:1024 - 
BYE sip:5678@xx.xx.xxx.xx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.121:5060;branch=z9hG4bK-598f1319
From: <sip:3998@xx.xx.xxx.xx>;tag=53cca4372c533924i0
To: "(null)" <sip:5678@xx.xx.xxx.xx>;tag=7b2add35
Call-ID: AW6zfKQ8RWl71MipIe4X1WWKfw7xGGR9@chat.seohosting.com
CSeq: 101 BYE
Max-Forwards: 70
User-Agent: Linksys/SPA941-5.1.8
Content-Length: 0

Outgoing to 174.37.45.134:5060 - 
BYE sip:5678@4.68.250.148 SIP/2.0
CSeq: 2 BYE
Call-ID: MIAMGC0120091027172219041244@209.244.63.32
Contact: <sip:1234@xx.xx.xxx.xx>
From: <sip:+11234@4.79.212.229:5060>;tag=BYFeP7T1
Max-Forwards: 70
Route: <sip:174.37.45.134;lr=on;ftag=VPSF506071629460>, <sip:67.228.177.9;lr=on;ftag=VPSF506071629460>, <sip:216.82.224.202;lr;ftag=VPSF506071629460>
To: "CARRO RAMON    "  <sip:+15678@4.68.250.148;isup-oli=0>;tag=VPSF506071629460
Via: SIP/2.0/UDP 174.37.45.134:5060
Content-Length: 0

Outgoing to yyy.yyy.yy.yyy:1024 - 
SIP/2.0 200 OK
CSeq: 101 BYE
Call-ID: AW6zfKQ8RWl71MipIe4X1WWKfw7xGGR9@chat.seohosting.com
From: <sip:3998@xx.xx.xxx.xx>;tag=53cca4372c533924i0;tag=D1EASwOG
Max-Forwards: 70
To: "(null)" <sip:5678@xx.xx.xxx.xx>;tag=7b2add35
Via: SIP/2.0/UDP 192.168.1.121:5060;branch=z9hG4bK-598f1319

Incoming from 174.37.45.134:5060 - 
SIP/2.0 408 Request Timeout
CSeq: 2 BYE
Call-ID: MIAMGC0120091027172219041244@209.244.63.32
From: <sip:+11234@4.79.212.229:5060>;tag=BYFeP7T1
To: "CARRO RAMON    "  <sip:+15678@4.68.250.148;isup-oli=0>;tag=VPSF506071629460
Via: SIP/2.0/UDP 174.37.45.134:5060;rport=5060;received=xx.xx.xxx.xx
Server: Kamailio (1.5.2-notls (x86_64/linux))
Content-Length: 0
Warning: 392 67.228.177.9:5060 "Noisy feedback tells:  pid=15004 req_src_ip=174.37.45.134 req_src_port=5060 in_uri=sip:5678@4.68.250.148 out_uri=sip:5678@4.68.250.148 via_cnt==1092"

You might want to check what does the value of warning header says. There is some custom message "Noisy feedback tells"... this is very application specific. Request Timeout messages are usually emulated by stack when transaction timeout is expired. That might mean your BYE request to 174.37.45.134:5060 could not reach destination. This can also be the case when original BYE request is malformed and other party ignores it.

Have you tried debugging your server locally with SIPp?
You can also run Ethereal (Wireshark) to check your traffic.

"via_cnt==1092" is also very suspicious.

BTW, you appear to building a B2BUA, in that you accept the call from the outside before even sending an invite to local phone (1234). If the local phone were to accept with different parameters, accept a different codec, etc you'd be screwed since you told the local phone to send media directly to the original caller. They really should both be sending their media to your server, which would relay (or if needed transcode).

If you don't want to do that (i.e. you don't want to act as media relay and possible transcoder), you need to forward the INVITE to the local phone, then forward any response, etc. Basically act more as a SIP proxy server and not a SIP B2BUA.

I'd recommend to check if calling leg accepts BYE request (looks it accepts but...) and how it handles this request. What you really need is similar log from 174.37.45.134. It seems problem is behind .134 (timeout was generated by .134).

BTW as for first look I see you are breaking several basic call processing rules which could get you in such trouble: - You are missing Trying response for originating call leg. If originator's SIP stack really waits for this it could lead to call ID not really recorded. Yes, this is buggy behavior but we are living in real world. Standards say to respond with Trying ASAP (even before you are doing routing, just after call authentication - You are fully establishing call session with calling party before even initiating outgoing INVITE to called party. This is wrong logics. At least because in case of failed outgoing call originator will be billed.

If you can do this quick I'd recommend to fix call setup sequence first. You anyway will need this and there is possibility this will fix call termination:

INVITE  ->
TRYING  <-
        -> INVITE
        <- TRYING
        <- RINGING
RINGING <-
        <- OK
OK      <-
ACK     ->
        -> ACK

If you wish to be compliant with RFC 3261, it is mandated that the "Via" headers you send include the optional(!) "branch" parameter.

See RFC3261 ss 20.42:

Even though this specification mandates that the branch parameter be present in all requests, the BNF for the header field indicates that it is optional. This allows interoperation with RFC 2543 elements, which did not have to insert the branch parameter.

RFC 3261 dictates that the numbers (URI) associated in To and From Fields remain the same. If NAT’ing is involved, the IPs can change, however the numbers must remain constant. If you notice, the ‘To’ and ‘From’ fields in the BYE header are swapped making it a malformed packet.