Project

General

Profile

Actions

SIPIT 29

Sending BYE exception when using TCP transport

The problem occurs when proxy is stateless and is requesting authorization for the BYE.

The problem happens with every in-dialog request that gets challenged.

SENDING: Packet 188, +0:14:23.287009
2011-10-24 11:35:51.825513: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
INVITE sip:ag02@cisco.sipit.net SIP/2.0
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y
Max-Forwards: 70
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>
Contact: <sip:doszpemb@132.177.252.163:51544;transport=tls>
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4485 INVITE
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Supported: 100rel, replaces, norefersub
User-Agent: Blink Pro 1.3.1 (MacOSX)
Proxy-Authorization: Digest username="cisco", realm="h1.cisco.sipit.net", nonce="5f8327823b80b7c1ad635e68c6ab5ef8b1ac0010d74c76ea30d139be4b0e", uri="sip:ag02@cisco.sipit.net", response="02829cb450bd6f420e8f980f80dec000", algorithm=MD5, cnonce="WMYZEu5MhMBRJr97hlz3Nxqd9pidFkvZ", opaque="AQAAANXGRIqnJLpaa2+oaGI3teAaoA95", qop=auth, nc=00000001
Content-Type: application/sdp
Content-Length:   269

v=0
o=- 3528437751 3528437751 IN IP4 132.177.252.163
s=Blink Pro 1.3.1 (MacOSX)
c=IN IP4 132.177.252.163
t=0 0
m=audio 50004 RTP/AVP 9 0 101
a=rtcp:50005
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

RECEIVED: Packet 189, +0:14:23.333731
2011-10-24 11:35:51.872235: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
SIP/2.0 100 Trying
Via: SIP/2.0/tls 132.177.252.163:51280;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y;received=132.177.252.163;rport=51280;ingress-zone=DefaultZone
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4485 INVITE
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>
Server: TANDBERG/4103 (X7.1PreAlpha29 (TEST SW))
Content-Length: 0

RECEIVED: Packet 190, +0:14:23.380310
2011-10-24 11:35:51.918814: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
SIP/2.0 180 Ringing
Via: SIP/2.0/tls 132.177.252.163:51280;rport=51280;received=132.177.252.163;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y;ingress-zone=DefaultZone
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4485 INVITE
Contact: <sip:qwbivsgz@132.177.252.111:60868>
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
Allow: SUBSCRIBE,NOTIFY,PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,MESSAGE,REFER
Server: Blink Pro 1.3.1 (MacOSX)
Content-Length: 0

RECEIVED: Packet 191, +0:14:28.691178
2011-10-24 11:35:57.229682: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
SIP/2.0 200 OK
Via: SIP/2.0/tls 132.177.252.163:51280;rport=51280;received=132.177.252.163;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y;ingress-zone=DefaultZone
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4485 INVITE
Contact: <sip:qwbivsgz@132.177.252.111:60868>
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
Allow: SUBSCRIBE,NOTIFY,PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,MESSAGE,REFER
Server: Blink Pro 1.3.1 (MacOSX)
Supported: 100rel,replaces,norefersub
Content-Type: application/sdp
Content-Length: 255

v=0
o=- 3528437757 3528437758 IN IP4 132.177.252.111
s=Blink Pro 1.3.1 (MacOSX)
c=IN IP4 132.177.252.111
b=AS:384
t=0 0
m=audio 50018 RTP/AVP 9 101
a=rtcp:50019
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

SENDING: Packet 192, +0:14:28.691472
2011-10-24 11:35:57.229976: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
ACK sip:qwbivsgz@132.177.252.111:60868 SIP/2.0
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPjydOyhHyq82C92apBgV97cGE2r.G2e4GO
Max-Forwards: 70
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4485 ACK
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
User-Agent: Blink Pro 1.3.1 (MacOSX)
Content-Length:  0

