Defect #467

SIP "BYE" PROBLEM

Added by Saúl Ibarra Corretgé almost 3 years ago. Updated almost 3 years ago.

Status:Closed Start date:
Priority:Normal Due date:
Assignee:Saúl Ibarra Corretgé % Done:

0%

Category:SIP core
Target version:-
Resolution:fixed

Description

I'm quite happy with the overall lib, I only have the following situation in my local AVAYA SIP network, can you try to replicate this?:

agents:
A - BLINK APPLICATION using sipsimple
B - VOIP PHONE/OR ANY SOFTPHONE
scenario:
1- I Dial from A TO B, B ANSWERS, wait.. I TERMINATE A, B TERMINATES
2- I Dial from B TO A, A ANSWERS, wait.. I TERMINATE A, B (DOES NOT TERMINATE!!)

BLINK SIP TRACE ON scenario 1: (OK CASE)

###############################START OF FILE SCENARIO 1
2011-08-02 14:49:42.461945 [blink 2562]: SENDING: Packet 33, +0:00:15.439867
10.228.88.102:47341 (SIP over UDP)> 10.130.0.80:5060
BYE sip:10.130.0.80:6001;transport=tls SIP/2.0

Via: SIP/2.0/UDP 10.228.88.102:47341;rport;branch=z9hG4bKPjP3.EibnifNhJDPgthaJnYZgf1u9ChY2N

Max-Forwards: 70

From: "9019805" <sip:>;tag=awzR5HikRfYkqAWq0IUKDQ2XMZaCqAFX

To: <sip:>;tag=80402187ed1e01be144e37a79200

Call-ID: eX8zaQ46hsgL3vQaySY5Zi1cSB5TA4ry

CSeq: 3447 BYE

Route: <sip:10.130.0.80:5060;lr>

Route: <sip:10.130.0.80:6001;transport=tls;lr>

User-Agent: Blink 0.2.8 (Linux)

Content-Length: 0

--
2011-08-02 14:49:42.466959 [blink 2562]: RECEIVED: Packet 34, +0:00:15.444881
10.130.0.80:5060 (SIP over UDP)> 10.228.88.102:47341
SIP/2.0 407 Proxy Authentication Required

From: "9019805" <sip:>;tag=awzR5HikRfYkqAWq0IUKDQ2XMZaCqAFX

To: <sip:>;tag=80402187ed1e01be144e37a79200

Call-ID: eX8zaQ46hsgL3vQaySY5Zi1cSB5TA4ry

CSeq: 3447 BYE

Via: SIP/2.0/UDP 10.228.88.102:47341;received=10.228.88.102;rport=47341;branch=z9hG4bKPjP3.EibnifNhJDPgthaJnYZgf1u9ChY2N

Content-Length: 0

Proxy-Authenticate: Digest realm="rtenergia.pt",domain="rtenergia.pt",nonce="MTMxMjI5MDA0NDpTREZTZXJ2ZXJTZWNyZXRLZXk6MzY5NTMyODA5",algorithm=MD5

Server: Avaya SIP Enablement Services

Organization: rtenergia.pt

--
2011-08-02 14:49:42.467153 [blink 2562]: SENDING: Packet 35, +0:00:15.445075
10.228.88.102:47341 (SIP over UDP)> 10.130.0.80:5060
BYE sip:10.130.0.80:6001;transport=tls SIP/2.0

Via: SIP/2.0/UDP 10.228.88.102:47341;rport;branch=z9hG4bKPjasYrYTBh9J.WId8LOqSo4yE-soEVaAGq

Max-Forwards: 70

From: "9019805" <sip:>;tag=awzR5HikRfYkqAWq0IUKDQ2XMZaCqAFX

To: <sip:>;tag=80402187ed1e01be144e37a79200

Call-ID: eX8zaQ46hsgL3vQaySY5Zi1cSB5TA4ry

CSeq: 3448 BYE

Route: <sip:10.130.0.80:5060;lr>

Route: <sip:10.130.0.80:6001;transport=tls;lr>

User-Agent: Blink 0.2.8 (Linux)

Proxy-Authorization: Digest username="9019805", realm="rtenergia.pt", nonce="MTMxMjI5MDA0NDpTREZTZXJ2ZXJTZWNyZXRLZXk6MzY5NTMyODA5", uri="sip:10.130.0.80:6001;transport=tls", response="87786e909c16db200b153d12c59c2c9e", algorithm=MD5

Content-Length: 0

--
2011-08-02 14:49:42.485327 [blink 2562]: RECEIVED: Packet 36, +0:00:15.463249
10.130.0.80:5060 (SIP over UDP)> 10.228.88.102:47341
SIP/2.0 200 OK

