Project

General

Profile

IO-sipit29 » History » Version 13

Anonymous, 10/28/2011 11:16 AM

1 1 Adrian Georgescu
2 13 Adrian Georgescu
h1. SIPIT 29
3 1 Adrian Georgescu
4 13 Adrian Georgescu
5
6
h2. Sending BYE exception when using TCP transport
7
8
9 10 Adrian Georgescu
The problem occurs when proxy is stateless and is requesting authorization for the BYE.
10
11 1 Adrian Georgescu
The problem happens with every in-dialog request that gets challenged.
12 6 Adrian Georgescu
 
13
14 13 Adrian Georgescu
<pre>
15 5 Adrian Georgescu
SENDING: Packet 188, +0:14:23.287009
16
2011-10-24 11:35:51.825513: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
17
INVITE sip:ag02@cisco.sipit.net SIP/2.0
18
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y
19
Max-Forwards: 70
20
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
21
To: <sip:ag02@cisco.sipit.net>
22
Contact: <sip:doszpemb@132.177.252.163:51544;transport=tls>
23
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
24
CSeq: 4485 INVITE
25
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
26
Supported: 100rel, replaces, norefersub
27
User-Agent: Blink Pro 1.3.1 (MacOSX)
28
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
29
Content-Type: application/sdp
30
Content-Length:   269
31
32
v=0
33
o=- 3528437751 3528437751 IN IP4 132.177.252.163
34
s=Blink Pro 1.3.1 (MacOSX)
35
c=IN IP4 132.177.252.163
36
t=0 0
37
m=audio 50004 RTP/AVP 9 0 101
38
a=rtcp:50005
39
a=rtpmap:9 G722/8000
40
a=rtpmap:0 PCMU/8000
41
a=rtpmap:101 telephone-event/8000
42
a=fmtp:101 0-15
43
a=sendrecv
44
45
RECEIVED: Packet 189, +0:14:23.333731
46
2011-10-24 11:35:51.872235: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
47
SIP/2.0 100 Trying
48
Via: SIP/2.0/tls 132.177.252.163:51280;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y;received=132.177.252.163;rport=51280;ingress-zone=DefaultZone
49
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
50
CSeq: 4485 INVITE
51
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
52
To: <sip:ag02@cisco.sipit.net>
53
Server: TANDBERG/4103 (X7.1PreAlpha29 (TEST SW))
54
Content-Length: 0
55
56
RECEIVED: Packet 190, +0:14:23.380310
57
2011-10-24 11:35:51.918814: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
58
SIP/2.0 180 Ringing
59
Via: SIP/2.0/tls 132.177.252.163:51280;rport=51280;received=132.177.252.163;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y;ingress-zone=DefaultZone
60
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
61
CSeq: 4485 INVITE
62
Contact: <sip:qwbivsgz@132.177.252.111:60868>
63
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
64
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
65
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
66
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
67
Allow: SUBSCRIBE,NOTIFY,PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,MESSAGE,REFER
68
Server: Blink Pro 1.3.1 (MacOSX)
69
Content-Length: 0
70
71
RECEIVED: Packet 191, +0:14:28.691178
72
2011-10-24 11:35:57.229682: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
73
SIP/2.0 200 OK
74
Via: SIP/2.0/tls 132.177.252.163:51280;rport=51280;received=132.177.252.163;branch=z9hG4bKPjGqaVmgy6QI4hqusA17.VmYbSEjEn1S-y;ingress-zone=DefaultZone
75
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
76
CSeq: 4485 INVITE
77
Contact: <sip:qwbivsgz@132.177.252.111:60868>
78
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
79
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
80
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
81
Record-Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
82
Allow: SUBSCRIBE,NOTIFY,PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,MESSAGE,REFER
83
Server: Blink Pro 1.3.1 (MacOSX)
84
Supported: 100rel,replaces,norefersub
85
Content-Type: application/sdp
86
Content-Length: 255
87
88
v=0
89
o=- 3528437757 3528437758 IN IP4 132.177.252.111
90
s=Blink Pro 1.3.1 (MacOSX)
91
c=IN IP4 132.177.252.111
92
b=AS:384
93
t=0 0
94
m=audio 50018 RTP/AVP 9 101
95
a=rtcp:50019
96
a=rtpmap:9 G722/8000
97
a=rtpmap:101 telephone-event/8000
98
a=fmtp:101 0-15
99
a=sendrecv
100
101
SENDING: Packet 192, +0:14:28.691472
102
2011-10-24 11:35:57.229976: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
103
ACK sip:qwbivsgz@132.177.252.111:60868 SIP/2.0
104
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPjydOyhHyq82C92apBgV97cGE2r.G2e4GO
105
Max-Forwards: 70
106
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
107
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
108
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
109
CSeq: 4485 ACK
110
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
111
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
112
User-Agent: Blink Pro 1.3.1 (MacOSX)
113
Content-Length:  0
114
115
SENDING: Packet 193, +0:14:32.184140
116
2011-10-24 11:36:00.722644: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
117
BYE sip:qwbivsgz@132.177.252.111:60868 SIP/2.0
118
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPjqWIKkD-f1CW8BystKkNHu3QQ.HhB920m
119
Max-Forwards: 70
120
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
121
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
122
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
123
CSeq: 4486 BYE
124
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
125
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
126
User-Agent: Blink Pro 1.3.1 (MacOSX)
127
Content-Length:  0
128
129
RECEIVED: Packet 194, +0:14:32.185918
130
2011-10-24 11:36:00.724422: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
131
SIP/2.0 407 Proxy Authentication Required
132
Via: SIP/2.0/tls 132.177.252.163:51280;branch=z9hG4bKPjqWIKkD-f1CW8BystKkNHu3QQ.HhB920m;received=132.177.252.163;rport=51280
133
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
134
CSeq: 4486 BYE
135
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
136
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
137
Server: TANDBERG/4103 (X7.1PreAlpha29 (TEST SW))
138
Proxy-Authenticate: Digest realm="h1.cisco.sipit.net", nonce="ecf10cc969b2858a1f46ce145b58ba291426098f076e4fa29924531f706e", opaque="AQAAANXGRIqnJLpaa2+oaGI3teAaoA95", stale=FALSE, algorithm=MD5, qop="auth"
139
Content-Length: 0
140
141
SENDING: Packet 195, +0:14:32.186342
142
2011-10-24 11:36:00.724846: 132.177.252.163:51280 -(SIP over tls)-> 132.177.253.22:5061
143
BYE sip:qwbivsgz@132.177.252.111:60868 SIP/2.0
144
Via: SIP/2.0/tls 132.177.252.163:51280;rport;branch=z9hG4bKPj7LZjnOhpR57.YTxGAv42MyoF7RSBupjk
145
Max-Forwards: 70
146
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
147
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
148
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
149
CSeq: 4487 BYE
150
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5061;transport=tls;lr>
151
Route: <sip:proxy-call-id=9041af5c-fe23-11e0-8ac1-000c29ab0f7b@132.177.253.22:5060;transport=udp;lr>
152
User-Agent: Blink Pro 1.3.1 (MacOSX)
153
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
154
Content-Length:  0
155
156
RECEIVED: Packet 196, +0:14:32.203260
157
2011-10-24 11:36:00.741764: 132.177.253.22:5061 -(SIP over tls)-> 132.177.252.163:51280
158
SIP/2.0 200 OK
159
Via: SIP/2.0/tls 132.177.252.163:51280;rport=51280;received=132.177.252.163;branch=z9hG4bKPj7LZjnOhpR57.YTxGAv42MyoF7RSBupjk;ingress-zone=DefaultZone
160
Call-ID: wm-ihLWnDBKwk743UftUCoP-H5qoETv-
161
CSeq: 4487 BYE
162
From: "Adrian Georgescu" <sip:ag01@cisco.sipit.net>;tag=tG4TWxTurelH-rGZRnivbJ96jCHFsQS8
163
To: <sip:ag02@cisco.sipit.net>;tag=nkEDOGe3nL5K7PwTs1-DzrwUmbdzAYUy
164
Server: Blink Pro 1.3.1 (MacOSX)
165
Content-Length: 0
166 1 Adrian Georgescu
167
2011-10-24 11:36:12.346891: DNS lookup A h1.cisco.sipit.net succeeded, ttl=600: 132.177.253.22
168 5 Adrian Georgescu
169
170 13 Adrian Georgescu
</pre>
171 2 Adrian Georgescu
172 13 Adrian Georgescu
<pre>
173 2 Adrian Georgescu
2011-10-24 10:42:21.419 Blink Pro[1668:a0f] [Session with ag02@cisco.sipit.net] Ending session with audio stream
174
2011-10-24 10:42:21.457 Blink Pro[1668:6527] Traceback (most recent call last):
175
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
176
    call.func(*call.args, **call.kw)