SENDING: Packet 193, +0:14:32.184140
2011-10-24 11:36:00.722644: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
BYE sip:qwbivsgz@132.177.252.111:60868 SIP/2.0
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPjqWIKkD-f1CW8BystKkNHu3QQ.HhB920m
Max-Forwards: 70
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4486 BYE
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
User-Agent: Blink Pro 1.3.1 (MacOSX)
Content-Length:  0

RECEIVED: Packet 194, +0:14:32.185918
2011-10-24 11:36:00.724422: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/tls 132.177.252.163:51280;branch=z9hG4bKPjqWIKkD-f1CW8BystKkNHu3QQ.HhB920m;received=132.177.252.163;rport=51280
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4486 BYE
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
Server: TANDBERG/4103 (X7.1PreAlpha29 (TEST SW))
Proxy-Authenticate: Digest realm="h1.cisco.sipit.net", nonce="ecf10cc969b2858a1f46ce145b58ba291426098f076e4fa29924531f706e", opaque="AQAAANXGRIqnJLpaa2+oaGI3teAaoA95", stale=FALSE, algorithm=MD5, qop="auth" 
Content-Length: 0

SENDING: Packet 195, +0:14:32.186342
2011-10-24 11:36:00.724846: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
BYE sip:qwbivsgz@132.177.252.111:60868 SIP/2.0
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPj7LZjnOhpR57.YTxGAv42MyoF7RSBupjk
Max-Forwards: 70
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4487 BYE
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
User-Agent: Blink Pro 1.3.1 (MacOSX)
Proxy-Authorization: Digest username="cisco", realm="h1.cisco.sipit.net", nonce="ecf10cc969b2858a1f46ce145b58ba291426098f076e4fa29924531f706e", uri="sip:qwbivsgz@132.177.252.111:60868", response="6ed728af6b1b5443c953ec89d17151c6", algorithm=MD5, cnonce="WMYZEu5MhMBRJr97hlz3Nxqd9pidFkvZ", opaque="AQAAANXGRIqnJLpaa2+oaGI3teAaoA95", qop=auth, nc=00000001
Content-Length:  0

RECEIVED: Packet 196, +0:14:32.203260
2011-10-24 11:36:00.741764: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
SIP/2.0 200 OK
Via: SIP/2.0/tls 132.177.252.163:51280;rport=51280;received=132.177.252.163;branch=z9hG4bKPj7LZjnOhpR57.YTxGAv42MyoF7RSBupjk;ingress-zone=DefaultZone
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
CSeq: 4487 BYE
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
Server: Blink Pro 1.3.1 (MacOSX)
Content-Length: 0

2011-10-24 11:36:12.346891: DNS lookup A h1.cisco.sipit.net succeeded, ttl=600: 132.177.253.22

2011-10-24 10:42:21.419 Blink Pro[1668:a0f] [Session with ag02@cisco.sipit.net] Ending session with audio stream
2011-10-24 10:42:21.457 Blink Pro[1668:6527] Traceback (most recent call last):
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/coros.py", line 253, in _do_acquire
    waiter.switch()
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
    return cb(*args, **kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 1904, in end
    TimestampedNotificationData(originator='local', method='BYE', code=notification.data.code, reason=notification.data.reason))