From: "9019805" <sip:>;tag=awzR5HikRfYkqAWq0IUKDQ2XMZaCqAFX

To: <sip:>;tag=80402187ed1e01be144e37a79200

Call-ID: eX8zaQ46hsgL3vQaySY5Zi1cSB5TA4ry

CSeq: 3448 BYE

Via: SIP/2.0/UDP 10.228.88.102:47341;psrrposn=1;received=10.228.88.102;rport=47341;branch=z9hG4bKPjasYrYTBh9J.WId8LOqSo4yE-soEVaAGq

Server: Avaya CM/R015x.02.0.947.3

Content-Length: 0

###############################END OF FILE SCENARIO 1

BLINK SIP TRACE ON scenario 2: (NOK CASE)

###############################START OF FILE SCENARIO 2
2011-08-02 14:50:26.875594 [blink 2590]: SENDING: Packet 23, +0:00:08.272589
10.228.88.102:33416 (SIP over UDP)> 10.130.0.80:5060
BYE sip::6001;transport=tls SIP/2.0

Via: SIP/2.0/UDP 10.228.88.102:33416;rport;branch=z9hG4bKPjXlZEVlaxaBO-26YvcNHRhsry6OAqYLXm

Max-Forwards: 70

From: "9019805" <sip:>;tag=d.NACydrdhbyukxBTOoogOjykFRXuYCo

To: "ST Travagem" <sip:>;tag=80789e347ed1e01cc144e37a79200

Call-ID: 80789e347ed1e01cd144e37a79200

CSeq: 13051 BYE

Route: <sip:10.130.0.80:5060;lr>

Route: <sip:10.130.0.80:6001;transport=tls;lr>

User-Agent: Blink 0.2.8 (Linux)

Content-Length: 0

--
2011-08-02 14:50:26.880305 [blink 2590]: RECEIVED: Packet 24, +0:00:08.277300
10.130.0.80:5060 (SIP over UDP)> 10.228.88.102:33416
SIP/2.0 407 Proxy Authentication Required

From: "9019805" <sip:>;tag=d.NACydrdhbyukxBTOoogOjykFRXuYCo

To: "ST Travagem" <sip:>;tag=80789e347ed1e01cc144e37a79200

Call-ID: 80789e347ed1e01cd144e37a79200

CSeq: 13051 BYE

Via: SIP/2.0/UDP 10.228.88.102:33416;received=10.228.88.102;rport=33416;branch=z9hG4bKPjXlZEVlaxaBO-26YvcNHRhsry6OAqYLXm

Content-Length: 0

Proxy-Authenticate: Digest realm="rtenergia.pt",domain="rtenergia.pt",nonce="MTMxMjI5MDA4ODpTREZTZXJ2ZXJTZWNyZXRLZXk6MjAwMjE1MDY5Mw==",algorithm=MD5

Server: Avaya SIP Enablement Services

Organization: rtenergia.pt

###############################END OF FILE SCENARIO 2

History

Updated by Saúl Ibarra Corretgé almost 3 years ago

follow up.. If I use the app (from pjsip 1.0) pjsua-i686-pc-linux-gnu it hangs the call well, if I use the same lib with sipsimple (from sipclients) it fails, can you give me any pointer?

Updated by Saúl Ibarra Corretgé almost 3 years ago

I did some logger marks on session.py and mixed with the pjsip dump, it seems when I accept an incoming session and then terminate it, the first bye is refused due to the authentication and then when preparing the auth this happens:
2011-08-18 14:50:56.670000 (4) sip_auth_clien: Unable to set auth for tdta0xb5376260: can not find credential for 10.130.0.80/Digest
any workaround for this?