177
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/coros.py", line 253, in _do_acquire
178
    waiter.switch()
179
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
180 1 Adrian Georgescu
    return cb(*args, **kw)
181 2 Adrian Georgescu
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 1904, in end
182
    TimestampedNotificationData(originator='local', method='BYE', code=notification.data.code, reason=notification.data.reason))
183 1 Adrian Georgescu
AttributeError: 'NotificationData' object has no attribute 'code'
184 2 Adrian Georgescu
2011-10-24 10:42:21.474 Blink Pro[1668:a0f] [Session with ag02@cisco.sipit.net] Session will end (local)
185
2011-10-24 10:42:21.643 Blink Pro[1668:a0f] [Session with ag02@cisco.sipit.net] Audio stream ended
186 13 Adrian Georgescu
</pre>
187 2 Adrian Georgescu
188
189
190 13 Adrian Georgescu
<pre>
191 2 Adrian Georgescu
2011-10-24 10:31:00.239837: Notification name=SIPInvitationChangedState
192
sender=<sipsimple.core._core.Invitation object at 0x18c5ab10>
193
data=NotificationData(originator='local', body=None, prev_sub_state='normal',
194
timestamp=datetime.datetime(2011, 10, 24, 10, 31, 0, 232073), headers={'Via':
195
[FrozenViaHeader('tls', '132.177.252.163', 50951, frozendict({'rport': 0,
196
'branch': 'z9hG4bKPj5bKvhluLSr5OxNTM0vdb4umkCpVNtox8'}))], 'From':
197
FrozenFromHeader(FrozenSIPURI('cisco.sipit.net', 'ag01', None, None, False,
198
frozendict({}), frozendict({})), u'Adrian Georgescu', frozendict({'tag':
199
'kfOPAVWAfIHorykAJBu31vAmIZif780n'})), 'Route':
200
[FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
201
'proxy-call-id=844482fa-fe1a-11e0-bd41-000c29ab0f7b', None, 5061, False,
202
frozendict({'lr': 1, 'transport': 'tls'}), frozendict({})), None,
203
frozendict({})), FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
204
'proxy-call-id=844482fa-fe1a-11e0-bd41-000c29ab0f7b', None, 5061, False,
205
frozendict({'lr': 1, 'transport': 'tls'}), frozendict({})), None,
206
frozendict({}))], 'User-Agent': FrozenHeader('User-Agent', 'Blink Pro 1.3.1
207
(MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('cisco.sipit.net', 'ag02', None,
208
None, False, frozendict({}), frozendict({})), None, frozendict({'tag':
209
'-9Gm-krVFw154HwQh5W.UsZY12oHT9di'})), 'CSeq': (8401, 'BYE'), 'Call-ID':
210
FrozenHeader('Call-ID', 'JzYfmKI6hZg0iBD9t4WdpKNhW6SyQzlm'), 'Max-Forwards':
211
70}, state='disconnecting', prev_state='connected', method='BYE',
212
request_uri=FrozenSIPURI('132.177.252.111', 'qwbivsgz', None, 51564, False,
213 1 Adrian Georgescu
frozendict({'transport': 'tls'}), frozendict({})))
214 2 Adrian Georgescu
215
216
2011-10-24 10:31:00.259586: Notification name=SIPInvitationChangedState
217
sender=<sipsimple.core._core.Invitation object at 0x18c5ab10>
218 1 Adrian Georgescu
data=NotificationData(originator='local', disconnect_reason='user request',
219
state='disconnected', prev_state='disconnecting',
220
timestamp=datetime.datetime(2011, 10, 24, 10, 31, 0, 250102))
221 13 Adrian Georgescu
</pre>
222 1 Adrian Georgescu
223 3 Adrian Georgescu
224
200 OK rdata seems to be none for received 200OK for the sent out BYE
225
226
227
228 13 Adrian Georgescu
h3. UDP trace that works
229
230
231
<pre>
232 3 Adrian Georgescu
2011-10-24 10:46:07.277414: Notification name=SIPInvitationChangedState
233
sender=<sipsimple.core._core.Invitation object at 0x18c5abf8>
234
data=NotificationData(originator='local', body=None, prev_sub_state='normal',
235
timestamp=datetime.datetime(2011, 10, 24, 10, 46, 7, 268879), headers={'Via':
236
[FrozenViaHeader('UDP', '132.177.252.163', 60653, frozendict({'rport': 0,
237
'branch': 'z9hG4bKPjVWjI8ftu8DW7rR5WhnOsbgpAWQFpbFYT'}))], 'From':
238
FrozenFromHeader(FrozenSIPURI('cisco.sipit.net', 'ag01', None, None, False,
239
frozendict({}), frozendict({})), u'Adrian Georgescu', frozendict({'tag':
240
'M5uaZcSknKymRnkGTjRG88C8DG99m5Hy'})), 'Route':
241
[FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
242
'proxy-call-id=99e57f04-fe1c-11e0-ba17-000c29ab0f7b', None, 5060, False,
243
frozendict({'lr': 1, 'transport': 'udp'}), frozendict({})), None,
244
frozendict({})), FrozenRouteHeader(FrozenSIPURI('132.177.253.22',
245
'proxy-call-id=99e57f04-fe1c-11e0-ba17-000c29ab0f7b', None, 5060, False,
246
frozendict({'lr': 1, 'transport': 'tcp'}), frozendict({})), None,
247
frozendict({}))], 'User-Agent': FrozenHeader('User-Agent', 'Blink Pro 1.3.1
248
(MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('cisco.sipit.net', 'ag02', None,
249
None, False, frozendict({}), frozendict({})), None, frozendict({'tag':
250
'hNd9U3UKc.VP-1WWYP-S8MegH2yeRc5e'})), 'CSeq': (28697, 'BYE'), 'Call-ID':
251
FrozenHeader('Call-ID', '41QYdm0-Eny2uHKzgETWx57HhGq47xPl'), 'Max-Forwards':
252
70}, state='disconnecting', prev_state='connected', method='BYE',
253
request_uri=FrozenSIPURI('132.177.252.111', 'qwbivsgz', None, 51252, False,
254
frozendict({'transport': 'tcp'}), frozendict({})))
255
256
257
2011-10-24 10:46:07.293137: Notification name=SIPInvitationChangedState
258
sender=<sipsimple.core._core.Invitation object at 0x18c5abf8>
259
data=NotificationData(originator='remote', body=None, code=200,
260
disconnect_reason='user request', timestamp=datetime.datetime(2011, 10, 24, 10,
261
46, 7, 287860), state='disconnected', headers={'Content-Length': 0, 'Via':
262 1 Adrian Georgescu
[FrozenViaHeader('UDP', '132.177.252.163', 60653, frozendict({'received':
263 3 Adrian Georgescu
'132.177.252.163', 'ingress-zone': 'DefaultSubZone', 'rport': 60653, 'branch':
264
'z9hG4bKPjB6pOFsn58EsyG4sXhsB.72oClDLkXjEW'}))], 'From':
265 1 Adrian Georgescu
FrozenFromHeader(FrozenSIPURI('cisco.sipit.net', 'ag01', None, None, False,
266
frozendict({}), frozendict({})), u'Adrian Georgescu', frozendict({'tag':
267
'M5uaZcSknKymRnkGTjRG88C8DG99m5Hy'})), 'Server': FrozenHeader('Server', 'Blink
268 3 Adrian Georgescu
Pro 1.3.1 (MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('cisco.sipit.net',
269 1 Adrian Georgescu
'ag02', None, None, False, frozendict({}), frozendict({})), None,
270 3 Adrian Georgescu
frozendict({'tag': 'hNd9U3UKc.VP-1WWYP-S8MegH2yeRc5e'})), 'CSeq': (28698,
271
'BYE'), 'Call-ID': FrozenHeader('Call-ID', '41QYdm0-Eny2uHKzgETWx57HhGq47xPl')},
272
reason='OK', prev_state='disconnecting')
273 13 Adrian Georgescu
</pre>
274 3 Adrian Georgescu
275 2 Adrian Georgescu
276 7 Adrian Georgescu
277 13 Adrian Georgescu
h2. MSRP Error (Solved)
278
279
280 9 Adrian Georgescu
Incoming session is cancelled by remote before we have the chance to initialize msrp media stream.
281 8 Adrian Georgescu
282 13 Adrian Georgescu
<pre>
283 7 Adrian Georgescu
2011-10-24 13:24:24.311 Blink Pro[3997:a0f] [Session with ag02@cisco.sipit.net] Session ended
284
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
285
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
286
2011-10-24 13:26:43.250 Blink Pro[3997:a0f] Incoming session request from GES <ges@georgescu.info> with chat streams
287
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
288
2011-10-24 13:27:21.438 Blink Pro[3997:a0f] Accepting session to ges@georgescu.info
289
2011-10-24 13:27:21.440 Blink Pro[3997:a0f] [Session with ges@georgescu.info] Handling incoming chat stream
290
2011-10-24 13:27:21.730 Blink Pro[3997:6527] Starting factory <eventlet.twistedutil.protocol.GreenInstanceFactory instance at 0x1885c620>
291
2011-10-24 13:27:21.740 Blink Pro[3997:6527] /etc/resolv.conf changed, reparsing
292
2011-10-24 13:27:21.740 Blink Pro[3997:6527] Resolver added ('132.177.252.2', 53) to server list
293
2011-10-24 13:27:21.742 Blink Pro[3997:6527] <class 'twisted.names.dns.DNSDatagramProtocol'> starting on 54952
294
2011-10-24 13:27:21.742 Blink Pro[3997:6527] Starting protocol <twisted.names.dns.DNSDatagramProtocol object at 0x18c0a490>
295 1 Adrian Georgescu
2011-10-24 13:27:21.939 Blink Pro[3997:6527] (Port 54952 Closed)
296 7 Adrian Georgescu
2011-10-24 13:27:21.940 Blink Pro[3997:6527] Stopping protocol <twisted.names.dns.DNSDatagramProtocol object at 0x18c0a490>
297
2011-10-24 13:27:23.978 Blink Pro[3997:6527] Traceback (most recent call last):
298
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
299
    call.func(*call.args, **call.kw)
300 1 Adrian Georgescu
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/hubs/twistedr.py", line 159, in call_if_greenlet_alive
301 7 Adrian Georgescu
    return func(*args1, **kwargs1)
302
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
303
    return cb(*args, **kw)
304
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/streams/msrp.py", line 260, in end
305
    notification_center.remove_observer(self, sender=self)
306
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/application/notification.py", line 164, in remove_observer
307 1 Adrian Georgescu
    raise KeyError("observer %r not registered for %r events from %r" % (observer, name, sender))
308
KeyError: 'observer <sipsimple.streams.msrp.ChatStream object at 0x1860cfd0> not registered for Any events from <sipsimple.streams.msrp.ChatStream object at 0x1860cfd0>'
309 13 Adrian Georgescu
</pre>
310 9 Adrian Georgescu
311 11 Adrian Georgescu
== Multiple reconnect for MSRP and cancel (when clicking cancel and reconnect like there is no tomorrow)==
312 9 Adrian Georgescu
313
314
315 13 Adrian Georgescu
<pre>
316 9 Adrian Georgescu
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
317
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
318
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)
319
2011-10-24 15:31:07.248 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
320
2011-10-24 15:31:07.262 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
321
2011-10-24 15:31:07.287 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
322
2011-10-24 15:31:07.317 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Session cancelled
323
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
324
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
325
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
326
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)
327
2011-10-24 15:31:07.470 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
328
2011-10-24 15:31:07.473 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
329
2011-10-24 15:31:07.501 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
330
2011-10-24 15:31:07.532 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Session cancelled
331
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
332
2011-10-24 15:31:07.696 Blink Pro[3997:6527] Traceback (most recent call last):
333
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
334
    call.func(*call.args, **call.kw)
