[SIP Beyond VoIP] MSRP sessions cannot be established by uknown reason

Hadzhiev, Tihomir tihomir.hadzhiev at acision.com
Thu Sep 13 17:52:17 CEST 2012


Is there a way to avoid tls usage, that is not that user feillriendly at this moment :)

Sent from my HTC

----- Reply message -----
From: "Adrian Georgescu" <ag at ag-projects.com>
To: "Hadzhiev, Tihomir" <tihomir.hadzhiev at acision.com>
Cc: "sipbeyondvoip at lists.ag-projects.com" <sipbeyondvoip at lists.ag-projects.com>
Subject: [SIP Beyond VoIP] MSRP sessions cannot be established by uknown reason
Date: Thu, Sep 13, 2012 16:56



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<mailto:SIPBeyondVoIP at lists.ag-projects.com>
http://lists.ag-projects.com/mailman/listinfo/sipbeyondvoip


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

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ag-projects.com/pipermail/sipbeyondvoip/attachments/20120913/3a44554e/attachment-0001.html>


More information about the SIPBeyondVoIP mailing list