#######################START OF LOG
@end:connected
@_NH_SIPSessionWillEnd
@notification_center.remove_observer(self, sender=stream)
@cancelling:False
@self._invitation.end(timeout=1):<sipsimple.core._core.Invitation object at 0x919b64c>
2011-08-18 14:50:46,439 INFO @Session_init
2011-08-18 14:50:46,439 INFO @Session_init
2011-08-18 14:50:46,442 INFO @Session_init_incoming
2011-08-18 14:50:46,442 INFO @Session_init_incoming
2011-08-18 14:50:46,654 INFO @_NH_SIPInvitationChangedState:incoming
2011-08-18 14:50:46,654 INFO @_NH_SIPInvitationChangedState:incoming
2011-08-18 14:50:50,928 INFO @_NH_SIPInvitationChangedState:accepting
2011-08-18 14:50:50,928 INFO @_NH_SIPInvitationChangedState:accepting
2011-08-18 14:50:50,968 INFO @_NH_SIPInvitationChangedState:accepting
2011-08-18 14:50:50,968 INFO @_NH_SIPInvitationChangedState:accepting
2011-08-18 14:50:56,630 INFO @end:connected
2011-08-18 14:50:56,630 INFO @end:connected
2011-08-18 14:50:56,644 INFO @notification_center.remove_observer(self, sender=stream)
2011-08-18 14:50:56,644 INFO @notification_center.remove_observer(self, sender=stream)
2011-08-18 14:50:56,645 INFO @cancelling:False
2011-08-18 14:50:56,645 INFO @cancelling:False
2011-08-18 14:50:56.659000 (5) endpoint: Request msg BYE/cseq=9055 (tdta0xb5376260) created.
2011-08-18 14:50:56.659000 (5) inv0xb5352c8c: Sending Request msg BYE/cseq=9055 (tdta0xb5376260)
2011-08-18 14:50:56.659000 (5) dlg0xb5352c8c: Sending Request msg BYE/cseq=9055 (tdta0xb5376260)
2011-08-18 14:50:56.659000 (5) tsx0xb5369a4c: Transaction created for Request msg BYE/cseq=9054 (tdta0xb5376260)
2011-08-18 14:50:56.659000 (5) tsx0xb5369a4c: Sending Request msg BYE/cseq=9054 (tdta0xb5376260) in state Null
2011-08-18 14:50:56.659000 (5) sip_resolve.c: Target '10.130.0.80:5060' type=Unspecified resolved to '10.130.0.80:5060' type=UDP (UDP transport)
2011-08-18 14:50:56.660000 (5) tsx0xb5369a4c: State changed from Null to Calling, event=TX_MSG
2011-08-18 14:50:56.660000 (5) dlg0xb5352c8c: Transaction tsx0xb5369a4c state changed to Calling
2011-08-18 14:50:56,661 INFO @self._invitation.end(timeout=1):<sipsimple.core._core.Invitation object at 0x919b64c>
2011-08-18 14:50:56,661 INFO @self._invitation.end(timeout=1):<sipsimple.core._core.Invitation object at 0x919b64c>
2011-08-18 14:50:56.665000 (4) wav_player.c: File player '/usr/share/sipclients/sounds/hangup_tone.wav' created: samp.rate=32000, ch=1, bufsize=4KB, filesize=32KB
2011-08-18 14:50:56.666000 (5) sip_endpoint.c: Processing incoming message: Response msg 407/BYE/cseq=9054 (rdata0x905713c)
2011-08-18 14:50:56.670000 (5) tsx0xb5369a4c: Incoming Response msg 407/BYE/cseq=9054 (rdata0x905713c) in state Calling
2011-08-18 14:50:56.670000 (5) tsx0xb5369a4c: State changed from Calling to Completed, event=RX_MSG
2011-08-18 14:50:56.670000 (5) dlg0xb5352c8c: Received Response msg 407/BYE/cseq=9054 (rdata0x905713c)
2011-08-18 14:50:56.670000 (5) dlg0xb5352c8c: Transaction tsx0xb5369a4c state changed to Completed
2011-08-18 14:50:56.670000 (4) sip_auth_clien: Unable to set auth for tdta0xb5376260: can not find credential for 10.130.0.80/Digest
2011-08-18 14:50:56.671000 (5) dlg0xb5352c8c: Session count dec to 1 by mod-invite
2011-08-18 14:50:56,702 INFO @_NH_SIPInvitationChangedState:terminating
2011-08-18 14:50:56,702 INFO @_NH_SIPInvitationChangedState:terminating
2011-08-18 14:50:56,715 INFO @_NH_SIPInvitationChangedState:terminating
2011-08-18 14:50:56,715 INFO @_NH_SIPInvitationChangedState:terminating
2011-08-18 14:50:56,723 INFO @if notification.name,notification.data.disconnect_reason:user request
2011-08-18 14:50:56,723 INFO @if notification.name,notification.data.disconnect_reason:user request
2011-08-18 14:50:56,732 INFO @else:,1962
2011-08-18 14:50:56,732 INFO @else:,1962

Updated by Saúl Ibarra Corretgé almost 3 years ago

  • Status changed from New to Closed
  • Resolution set to fixed

I solved this by using this workaround from avaya sip server:


All SIP proxies to which calls can be routed should be administered as trusted hosts in the
Avaya SIP Enablement Services server. This will permit far-end call clearing and other
supplementary call service requests by remote parties to be handled without authentication
challenges. Expand the Trusted Hosts link on the left side of the page, and click on Add. Fill
in the fields as shown. The IP Address is the IP address of the host and select the Host IP
address to the Avaya SIP Enablement Services

Also available in: Atom PDF