AttributeError: 'NotificationData' object has no attribute 'code'
2011-10-24 10:42:21.474 Blink Pro[1668:a0f] [Session with ag02@cisco.sipit.net] Session will end (local)
2011-10-24 10:42:21.643 Blink Pro[1668:a0f] [Session with ag02@cisco.sipit.net] Audio stream ended
2011-10-24 10:31:00.239837: Notification name=SIPInvitationChangedState
sender=<sipsimple.core._core.Invitation object at 0x18c5ab10>
data=NotificationData(originator='local', body=None, prev_sub_state='normal',
timestamp=datetime.datetime(2011, 10, 24, 10, 31, 0, 232073), headers={'Via':
[FrozenViaHeader('tls', '132.177.252.163', 50951, frozendict({'rport': 0,
'branch': 'z9hG4bKPj5bKvhluLSr5OxNTM0vdb4umkCpVNtox8'}))], 'From':
FrozenFromHeader(FrozenSIPURI('cisco.sipit.net', 'ag01', None, None, False,
frozendict({}), frozendict({})), u'Adrian Georgescu', frozendict({'tag':
'kfOPAVWAfIHorykAJBu31vAmIZif780n'})), 'Route':
[FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
'proxy-call-id=844482fa-fe1a-11e0-bd41-000c29ab0f7b', None, 5061, False,
frozendict({'lr': 1, 'transport': 'tls'}), frozendict({})), None,
frozendict({})), FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
'proxy-call-id=844482fa-fe1a-11e0-bd41-000c29ab0f7b', None, 5061, False,
frozendict({'lr': 1, 'transport': 'tls'}), frozendict({})), None,
frozendict({}))], 'User-Agent': FrozenHeader('User-Agent', 'Blink Pro 1.3.1
(MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('cisco.sipit.net', 'ag02', None,
None, False, frozendict({}), frozendict({})), None, frozendict({'tag':
'-9Gm-krVFw154HwQh5W.UsZY12oHT9di'})), 'CSeq': (8401, 'BYE'), 'Call-ID':
FrozenHeader('Call-ID', 'JzYfmKI6hZg0iBD9t4WdpKNhW6SyQzlm'), 'Max-Forwards':
70}, state='disconnecting', prev_state='connected', method='BYE',
request_uri=FrozenSIPURI('132.177.252.111', 'qwbivsgz', None, 51564, False,
frozendict({'transport': 'tls'}), frozendict({})))

2011-10-24 10:31:00.259586: Notification name=SIPInvitationChangedState
sender=<sipsimple.core._core.Invitation object at 0x18c5ab10>
data=NotificationData(originator='local', disconnect_reason='user request',
state='disconnected', prev_state='disconnecting',
timestamp=datetime.datetime(2011, 10, 24, 10, 31, 0, 250102))

200 OK rdata seems to be none for received 200OK for the sent out BYE

UDP trace that works

2011-10-24 10:46:07.277414: Notification name=SIPInvitationChangedState
sender=<sipsimple.core._core.Invitation object at 0x18c5abf8>
data=NotificationData(originator='local', body=None, prev_sub_state='normal',
timestamp=datetime.datetime(2011, 10, 24, 10, 46, 7, 268879), headers={'Via':
[FrozenViaHeader('UDP', '132.177.252.163', 60653, frozendict({'rport': 0,
'branch': 'z9hG4bKPjVWjI8ftu8DW7rR5WhnOsbgpAWQFpbFYT'}))], 'From':
FrozenFromHeader(FrozenSIPURI('cisco.sipit.net', 'ag01', None, None, False,
frozendict({}), frozendict({})), u'Adrian Georgescu', frozendict({'tag':
'M5uaZcSknKymRnkGTjRG88C8DG99m5Hy'})), 'Route':
[FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
'proxy-call-id=99e57f04-fe1c-11e0-ba17-000c29ab0f7b', None, 5060, False,
frozendict({'lr': 1, 'transport': 'udp'}), frozendict({})), None,
frozendict({})), FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
'proxy-call-id=99e57f04-fe1c-11e0-ba17-000c29ab0f7b', None, 5060, False,
frozendict({'lr': 1, 'transport': 'tcp'}), frozendict({})), None,
frozendict({}))], 'User-Agent': FrozenHeader('User-Agent', 'Blink Pro 1.3.1
(MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('cisco.sipit.net', 'ag02', None,
None, False, frozendict({}), frozendict({})), None, frozendict({'tag':
'hNd9U3UKc.VP-1WWYP-S8MegH2yeRc5e'})), 'CSeq': (28697, 'BYE'), 'Call-ID':
FrozenHeader('Call-ID', '41QYdm0-Eny2uHKzgETWx57HhGq47xPl'), 'Max-Forwards':
70}, state='disconnecting', prev_state='connected', method='BYE',
request_uri=FrozenSIPURI('132.177.252.111', 'qwbivsgz', None, 51252, False,
frozendict({'transport': 'tcp'}), frozendict({})))

