[OpenSIPS-Users] Dialog Module and Bogus Event 8 in state 2
Sven Schulz
svens at psu.edu
Fri Jan 14 14:49:46 CET 2011
Bogdan, I hope this capture gets formatted correctly when I paste it in.
Apparently Cisco uses NOTIFY to negotiate DTMF-relay. Inside the initial
INVITE is a "Allow-Events: kpml" which the receiving gateway interprets this
as an out-of-band dtmf capability. Then immediately after the 183, you can
see the NOTIFY coming from the gateway. What you don't see here in this
capture is that once the call is setup and dialog occurs, DTMF tones are
then sent as NOTIFY packets.
Sven
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 65535
bytes
08:42:01.889314 IP (tos 0xb8, ttl 63, id 0, offset 0, flags [DF], proto:
UDP (17), length: 1031) 10.1.2.52.sip > 10.1.1.82.sip: SIP, length: 1003
INVITE sip:18148656116 at testsipcore.phonetest.psu.edu:5060 SIP/2.0
Date: Fri, 14 Jan 2011 13:42:01 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE,
REFER, SUBSCRIBE, NOTIFY, PUBLISH
From:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
Allow-Events: presence, kpml
Supported: timer,replaces
Min-SE: 1800
Remote-Party-ID:
<sip:8148636939 at 10.1.2.52>;party=calling;screen=yes;privacy=off
Content-Length: 206
User-Agent: Cisco-CUCM6.1
To: <sip:18148656116 at testsipcore.phonetest.psu.edu>
Contact: <sip:8148636939 at 10.1.2.52:5060>
Expires: 60
Content-Type: application/sdp
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
Via: SIP/2.0/UDP 10.1.2.52:5060;branch=z9hG4bK20b30df3f23
CSeq: 101 INVITE
Session-Expires: 1800
Max-Forwards: 70
v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 10.1.2.52
s=SIP Call
c=IN IP4 10.1.2.52
t=0 0
m=audio 24854 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
08:42:01.889760 IP (tos 0x10, ttl 64, id 0, offset 0, flags [DF], proto:
UDP (17), length: 385) 10.1.1.82.sip > 10.1.2.52.sip: SIP, length: 357
SIP/2.0 100 Giving a try
From:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
To: <sip:18148656116 at testsipcore.phonetest.psu.edu>
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
Via: SIP/2.0/UDP 10.1.2.52:5060;branch=z9hG4bK20b30df3f23
CSeq: 101 INVITE
Server: OpenSIPS (1.6.3-notls (x86_64/linux))
Content-Length: 0
08:42:01.889817 IP (tos 0x10, ttl 64, id 0, offset 0, flags [DF], proto:
UDP (17), length: 1117) 10.1.1.82.sip > 10.1.1.60.sip: SIP, length: 1089
INVITE sip:18148656116 at 10.1.1.60 SIP/2.0
Record-Route: <sip:10.1.1.82;lr=on;did=4a2.b78cc16>
Date: Fri, 14 Jan 2011 13:42:01 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE,
REFER, SUBSCRIBE, NOTIFY, PUBLISH
From:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
Allow-Events: presence, kpml
Supported: timer,replaces
Min-SE: 1800
Remote-Party-ID:
<sip:8148636939 at 10.1.2.52>;party=calling;screen=yes;privacy=off
Content-Length: 206
User-Agent: Cisco-CUCM6.1
To: <sip:18148656116 at testsipcore.phonetest.psu.edu>
Contact: <sip:8148636939 at 10.1.2.52:5060>
Expires: 60
Content-Type: application/sdp
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
Via: SIP/2.0/UDP 10.1.1.82;branch=z9hG4bK6718.390f04c7.0
Via: SIP/2.0/UDP 10.1.2.52:5060;branch=z9hG4bK20b30df3f23
CSeq: 101 INVITE
Session-Expires: 1800
Max-Forwards: 69
v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 10.1.2.52
s=SIP Call
c=IN IP4 10.1.2.52
t=0 0
m=audio 24854 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
08:42:01.892363 IP (tos 0x68, ttl 255, id 708, offset 0, flags [none],
proto: UDP (17), length: 493) 10.1.1.60.sip > 10.1.1.82.sip: SIP, length:
465
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.1.82;branch=z9hG4bK6718.390f04c7.0,SIP/2.0/UDP
10.1.2.52:5060;branch=z9hG4bK20b30df3f23
From:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
To: <sip:18148656116 at testsipcore.phonetest.psu.edu>
Date: Fri, 14 Jan 2011 13:43:34 GMT
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
CSeq: 101 INVITE
Allow-Events: kpml, telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
08:42:02.402083 IP (tos 0xfc, ttl 64, id 0, offset 0, flags [DF], proto:
UDP (17), length: 403) 10.1.1.80.sip > 10.1.1.82.sip: SIP, length: 375
OPTIONS sip:10.1.1.82:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP
10.1.1.80:5060;branch=z9hG4bK919fb703eeee41428272d9434d6c8928
To: <sip:10.1.1.82:5060;transport=udp>
From: <sip:10.1.1.82:5060;transport=udp>;tag=4a8b46ce
Call-ID: 3250b9ce-4d3052aa6294f-35d0765a at sipgt-48cdeeb1
CSeq: 423177660 OPTIONS
User-Agent: SIParator/4.8.1
Max-Forwards: 70
Content-Length: 0
08:42:02.402190 IP (tos 0x10, ttl 64, id 0, offset 0, flags [DF], proto:
UDP (17), length: 411) 10.1.1.82.sip > 10.1.1.80.sip: SIP, length: 383
SIP/2.0 200 ok
Via: SIP/2.0/UDP
10.1.1.80:5060;branch=z9hG4bK919fb703eeee41428272d9434d6c8928
To:
<sip:10.1.1.82:5060;transport=udp>;tag=c97b4d1cb1f3d0da549e06a8d482ef63.85bc
From: <sip:10.1.1.82:5060;transport=udp>;tag=4a8b46ce
Call-ID: 3250b9ce-4d3052aa6294f-35d0765a at sipgt-48cdeeb1
CSeq: 423177660 OPTIONS
Server: OpenSIPS (1.6.3-notls (x86_64/linux))
Content-Length: 0
08:42:03.304647 IP (tos 0x68, ttl 255, id 709, offset 0, flags [none],
proto: UDP (17), length: 1136) 10.1.1.60.sip > 10.1.1.82.sip: SIP, length:
1108
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.1.1.82;branch=z9hG4bK6718.390f04c7.0,SIP/2.0/UDP
10.1.2.52:5060;branch=z9hG4bK20b30df3f23
From:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
To: <sip:18148656116 at testsipcore.phonetest.psu.edu>;tag=38988880-C16
Date: Fri, 14 Jan 2011 13:43:34 GMT
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER,
SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: kpml, telephone-event
Remote-Party-ID:
<sip:18148656116 at 10.1.1.60>;party=called;screen=no;privacy=off
Contact: <sip:18148656116 at 10.1.1.60:5060>
Record-Route: <sip:10.1.1.82;lr=on;did=4a2.b78cc16>
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 238
v=0
o=CiscoSystemsSIP-GW-UserAgent 7275 4947 IN IP4 10.1.1.60
s=SIP Call
c=IN IP4 10.1.1.60
t=0 0
m=audio 25170 RTP/AVP 0 101
c=IN IP4 10.1.1.60
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
08:42:03.304834 IP (tos 0x10, ttl 64, id 0, offset 0, flags [DF], proto:
UDP (17), length: 1084) 10.1.1.82.sip > 10.1.2.52.sip: SIP, length: 1056
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.1.2.52:5060;branch=z9hG4bK20b30df3f23
From:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
To: <sip:18148656116 at testsipcore.phonetest.psu.edu>;tag=38988880-C16
Date: Fri, 14 Jan 2011 13:43:34 GMT
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER,
SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: kpml, telephone-event
Remote-Party-ID:
<sip:18148656116 at 10.1.1.60>;party=called;screen=no;privacy=off
Contact: <sip:18148656116 at 10.1.1.60:5060>
Record-Route: <sip:10.1.1.82;lr=on;did=4a2.b78cc16>
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 238
v=0
o=CiscoSystemsSIP-GW-UserAgent 7275 4947 IN IP4 10.1.1.60
s=SIP Call
c=IN IP4 10.1.1.60
t=0 0
m=audio 25170 RTP/AVP 0 101
c=IN IP4 10.1.1.60
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
08:42:03.315601 IP (tos 0x0, ttl 255, id 0, offset 0, flags [none], proto:
UDP (17), length: 583) 10.1.1.60.49755 > 10.1.1.82.sip: SIP, length: 555
NOTIFY sip:10.1.2.52:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.60:5060;branch=z9hG4bKFD1B90
From:
<sip:18148656116 at testsipcore.phonetest.psu.edu>;tag=38988880-C16
To:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
CSeq: 101 NOTIFY
Max-Forwards: 70
Date: Fri, 14 Jan 2011 13:43:36 GMT
User-Agent: Cisco-SIPGateway/IOS-12.x
Event: kpml
Subscription-State: active
Route: <sip:10.1.1.82;lr=on;did=4a2.b78cc16>
Contact: <sip:18148656116 at 10.1.1.60:5060>
Content-Length: 0
08:42:03.315724 IP (tos 0x10, ttl 64, id 0, offset 0, flags [DF], proto:
UDP (17), length: 595) 10.1.1.82.sip > 10.1.2.52.sip: SIP, length: 567
NOTIFY sip:10.1.2.52:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.82;branch=z9hG4bK6718.490f04c7.0
Via: SIP/2.0/UDP 10.1.1.60:5060;branch=z9hG4bKFD1B90
From:
<sip:18148656116 at testsipcore.phonetest.psu.edu>;tag=38988880-C16
To:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
CSeq: 101 NOTIFY
Max-Forwards: 69
Date: Fri, 14 Jan 2011 13:43:36 GMT
User-Agent: Cisco-SIPGateway/IOS-12.x
Event: kpml
Subscription-State: active
Contact: <sip:18148656116 at 10.1.1.60:5060>
Content-Length: 0
08:42:03.316876 IP (tos 0xb8, ttl 63, id 0, offset 0, flags [DF], proto:
UDP (17), length: 429) 10.1.2.52.sip > 10.1.1.82.sip: SIP, length: 401
SIP/2.0 200 OK
Date: Fri, 14 Jan 2011 13:42:03 GMT
From:
<sip:18148656116 at testsipcore.phonetest.psu.edu>;tag=38988880-C16
Content-Length: 0
To:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
Via: SIP/2.0/UDP 10.1.1.82;branch=z9hG4bK6718.490f04c7.0,SIP/2.0/UDP
10.1.1.60:5060;branch=z9hG4bKFD1B90
CSeq: 101 NOTIFY
08:42:03.316956 IP (tos 0x10, ttl 64, id 0, offset 0, flags [DF], proto:
UDP (17), length: 377) 10.1.1.82.sip > 10.1.1.60.sip: SIP, length: 349
SIP/2.0 200 OK
Date: Fri, 14 Jan 2011 13:42:03 GMT
From:
<sip:18148656116 at testsipcore.phonetest.psu.edu>;tag=38988880-C16
Content-Length: 0
To:
<sip:8148636939 at 10.1.2.52>;tag=d5edda48-9c10-424c-b200-8ec1eb8e532c-42505206
Call-ID: f39a000-d30152a9-59-3402010a at 10.1.2.52
Via: SIP/2.0/UDP 10.1.1.60:5060;branch=z9hG4bKFD1B90
CSeq: 101 NOTIFY
On 1/12/11 2:07 PM, "Bogdan-Andrei Iancu" <bogdan at voice-system.ro> wrote:
> Hi Sven,
>
> Interesting, never saw a NOTIFY in early state of a dialog...can you
> post a SIP capture for such a dialog ?
>
> Going back to your question, the message said that the notify event does
> not fit to the current dialog state, but this has no effect on the
> dialog state, neither on the routing / processing of the NOTIFY...
>
> Best regards,
> Bogdan
>
> Sven Schulz wrote:
>> Directly after the 183 Ringing is a NOTIFY message coming from the
>> destination (which is a Cisco Sip gateway). The source sends a corresponding
>> 200 OK to this NOTIFY (also a cisco PBX).
>>
>> So is the "bogus event" something I should be concerned with or is it more
>> of an informational error message?
>>
>> 0.000000 10.1.2.52 -> 10.1.1.82 SIP/SDP Request: INVITE
>> sip:phonenumber at xx.edu:5060, with session description
>> 0.000291 10.1.1.82 -> 10.1.2.52 SIP Status: 100 Giving a try
>> 0.001830 10.1.1.82 -> 10.1.1.60 SIP/SDP Request: INVITE
>> sip:18148656116 at 10.1.1.60, with session description
>> 0.004343 10.1.1.60 -> 10.1.1.82 SIP Status: 100 Trying
>> 1.474100 10.1.1.60 -> 10.1.1.82 SIP/SDP Status: 183 Session
>> Progress, with session description
>> 1.474240 10.1.1.82 -> 10.1.2.52 SIP/SDP Status: 183 Session
>> Progress, with session description
>> 1.483850 10.1.1.60 -> 10.1.1.82 SIP Request: NOTIFY
>> sip:10.1.2.52:5060
>> 1.483962 10.1.1.82 -> 10.1.2.52 SIP Request: NOTIFY
>> sip:10.1.2.52:5060
>> 1.486091 10.1.2.52 -> 10.1.1.82 SIP Status: 200 OK
>> 1.486133 10.1.1.82 -> 10.1.1.60 SIP Status: 200 OK
>> 4.252373 10.1.1.60 -> 10.1.1.82 SIP/SDP Status: 200 OK, with session
>> description
>> 4.252756 10.1.1.82 -> 10.1.2.52 SIP/SDP Status: 200 OK, with session
>> description
>>
>>
>>
>> On 1/12/11 6:19 AM, "Bogdan-Andrei Iancu" <bogdan at voice-system.ro> wrote:
>>
>>
>>> Hi Sven,
>>>
>>> "Bogus Event 8 in state 2" is translated to receiving an indialog
>>> request (non ACK, non BYE) while dialog in early state.....maybe it is a
>>> PRACK to the 183....can you check that ?
>>>
>>> Regards,
>>> Bogdan
>>>
>>> Sven Schulz wrote:
>>>
>>>> Running opensips 1.6.3, dialog module seems to function correctly
>>>> however I keep getting these messages:
>>>>
>>>> CRITICAL:dialog:log_next_state_dlg: bogus event 8 in state 2 for dlg
>>>> 0x2b33956052c0 [2284:61359203] with clid
>>>> '11a0bd80-d2c160b0-1a-3402010a at 10.1.2.52
>>>> <%2711a0bd80-d2c160b0-1a-3402010a at 10.1.2.52>' and tags
>>>> 'd5edda48-9c10-424c-b200-8ec1eb8e532c-42504961' '292F5834-D13'
>>>>
>>>> They only seem to happen when an INVITE is followed by a 183 RINGING
>>>> message. INVITES without a 183 wont get this error messege. Is this
>>>> normal or should I be concerned?
>>>>
>>>>
>>>> Sven Schulz
>>>> Penn State University
>>>> Telecommunications and Network Services
>>>> 814.865.6116
>>>> sip:sven at psu.edu
>>>>
>>>> ------------------------------------------------------------------------
>>>>
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users at lists.opensips.org
>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>
>>>>
>>
>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.opensips.org
>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>
>>
>
More information about the Users
mailing list