335
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
336
    g.switch()
337
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
338
    return cb(*args, **kw)
339
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
340
    handler(notification)
341
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2310, in _NH_SIPInvitationChangedState
342
    elif notification.data.state == 'connected' and notification.data.sub_state == 'normal' and notification.data.prev_sub_state == 'received_proposal':
343
AttributeError: 'NotificationData' object has no attribute 'prev_sub_state'
344
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
345
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
346
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)
347
2011-10-24 15:31:07.775 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
348
2011-10-24 15:31:07.782 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
349
2011-10-24 15:31:07.804 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
350
2011-10-24 15:31:08.075 Blink Pro[3997:6527] Traceback (most recent call last):
351
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
352
    call.func(*call.args, **call.kw)
353
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
354
    g.switch()
355
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
356
    return cb(*args, **kw)
357
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
358
    handler(notification)
359
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2310, in _NH_SIPInvitationChangedState
360
    elif notification.data.state == 'connected' and notification.data.sub_state == 'normal' and notification.data.prev_sub_state == 'received_proposal':
361
AttributeError: 'NotificationData' object has no attribute 'prev_sub_state'
362
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
363
2011-10-24 15:31:08.551 Blink Pro[3997:6527] *** attempt to pop an unknown autorelease pool (0x24d0e00)
364
2011-10-24 15:31:08.760 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Session cancelled
365
2011-10-24 15:31:08.775 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Chat stream ended
366
2011-10-24 15:31:17.812 Blink Pro[3997:6527] Traceback (most recent call last):
367
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
368
    call.func(*call.args, **call.kw)
