[SIP Beyond VoIP] MSRP sessions cannot be established by uknown reason
Adrian Georgescu
ag at ag-projects.com
Thu Sep 13 16:56:20 CEST 2012
SylkServer is using TLS for MSRP. You are using TCP.
Adrian
On Sep 13, 2012, at 4:53 PM, Hadzhiev, Tihomir wrote:
> Hi All,
>
> The problem with the SIP <-> XMPP messaging has been solved ( thanks to Saul in the latest 2.0 version, installed from source ). However the MSRP sessions seam to not work. I’m trying from IMS client towards XMPP user, and I see Sylk rejecting with Not acceptable here.
>
> Here is some debug log from Sylk:
> ==> core_trace.txt <==
> 2012-09-13 10:48:48.761690 [sylk-server 7379] (5) sip_endpoint.c: Processing incoming message: Request msg INVITE/cseq=401 (rdata0x7f79f4037908)
>
> ==> sip_trace.txt <==
> 2012-09-13 10:48:48.763443 [sylk-server 7379]: RECEIVED: Packet 63, +0:21:25.326394
> 10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.31:5070
> INVITE sip:tihoparvi at testing.com SIP/2.0
> Record-Route: <sip:mo at scscf.open-ims.test:6060;lr>
> Route: <sip:10.226.20.31:5070;lr>, <sip:iscmark at scscf.open-ims.test:6060;lr;s=1;h=0;d=0;a=7369703a616c696365406f70656e2d696d732e74657374>
> Record-Route: <sip:mo at pcscf.open-ims.test:4060;lr>
> Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bKe05.0c2dbcd6.0
> Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bKe05.9eb39b34.0
> Via: SIP/2.0/UDP 10.226.20.16:1925;rport=1925;branch=z9hG4bK1347547161148
> From: <sip:alice at open-ims.test>;tag=6936
> To: <sip:tihoparvi at testing.com>
> Call-ID: M-c2c9a849cc69530195840a86bd90ef92
> CSeq: 401 INVITE
> Max-Forwards: 15
> Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER
> Contact: <sip:alice at 10.226.20.16:1925;transport=udp>;+g.oma.sip-im
> User-Agent: IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0
> P-Preferred-Service: urn:urn-7:3gpp-service.ims.icsi.mmtel
> Accept-Contact: *;+g.oma.sip-im
> Session-Expires: 1800;refresher=uac
> Supported: timer
> Content-Type: application/sdp
> P-Access-Network-Info: ADSL;utran-cell-id-3gpp=00000000
> Privacy: none
> Allow-Events: refer, presence, presence.winfo, xcap-diff, conference
> Content-Length: 338
> P-Asserted-Identity: <sip:alice at open-ims.test>
> P-Charging-Vector: icid-value="P-CSCFabcd000000005051f25200000052";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"
>
> v=0
> o=- 3344 3344 IN IP4 10.226.20.16
> s=Mercuro IMS Client Session
> t=0 0
> m=message 1962 TCP/MSRP *
> c=IN IP4 10.226.20.16
> a=sendrecv
> a=accept-types:message/CPIM text/plain
> a=accept-wrapped-types:text/plain image/jpeg image/gif image/bmp image/png
> a=setup:active
> a=connection:new
> a=path:msrp://10.226.20.16:1962/vwsrenzkycx;tcp
>
> --
>
> ==> core_trace.txt <==
> 2012-09-13 10:48:48.766639 [sylk-server 7379] (5) tsx0x7f79f404a: Transaction created for Request msg INVITE/cseq=401 (rdata0x7f79f4037908)
> 2012-09-13 10:48:48.767834 [sylk-server 7379] (5) tsx0x7f79f404a: Incoming Request msg INVITE/cseq=401 (rdata0x7f79f4037908) in state Null
> 2012-09-13 10:48:48.769524 [sylk-server 7379] (5) tsx0x7f79f404a: State changed from Null to Trying, event=RX_MSG
> 2012-09-13 10:48:48.771056 [sylk-server 7379] (5) dlg0x7f79f402f: Transaction tsx0x7f79f404a868 state changed to Trying
> 2012-09-13 10:48:48.772243 [sylk-server 7379] (5) dlg0x7f79f402f: UAS dialog created
> 2012-09-13 10:48:48.773784 [sylk-server 7379] (5) dlg0x7f79f402f: Module mod-invite added as dialog usage, data=0x7f79f4024308
> 2012-09-13 10:48:48.775194 [sylk-server 7379] (5) dlg0x7f79f402f: Session count inc to 2 by mod-invite
> 2012-09-13 10:48:48.776449 [sylk-server 7379] (5) inv0x7f79f402f: UAS invite session created for dialog dlg0x7f79f402f318
> 2012-09-13 10:48:48.777914 [sylk-server 7379] (5) endpoint: Response msg 100/INVITE/cseq=401 (tdta0x7f79f4011cd0) created
> 2012-09-13 10:48:48.779029 [sylk-server 7379] (5) dlg0x7f79f402f: Initial answer Response msg 100/INVITE/cseq=401 (tdta0x7f79f4011cd0)
>
> ==> notifications_trace.txt <==
> 2012-09-13 10:48:48.786588 [sylk-server 7379]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x7f79f4029ed0>
> {'body': 'v=0\r\no=- 3344 3344 IN IP4 10.226.20.16\r\ns=Mercuro IMS Client Session\r\nt=0 0\r\nm=message 1962 TCP/MSRP *\r\nc=IN IP4 10.226.20.16\r\na=sendrecv\r\na=accept-types:message/CPIM text/plain\r\na=accept-wrapped-types:text/plain image/jpeg image/gif image/bmp image/png\r\na=setup:active\r\na=connection:new\r\na=path:msrp://10.226.20.16:1962/vwsrenzkycx;tcp\r\n',
> 'headers': {'Accept-Contact': FrozenHeader('Accept-Contact', '*;+g.oma.sip-im'),
> 'Allow': ['INVITE',
> 'ACK',
> 'CANCEL',
> 'BYE',
> 'MESSAGE',
> 'OPTIONS',
> 'NOTIFY',
> 'PRACK',
> 'UPDATE',
> 'REFER'],
> 'Allow-Events': ['refer',
> 'presence',
> 'presence.winfo',
> 'xcap-diff',
> 'conference'],
> 'CSeq': (401, 'INVITE'),
> 'Call-ID': FrozenHeader('Call-ID', 'M-c2c9a849cc69530195840a86bd90ef92'),
> 'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.16', 'alice', None, 1925, False, frozendict({'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0', '+g.oma.sip-im': None}))],
> 'Content-Length': 338,
> 'Content-Type': FrozenContentTypeHeader('application/sdp', frozendict({})),
> 'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '6936'})),
> 'Max-Forwards': 15,
> 'P-Access-Network-Info': FrozenHeader('P-Access-Network-Info', 'ADSL;utran-cell-id-3gpp=00000000'),
> 'P-Asserted-Identity': FrozenHeader('P-Asserted-Identity', '<sip:alice at open-ims.test>'),
> 'P-Charging-Vector': FrozenHeader('P-Charging-Vector', 'icid-value="P-CSCFabcd000000005051f25200000052";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"'),
> 'P-Preferred-Service': FrozenHeader('P-Preferred-Service', 'urn:urn-7:3gpp-service.ims.icsi.mmtel'),
> 'Privacy': FrozenHeader('Privacy', 'none'),
> 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('scscf.open-ims.test', 'mo', None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
> FrozenRecordRouteHeader(FrozenSIPURI('pcscf.open-ims.test', 'mo', None, 4060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({}))],
> 'Route': [FrozenRouteHeader(FrozenSIPURI('10.226.20.31', None, None, 5070, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
> FrozenRouteHeader(FrozenSIPURI('scscf.open-ims.test', 'iscmark', None, 6060, False, frozendict({'a': '7369703a616c696365406f70656e2d696d732e74657374', 'h': '0', 's': '1', 'lr': None, 'd': '0'}), frozendict({})), None, frozendict({}))],
> 'Session-Expires': FrozenHeader('Session-Expires', '1800;refresher=uac'),
> 'Supported': ['timer'],
> 'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({})),
> 'User-Agent': FrozenHeader('User-Agent', 'IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0'),
> 'Via': [FrozenViaHeader('UDP', '10.226.20.240', 6060, frozendict({'received': '10.226.20.240', 'branch': 'z9hG4bKe05.0c2dbcd6.0'})),
> FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bKe05.9eb39b34.0'})),
> FrozenViaHeader('UDP', '10.226.20.16', 1925, frozendict({'rport': 1925, 'branch': 'z9hG4bK1347547161148'}))]},
> 'method': 'INVITE',
> 'originator': 'remote',
> 'prev_state': None,
> 'request_uri': FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})),
> 'state': 'incoming'}
>
> ==> core_trace.txt <==
> 2012-09-13 10:48:48.787278 [sylk-server 7379] (5) inv0x7f79f402f: Sending Response msg 100/INVITE/cseq=401 (tdta0x7f79f4011cd0)
> 2012-09-13 10:48:48.787346 [sylk-server 7379] (5) dlg0x7f79f402f: Sending Response msg 100/INVITE/cseq=401 (tdta0x7f79f4011cd0)
> 2012-09-13 10:48:48.787392 [sylk-server 7379] (5) tsx0x7f79f404a: Sending Response msg 100/INVITE/cseq=401 (tdta0x7f79f4011cd0) in state Trying
> 2012-09-13 10:48:48.787436 [sylk-server 7379] (5) sip_resolve.c: Target '10.226.20.240:6060' type=UDP resolved to '10.226.20.240:6060' type=UDP (UDP transport)
>
> ==> sip_trace.txt <==
> 2012-09-13 10:48:48.787583 [sylk-server 7379]: SENDING: Packet 64, +0:21:25.350534
> 10.226.20.31:5070 -(SIP over UDP)-> 10.226.20.240:6060
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bKe05.0c2dbcd6.0
> Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bKe05.9eb39b34.0
> Via: SIP/2.0/UDP 10.226.20.16:1925;rport=1925;branch=z9hG4bK1347547161148
> Record-Route: <sip:mo at scscf.open-ims.test:6060;lr>
> Record-Route: <sip:mo at pcscf.open-ims.test:4060;lr>
> Call-ID: M-c2c9a849cc69530195840a86bd90ef92
> From: <sip:alice at open-ims.test>;tag=6936
> To: <sip:tihoparvi at testing.com>
> CSeq: 401 INVITE
> Server: SylkServer-2.0.0
> Content-Length: 0
>
>
> --
>
> ==> core_trace.txt <==
> 2012-09-13 10:48:48.787632 [sylk-server 7379] (5) tsx0x7f79f404a: State changed from Trying to Proceeding, event=TX_MSG
> 2012-09-13 10:48:48.787676 [sylk-server 7379] (5) dlg0x7f79f402f: Transaction tsx0x7f79f404a868 state changed to Proceeding
> 2012-09-13 10:48:48.787738 [sylk-server 7379] (5) inv0x7f79f402f: Sending Response msg 488/INVITE/cseq=401 (tdta0x7f79f4011cd0)
> 2012-09-13 10:48:48.787783 [sylk-server 7379] (5) dlg0x7f79f402f: Sending Response msg 488/INVITE/cseq=401 (tdta0x7f79f4011cd0)
> 2012-09-13 10:48:48.788055 [sylk-server 7379] (5) tsx0x7f79f404a: Sending Response msg 488/INVITE/cseq=401 (tdta0x7f79f4011cd0) in state Proceeding
>
> ==> sip_trace.txt <==
> 2012-09-13 10:48:48.788104 [sylk-server 7379]: SENDING: Packet 65, +0:21:25.351055
> 10.226.20.31:5070 -(SIP over UDP)-> 10.226.20.240:6060
> SIP/2.0 488 Not Acceptable Here
> Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bKe05.0c2dbcd6.0
> Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bKe05.9eb39b34.0
> Via: SIP/2.0/UDP 10.226.20.16:1925;rport=1925;branch=z9hG4bK1347547161148
> Record-Route: <sip:mo at scscf.open-ims.test:6060;lr>
> Record-Route: <sip:mo at pcscf.open-ims.test:4060;lr>
> Call-ID: M-c2c9a849cc69530195840a86bd90ef92
> From: <sip:alice at open-ims.test>;tag=6936
> To: <sip:tihoparvi at testing.com>;tag=rAKbk0j4rqvwEazX3tQSnK55hvsWpJv-
> CSeq: 401 INVITE
> Server: SylkServer-2.0.0
> Content-Length: 0
>
>
> --
>
> ==> core_trace.txt <==
> 2012-09-13 10:48:48.788149 [sylk-server 7379] (5) tsx0x7f79f404a: State changed from Proceeding to Completed, event=TX_MSG
> 2012-09-13 10:48:48.788192 [sylk-server 7379] (5) dlg0x7f79f402f: Transaction tsx0x7f79f404a868 state changed to Completed
> 2012-09-13 10:48:48.788235 [sylk-server 7379] (5) dlg0x7f79f402f: Session count dec to 2 by mod-invite
> 2012-09-13 10:48:48.788278 [sylk-server 7379] (5) sip_endpoint.c: Processing incoming message: Request msg ACK/cseq=401 (rdata0x7f79f4037908)
>
> ==> sip_trace.txt <==
> 2012-09-13 10:48:48.788323 [sylk-server 7379]: RECEIVED: Packet 66, +0:21:25.351274
> 10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.31:5070
> ACK sip:tihoparvi at testing.com SIP/2.0
> Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bKe05.0c2dbcd6.0
> From: <sip:alice at open-ims.test>;tag=6936
> Call-ID: M-c2c9a849cc69530195840a86bd90ef92
> To: <sip:tihoparvi at testing.com>;tag=rAKbk0j4rqvwEazX3tQSnK55hvsWpJv-
> CSeq: 401 ACK
> Route: <sip:orig at scscf.open-ims.test:6060;lr>
> User-Agent: Sip EXpress router(2.1.0-dev1 OpenIMSCore (x86_64/linux))
> Content-Length: 0
>
>
> --
>
> ==> core_trace.txt <==
> 2012-09-13 10:48:48.788366 [sylk-server 7379] (5) tsx0x7f79f404a: Incoming Request msg ACK/cseq=401 (rdata0x7f79f4037908) in state Completed
> 2012-09-13 10:48:48.788431 [sylk-server 7379] (5) tsx0x7f79f404a: State changed from Completed to Confirmed, event=RX_MSG
> 2012-09-13 10:48:48.788474 [sylk-server 7379] (5) dlg0x7f79f402f: Transaction tsx0x7f79f404a868 state changed to Confirmed
>
> ==> notifications_trace.txt <==
> 2012-09-13 10:48:48.793639 [sylk-server 7379]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x7f79f4029ed0>
> {'originator': 'local', 'prev_state': 'incoming', 'state': 'disconnecting'}
> 2012-09-13 10:48:48.794879 [sylk-server 7379]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x7f79f4029ed0>
> {'body': None,
> 'code': 488,
> 'disconnect_reason': 'Not Acceptable Here',
> 'headers': {'CSeq': (401, 'INVITE'),
> 'Call-ID': FrozenHeader('Call-ID', 'M-c2c9a849cc69530195840a86bd90ef92'),
> 'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '6936'})),
> 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('scscf.open-ims.test', 'mo', None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
> FrozenRecordRouteHeader(FrozenSIPURI('pcscf.open-ims.test', 'mo', None, 4060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({}))],
> 'Server': FrozenHeader('Server', 'SylkServer-2.0.0'),
> 'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': 'rAKbk0j4rqvwEazX3tQSnK55hvsWpJv-'})),
> 'Via': [FrozenViaHeader('UDP', '10.226.20.240', 6060, frozendict({'received': '10.226.20.240', 'branch': 'z9hG4bKe05.0c2dbcd6.0'})),
> FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bKe05.9eb39b34.0'})),
> FrozenViaHeader('UDP', '10.226.20.16', 1925, frozendict({'rport': 1925, 'branch': 'z9hG4bK1347547161148'}))]},
> 'originator': 'local',
> 'prev_state': 'disconnecting',
> 'reason': 'Not Acceptable Here',
> 'state': 'disconnected'}
>
> ==> core_trace.txt <==
> 2012-09-13 10:48:48.889289 [sylk-server 7379] (5) tsx0x7f79f404a: Timeout timer event
> 2012-09-13 10:48:48.889539 [sylk-server 7379] (5) tsx0x7f79f404a: State changed from Confirmed to Terminated, event=TIMER
> 2012-09-13 10:48:48.889767 [sylk-server 7379] (5) dlg0x7f79f402f: Transaction tsx0x7f79f404a868 state changed to Terminated
> 2012-09-13 10:48:48.889905 [sylk-server 7379] (5) dlg0x7f79f402f: Dialog destroyed
> 2012-09-13 10:48:48.890081 [sylk-server 7379] (5) tsx0x7f79f404a: Timeout timer event
> 2012-09-13 10:48:48.890221 [sylk-server 7379] (5) tsx0x7f79f404a: State changed from Terminated to Destroyed, event=TIMER
> 2012-09-13 10:48:48.890354 [sylk-server 7379] (5) tdta0x7f79f401: Destroying txdata Response msg 488/INVITE/cseq=401 (tdta0x7f79f4011cd0)
> 2012-09-13 10:48:48.890527 [sylk-server 7379] (5) tsx0x7f79f404a: Transaction destroyed!
> 2012-09-13 10:48:56.493729 [sylk-server 7379] (5) tsx0x7f79f4026: Timeout timer event
> 2012-09-13 10:48:56.496320 [sylk-server 7379] (5) tsx0x7f79f4026: State changed from Completed to Terminated, event=TIMER
> 2012-09-13 10:48:56.500773 [sylk-server 7379] (5) tsx0x7f79f4026: Timeout timer event
> 2012-09-13 10:48:56.502188 [sylk-server 7379] (5) tsx0x7f79f4026: State changed from Terminated to Destroyed, event=TIMER
> 2012-09-13 10:48:56.503975 [sylk-server 7379] (5) tdta0x7f79f402: Destroying txdata Response msg 500/MESSAGE/cseq=1 (tdta0x7f79f402de30)
> 2012-09-13 10:48:56.505637 [sylk-server 7379] (5) tsx0x7f79f4026: Transaction destroyed!
>
> As well as TCP DUMP attached. I’m having currently 2 machines with the Sylk, e.g. one on the old DEV version which perfectly works for both SIP and MSRP, and a single OpenIMS core. So the only difference now is that I’m using different application server IP address. The configuration of the working and non working version of Sylk is absolutely the same. Advises ?
>
> Thanks,
> Tiho
>
> This e-mail and any attachment is for authorised use by the intended recipient(s) only. It may contain proprietary material, confidential information and/or be subject to legal privilege. It should not be copied, disclosed to, retained or used by, any other party. If you are not an intended recipient then please promptly delete this e-mail and any attachment and all copies and inform the sender. Thank you for understanding.
>
> <sip-msrp-to-xmpp-chat4.cap>_______________________________________________
> SIPBeyondVoIP mailing list
> SIPBeyondVoIP at lists.ag-projects.com
> http://lists.ag-projects.com/mailman/listinfo/sipbeyondvoip
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ag-projects.com/pipermail/sipbeyondvoip/attachments/20120913/19ef44ec/attachment-0001.html>
More information about the SIPBeyondVoIP
mailing list