SIP SIMPLE Client SDK

h1. SIPIT 29

h2. 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.

<pre>

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

</pre>

<pre>

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

</pre>

<pre>

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))

</pre>

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

h3. UDP trace that works

<pre>

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')

</pre>

h2. MSRP Error (Solved)

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

<pre>

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>'

</pre>

== Multiple reconnect for MSRP and cancel (when clicking cancel and reconnect like there is no tomorrow)==

<pre>

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

</pre>

h2. Problem if hold request is received with direction "inactive"

* 200 OK is correct

* Another INVITE is sent with same SDP, possibly confusing session state

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

* In the candidates added by MediaProxy

* RFC5245, page 74.