369
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
370
    g.switch()
371
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
372
    return cb(*args, **kw)
373
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
374
    handler(notification)
375
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2328, in _NH_SIPInvitationChangedState
376
    for stream in self.streams:
377
TypeError: 'NoneType' object is not iterable
378
2011-10-24 15:31:18.005 Blink Pro[3997:6527] Traceback (most recent call last):
379
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
380
    call.func(*call.args, **call.kw)
381
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 239, in _spawn
382
    g.switch()
383
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
384
    return cb(*args, **kw)
385
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2175, in handle_notification
386
    handler(notification)
387
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 2328, in _NH_SIPInvitationChangedState
388
    for stream in self.streams:
389
TypeError: 'NoneType' object is not iterable
390
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
391
2011-10-24 15:32:14.921 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
392
2011-10-24 15:32:14.922 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
393
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
394
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
395
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)
396
2011-10-24 15:32:15.501 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Connecting session
397
2011-10-24 15:32:15.512 Blink Pro[3997:a0f] Starting Outgoing Session to agp@conference.sip2sip.info with ['chat']
398
2011-10-24 15:32:15.772 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Ending session with chat stream
399
2011-10-24 15:32:26.048 Blink Pro[3997:6527] Traceback (most recent call last):
400
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/twisted/internet/base.py", line 757, in runUntilCurrent
401 1 Adrian Georgescu
    call.func(*call.args, **call.kw)