2011-10-24 10:46:07.293137: Notification name=SIPInvitationChangedState
sender=<sipsimple.core._core.Invitation object at 0x18c5abf8>
data=NotificationData(originator='remote', body=None, code=200,
disconnect_reason='user request', timestamp=datetime.datetime(2011, 10, 24, 10,
46, 7, 287860), state='disconnected', headers={'Content-Length': 0, 'Via':
[FrozenViaHeader('UDP', '132.177.252.163', 60653, frozendict({'received':
'132.177.252.163', 'ingress-zone': 'DefaultSubZone', 'rport': 60653, 'branch':
'z9hG4bKPjB6pOFsn58EsyG4sXhsB.72oClDLkXjEW'}))], 'From':
FrozenFromHeader(FrozenSIPURI('cisco.sipit.net', 'ag01', None, None, False,
frozendict({}), frozendict({})), u'Adrian Georgescu', frozendict({'tag':
'M5uaZcSknKymRnkGTjRG88C8DG99m5Hy'})), 'Server': FrozenHeader('Server', 'Blink
Pro 1.3.1 (MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('cisco.sipit.net',
'ag02', None, None, False, frozendict({}), frozendict({})), None,
frozendict({'tag': 'hNd9U3UKc.VP-1WWYP-S8MegH2yeRc5e'})), 'CSeq': (28698,
'BYE'), 'Call-ID': FrozenHeader('Call-ID', '41QYdm0-Eny2uHKzgETWx57HhGq47xPl')},
reason='OK', prev_state='disconnecting')

MSRP Error (Solved)

Incoming session is cancelled by remote before we have the chance to initialize msrp media stream.

2011-10-24 13:24:24.311 Blink Pro[3997:a0f] [Session with ag02@cisco.sipit.net] Session ended
2011-10-24 13:25:07.452 Blink Pro[3997:6527] Account('ag01@cisco.sipit.net') registered contact "sip:ohwvastb@132.177.252.163:52017;transport=tls" at 132.177.253.22:5061;transport=tls for 93 seconds
2011-10-24 13:26:10.570 Blink Pro[3997:6527] Account('ag01@cisco.sipit.net') registered contact "sip:ohwvastb@132.177.252.163:52017;transport=tls" at 132.177.253.22:5061;transport=tls for 93 seconds
2011-10-24 13:26:43.250 Blink Pro[3997:a0f] Incoming session request from GES <ges@georgescu.info> with chat streams
2011-10-24 13:27:13.688 Blink Pro[3997:6527] Account('ag01@cisco.sipit.net') registered contact "sip:ohwvastb@132.177.252.163:52017;transport=tls" at 132.177.253.22:5061;transport=tls for 93 seconds
2011-10-24 13:27:21.438 Blink Pro[3997:a0f] Accepting session to ges@georgescu.info
2011-10-24 13:27:21.440 Blink Pro[3997:a0f] [Session with ges@georgescu.info] Handling incoming chat stream
2011-10-24 13:27:21.730 Blink Pro[3997:6527] Starting factory <eventlet.twistedutil.protocol.GreenInstanceFactory instance at 0x1885c620>
2011-10-24 13:27:21.740 Blink Pro[3997:6527] /etc/resolv.conf changed, reparsing
2011-10-24 13:27:21.740 Blink Pro[3997:6527] Resolver added ('132.177.252.2', 53) to server list
2011-10-24 13:27:21.742 Blink Pro[3997:6527] <class 'twisted.names.dns.DNSDatagramProtocol'> starting on 54952
2011-10-24 13:27:21.742 Blink Pro[3997:6527] Starting protocol <twisted.names.dns.DNSDatagramProtocol object at 0x18c0a490>
2011-10-24 13:27:21.939 Blink Pro[3997:6527] (Port 54952 Closed)
2011-10-24 13:27:21.940 Blink Pro[3997:6527] Stopping protocol <twisted.names.dns.DNSDatagramProtocol object at 0x18c0a490>
2011-10-24 13:27:23.978 Blink Pro[3997:6527] Traceback (most recent call last):
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/hubs/twistedr.py", line 159, in call_if_greenlet_alive
    return func(*args1, **kwargs1)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
    return cb(*args, **kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/streams/msrp.py", line 260, in end
    notification_center.remove_observer(self, sender=self)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/application/notification.py", line 164, in remove_observer
    raise KeyError("observer %r not registered for %r events from %r" % (observer, name, sender))
KeyError: 'observer <sipsimple.streams.msrp.ChatStream object at 0x1860cfd0> not registered for Any events from <sipsimple.streams.msrp.ChatStream object at 0x1860cfd0>'
Multiple reconnect for MSRP and cancel (when clicking cancel and reconnect like there is no tomorrow)
2011-10-24 15:31:07.196 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Initiating DNS Lookup of Account('31208005169@ag-projects.com') to sip:agp@conference.sip2sip.info
2011-10-24 15:31:07.205 Blink Pro[3997:a0f] Starting DNS Lookup for sip:agp@conference.sip2sip.info via proxy of account 31208005169@ag-projects.com
2011-10-24 15:31:07.212 Blink Pro[3997:6527] DNS Lookup for sip:agp@conference.sip2sip.info succeeded: 85.17.186.7:5060 (UDP), 81.23.228.129:5060 (UDP)
2011-10-24 15:31:07.248 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
2011-10-24 15:31:07.262 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
2011-10-24 15:31:07.287 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
2011-10-24 15:31:07.317 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Session cancelled
2011-10-24 15:31:07.364 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Re-establishing session to agp@conference.sip2sip.info
2011-10-24 15:31:07.414 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Initiating DNS Lookup of Account('31208005169@ag-projects.com') to sip:agp@conference.sip2sip.info
2011-10-24 15:31:07.423 Blink Pro[3997:a0f] Starting DNS Lookup for sip:agp@conference.sip2sip.info via proxy of account 31208005169@ag-projects.com
2011-10-24 15:31:07.430 Blink Pro[3997:6527] DNS Lookup for sip:agp@conference.sip2sip.info succeeded: 85.17.186.7:5060 (UDP), 81.23.228.129:5060 (UDP)
2011-10-24 15:31:07.470 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
2011-10-24 15:31:07.473 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
2011-10-24 15:31:07.501 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
2011-10-24 15:31:07.532 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Session cancelled
2011-10-24 15:31:07.625 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Re-establishing session to agp@conference.sip2sip.info
2011-10-24 15:31:07.696 Blink Pro[3997:6527] Traceback (most recent call last):
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
    g.switch()
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
    return cb(*args, **kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
    handler(notification)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2310, in _NH_SIPInvitationChangedState
    elif notification.data.state == 'connected' and notification.data.sub_state == 'normal' and notification.data.prev_sub_state == 'received_proposal':
AttributeError: 'NotificationData' object has no attribute 'prev_sub_state'
2011-10-24 15:31:07.696 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Initiating DNS Lookup of Account('31208005169@ag-projects.com') to sip:agp@conference.sip2sip.info
2011-10-24 15:31:07.706 Blink Pro[3997:a0f] Starting DNS Lookup for sip:agp@conference.sip2sip.info via proxy of account 31208005169@ag-projects.com
2011-10-24 15:31:07.714 Blink Pro[3997:6527] DNS Lookup for sip:agp@conference.sip2sip.info succeeded: 85.17.186.7:5060 (UDP), 81.23.228.129:5060 (UDP)
2011-10-24 15:31:07.775 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
2011-10-24 15:31:07.782 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
2011-10-24 15:31:07.804 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
2011-10-24 15:31:08.075 Blink Pro[3997:6527] Traceback (most recent call last):
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
    g.switch()
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
    return cb(*args, **kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
    handler(notification)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2310, in _NH_SIPInvitationChangedState
    elif notification.data.state == 'connected' and notification.data.sub_state == 'normal' and notification.data.prev_sub_state == 'received_proposal':
AttributeError: 'NotificationData' object has no attribute 'prev_sub_state'
2011-10-24 15:31:08.477 Blink Pro[3997:6527] *** __NSAutoreleaseNoPool(): Object 0x1e5e4af0 of class NSCFString autoreleased with no pool in place - just leaking
2011-10-24 15:31:08.551 Blink Pro[3997:6527] *** attempt to pop an unknown autorelease pool (0x24d0e00)
2011-10-24 15:31:08.760 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Session cancelled
2011-10-24 15:31:08.775 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Chat stream ended
2011-10-24 15:31:17.812 Blink Pro[3997:6527] Traceback (most recent call last):
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
    g.switch()
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
    return cb(*args, **kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
    handler(notification)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2328, in _NH_SIPInvitationChangedState
    for stream in self.streams:
TypeError: 'NoneType' object is not iterable
2011-10-24 15:31:18.005 Blink Pro[3997:6527] Traceback (most recent call last):
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
    g.switch()
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
    return cb(*args, **kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
    handler(notification)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2328, in _NH_SIPInvitationChangedState
    for stream in self.streams:
TypeError: 'NoneType' object is not iterable
2011-10-24 15:32:02.401 Blink Pro[3997:6527] Account('ag01@cisco.sipit.net') registered contact "sip:ohwvastb@132.177.252.163:52016;transport=tcp" at 132.177.253.22:5060;transport=tcp for 93 seconds
2011-10-24 15:32:14.921 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
2011-10-24 15:32:14.922 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
2011-10-24 15:32:14.970 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Initiating DNS Lookup of Account('31208005169@ag-projects.com') to sip:agp@conference.sip2sip.info
2011-10-24 15:32:14.981 Blink Pro[3997:a0f] Starting DNS Lookup for sip:agp@conference.sip2sip.info via proxy of account 31208005169@ag-projects.com
2011-10-24 15:32:15.465 Blink Pro[3997:6527] DNS Lookup for sip:agp@conference.sip2sip.info succeeded: 81.23.228.129:5060 (UDP), 81.23.228.150:5060 (UDP), 85.17.186.7:5060 (UDP)
2011-10-24 15:32:15.501 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
2011-10-24 15:32:15.512 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
2011-10-24 15:32:15.772 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
2011-10-24 15:32:26.048 Blink Pro[3997:6527] Traceback (most recent call last):
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/coros.py", line 253, in _do_acquire
    waiter.switch()
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
    return cb(*args, **kw)
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 1898, in end
    TimestampedNotificationData(originator='local', method='INVITE', code=notification.data.code, reason=notification.data.reason))
AttributeError: 'NotificationData' object has no attribute 'code'
2011-10-24 15:32:26.057 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Chat stream ended
2011-10-24 15:32:28.717 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
2011-10-24 15:32:28.718 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
2011-10-24 15:32:28.762 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Proposing chat stream
2011-10-24 15:32:28.763 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] IllegalStateError: cannot call add_stream in terminated state
2011-10-24 15:32:41.751 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Cancelling proposal
2011-10-24 15:32:41.752 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] IllegalStateError: cannot call cancel_proposal in terminated state
2011-10-24 15:33:05.520 Blink Pro[3997:6527] Account('ag01@cisco.sipit.net') registered contact "sip:ohwvastb@132.177.252.163:52016;transport=tcp" at 132.177.253.22:5060;transport=tcp for 93 seconds

Problem if hold request is received with direction "inactive"

  • 200 OK is correct
  • Another INVITE is sent with same SDP, possibly confusing session state

ICE relayed candidates MUST have rel-addr and rel-port

  • In the candidates added by MediaProxy
  • RFC5245, page 74.

Updated by about 13 years ago ยท 13 revisions