402
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/coros.py", line 253, in _do_acquire
403
    waiter.switch()
404
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/eventlet/api.py", line 235, in _spawn_startup
405
    return cb(*args, **kw)
406
  File "/Users/adigeo/work/blink/build/Release/Blink Pro.app/Contents/Resources/lib/sipsimple/session.py", line 1898, in end
407
    TimestampedNotificationData(originator='local', method='INVITE', code=notification.data.code, reason=notification.data.reason))
408
AttributeError: 'NotificationData' object has no attribute 'code'
409
2011-10-24 15:32:26.057 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Chat stream ended
410 9 Adrian Georgescu
2011-10-24 15:32:28.717 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
411
2011-10-24 15:32:28.718 Blink Pro[3997:a0f] Re-establishing session to agp@conference.sip2sip.info
412
2011-10-24 15:32:28.762 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Proposing chat stream
413
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
414
2011-10-24 15:32:41.751 Blink Pro[3997:a0f] [Session with agp@conference.sip2sip.info] Cancelling proposal
415
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
416
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
417 13 Adrian Georgescu
</pre>
418 9 Adrian Georgescu
419 1 Adrian Georgescu
420 13 Adrian Georgescu
h2. Problem if hold request is received with direction "inactive"
421 11 Adrian Georgescu
422
423 13 Adrian Georgescu
* 200 OK is correct
424
* Another INVITE is sent with same SDP, possibly confusing session state
425
426
427
h2. ICE relayed candidates MUST have rel-addr and rel-port
428
429
430
* In the candidates added by MediaProxy
431
* RFC5245, page 74.