[SIP Beyond VoIP] Can't get sylkserver sending messages towards XMPP Server

Tihomir Hadzhiev thadgiev at yahoo.com
Wed Aug 22 12:16:53 CEST 2012


Hi All, 

I have finally covered the problem with the non running SylkServer with the XMPP module. Just had to go for a bit older Ubuntu version but still the one which already has the Python 2.7 supported fully. So far so good. I am somehow able to send now a message from:

tihoparvi at testing.com ( whcih is my XMPP domain ) -> to alice at open-ims.test ( my SIP/MSRP ) domain  ( using Boghe IMS/RCS client )

Problem 1:

in the above case, the pure SIP message works fine, at least the direction which is described above. However when I try to make a chat session, obviously something is being sent through the chain upto the IMS client, the window for the chat sessions pops up, but that's already all of it, no message really reaches the IMS client. 


Attached is excerpt from all the logs generated during the INVITE sessions, I have doubts that it has to do with with resolving hostnames:

2012-08-22 12:02:35.209000 [sylk-server 10194] (5)   tsx0x3254418: Incoming Response msg 180/INVITE/cseq=19265 (rdata0x280c3f8) in state Proceeding
2012-08-22 12:02:35.209000 [sylk-server 10194] (5)   tsx0x3254418: State changed from Proceeding to Proceeding, event=RX_MSG
2012-08-22 12:02:35.209000 [sylk-server 10194] (5)   dlg0x3234268: Received Response msg 180/INVITE/cseq=19265 (rdata0x280c3f8)
2012-08-22 12:02:35.209000 [sylk-server 10194] (5)   dlg0x3234268: Route-set updated
2012-08-22 12:02:35.209000 [sylk-server 10194] (5)   dlg0x3234268: Transaction tsx0x3254418 state changed to Proceeding
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)       endpoint: Request msg PRACK/cseq=19267 (tdta0x3255680) created.
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   dlg0x3234268: Sending Request msg PRACK/cseq=19267 (tdta0x3255680)
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   tsx0x3256738: Transaction created for Request msg PRACK/cseq=19266 (tdta0x3255680)
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   tsx0x3256738: Sending Request msg PRACK/cseq=19266 (tdta0x3255680) in state Null
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)  sip_resolve.c: Starting async DNS A query: target=scscf.open-ims.test, transport=Unspecified, port=6060
2012-08-22 12:02:35.210000 [sylk-server 10194] (4)  sip_resolve.c: Failed to resolve 'scscf.open-ims.test'. Err=320045 (No nameserver is in DNS resolver (PJLIB_UTIL_EDNSNONS))
2012-08-22 12:02:35.210000 [sylk-server 10194] (2)   tsx0x3256738: Failed to send Request msg PRACK/cseq=19266 (tdta0x3255680)! err=320045 (No nameserver is in DNS resolver (PJLIB_UTIL_EDNSNONS))
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   tsx0x3256738: State changed from Null to Terminated, event=TRANSPORT_ERROR
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   dlg0x3234268: Transaction tsx0x3256738 state changed to Terminated
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   dlg0x3234268: Session count dec to 3 by mod-invite
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)       endpoint: Request msg BYE/cseq=19268 (tdta0x3257e50) created.
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   inv0x3234268: Sending Request msg BYE/cseq=19268 (tdta0x3257e50)
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   dlg0x3234268: Sending Request msg BYE/cseq=19268 (tdta0x3257e50)
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   tsx0x3258f08: Transaction created for Request msg BYE/cseq=19267 (tdta0x3257e50)
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   tsx0x3258f08: Sending Request msg BYE/cseq=19267 (tdta0x3257e50) in state Null
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)  sip_resolve.c: Starting async DNS A query: target=scscf.open-ims.test, transport=Unspecified, port=6060
2012-08-22 12:02:35.210000 [sylk-server 10194] (4)  sip_resolve.c: Failed to resolve 'scscf.open-ims.test'. Err=320045 (No nameserver is in DNS resolver (PJLIB_UTIL_EDNSNONS))
2012-08-22 12:02:35.210000 [sylk-server 10194] (2)   tsx0x3258f08: Failed to send Request msg BYE/cseq=19267 (tdta0x3257e50)! err=320045 (No nameserver is in DNS resolver (PJLIB_UTIL_EDNSNONS))
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   tsx0x3258f08: State changed from Null to Terminated, event=TRANSPORT_ERROR
2012-08-22 12:02:35.210000 [sylk-server 10194] (5)   dlg0x3234268: Transaction tsx0x3258f08 state changed to Terminated

but from the other side if I issue the following command on the machine where the sylkserver is running:

root at tichomir-VirtualBox:/var/log/sylkserver# nslookup scscf.open-ims.test
Server:         10.226.20.240
Address:        10.226.20.240#53

Name:   scscf.open-ims.test
Address: 10.226.20.240

So this was problem one, please help if that's possible ?

Problem 2: 

The other direction of course there is a problem as well, e.g. SIP/MSRP -> XMPP domain. The below logs excerpt is when I try to send a normal SIP message ( SMS ) through the IMS/RCS client, obviously the INVITE reaches the SylkServer, however then SylkServer replies with Method Not Allowed. 

Same problem of course will appear if I try to initiate Chat session, e.g. MSRP based

What can be the problem here ?

Also, how the SylkServer is supposed to transfer the message towards the XMPP domain. That's not really clear from the documentation. Is it the case that it should contact the S2S XMPP server port, e.g. 5269, or there is a different mechanism ?


==> core_trace.txt <==
2012-08-22 11:47:10.328000 [sylk-server 10194] (5) sip_endpoint.c: Processing incoming message: Request msg MESSAGE/cseq=3790 (rdata0x280c3f8)

==> sip_trace.txt <==
2012-08-22 11:47:10.328327 [sylk-server 10194]: RECEIVED: Packet 14, +0:10:06.724297
10.226.20.240:6060 -(SIP over UDP)-> 192.168.56.101:5070
MESSAGE sip:tihoparvi at testing.com SIP/2.0
Route: <sip:192.168.56.101:5070;lr>, <sip:iscmark at scscf.open-ims.test:6060;lr;s=1;h=0;d=0;a=7369703a616c696365406f70656e2d696d732e74657374>
Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bKe949.b80cf816.0
Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bKe949.e81c7601.0
Via: SIP/2.0/UDP 10.226.20.23:1708;branch=z9hG4bK441290514;rport=1708
From: <sip:alice at open-ims.test>;tag=441296205
To: <sip:tihoparvi at testing.com>
Call-ID: b48cb0a9-0152-898e-aeda-4229fb8f3e03
CSeq: 3790 MESSAGE
Content-Length: 12
Max-Forwards: 15
Accept-Contact: *;+g.oma.sip-im
Accept-Contact: *;language="en,fr"
Content-Type: text/plain
Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER
Privacy: none
P-Access-Network-Info: ADSL;utran-cell-id-3gpp=00000000
User-Agent: IM-client/OMA1.0 Boghe/v2.0.104.715
P-Asserted-Identity: <sip:alice at open-ims.test>
P-Charging-Vector: icid-value="P-CSCFabcd000000005034aa9f00000022";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"

SIP  MESSAGE
--

==> core_trace.txt <==
2012-08-22 11:47:10.328000 [sylk-server 10194] (5)       endpoint: Response msg 500/MESSAGE/cseq=3790 (tdta0x3268a80) created
2012-08-22 11:47:10.328000 [sylk-server 10194] (5)   tsx0x32675d8: Transaction created for Request msg MESSAGE/cseq=3790 (rdata0x280c3f8)
2012-08-22 11:47:10.328000 [sylk-server 10194] (5)   tsx0x32675d8: Incoming Request msg MESSAGE/cseq=3790 (rdata0x280c3f8) in state Null
2012-08-22 11:47:10.328000 [sylk-server 10194] (5)   tsx0x32675d8: State changed from Null to Trying, event=RX_MSG

==> notifications_trace.txt <==
2012-08-22 11:47:10.358133 [sylk-server 10194]: Notification name=SIPIncomingRequestGotRequest sender=<sipsimple.core._core.IncomingRequest object at 0x3140d08>
{'body': 'SIP  MESSAGE',
 'headers': {'Accept-Contact': FrozenHeader('Accept-Contact', '*;+g.oma.sip-im'),
             'Allow': ['INVITE',
                       'ACK',
                       'CANCEL',
                       'BYE',
                       'MESSAGE',
                       'OPTIONS',
                       'NOTIFY',
                       'PRACK',
                       'UPDATE',
                       'REFER'],
             'CSeq': (3790, 'MESSAGE'),
             'Call-ID': FrozenHeader('Call-ID', 'b48cb0a9-0152-898e-aeda-4229fb8f3e03'),
             'Content-Length': 12,
             'Content-Type': ('text/plain', ''),
             'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '441296205'})),
             '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-CSCFabcd000000005034aa9f00000022";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"'),
             'Privacy': FrozenHeader('Privacy', 'none'),
             'Route': [FrozenRouteHeader(FrozenSIPURI('192.168.56.101', None, None, 5070, False, frozendict({'lr': 1}), frozendict({})), None, frozendict({})),
                       FrozenRouteHeader(FrozenSIPURI('scscf.open-ims.test', 'iscmark', None, 6060, False, frozendict({'a': '7369703a616c696365406f70656e2d696d732e74657374', 'h': '0', 's': '1', 'lr': 1, 'd': '0'}), frozendict({})), None, frozendict({}))],
             'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({})),
             'User-Agent': FrozenHeader('User-Agent', 'IM-client/OMA1.0 Boghe/v2.0.104.715'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.240', 6060, frozendict({'received': '10.226.20.240', 'branch': 'z9hG4bKe949.b80cf816.0'})),
                     FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bKe949.e81c7601.0'})),
                     FrozenViaHeader('UDP', '10.226.20.23', 1708, frozendict({'rport': 1708, 'branch': 'z9hG4bK441290514'}))]},
 'method': 'MESSAGE',
 'request_uri': FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})),
 'timestamp': datetime.datetime(2012, 8, 22, 11, 47, 10, 328575)}

==> core_trace.txt <==
2012-08-22 11:47:10.347000 [sylk-server 10194] (5)   tsx0x32675d8: Sending Response msg 500/MESSAGE/cseq=3790 (tdta0x3268a80) in state Trying
2012-08-22 11:47:10.347000 [sylk-server 10194] (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-08-22 11:47:10.348178 [sylk-server 10194]: SENDING: Packet 15, +0:10:06.744148
192.168.56.101:5070 -(SIP over UDP)-> 10.226.20.240:6060
SIP/2.0 405 Method Not Allowed
Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bKe949.b80cf816.0
Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bKe949.e81c7601.0
Via: SIP/2.0/UDP 10.226.20.23:1708;rport=1708;branch=z9hG4bK441290514
Call-ID: b48cb0a9-0152-898e-aeda-4229fb8f3e03
From: <sip:alice at open-ims.test>;tag=441296205
To: <sip:tihoparvi at testing.com>
CSeq: 3790 MESSAGE
Server: SylkServer-2.0.0-dev
Content-Length:  0


--

==> core_trace.txt <==
2012-08-22 11:47:10.348000 [sylk-server 10194] (5)   tsx0x32675d8: State changed from Trying to Completed, event=TX_MSG

==> notifications_trace.txt <==
2012-08-22 11:47:10.446312 [sylk-server 10194]: Notification name=SIPIncomingRequestSentResponse sender=<sipsimple.core._core.IncomingRequest object at 0x3140d08>
{'body': None,
 'code': 405,
 'headers': {'CSeq': (3790, 'MESSAGE'),
             'Call-ID': FrozenHeader('Call-ID', 'b48cb0a9-0152-898e-aeda-4229fb8f3e03'),
             'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '441296205'})),
             'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({})),
             'Via': [FrozenViaHeader('UDP', '10.226.20.240', 6060, frozendict({'received': '10.226.20.240', 'branch': 'z9hG4bKe949.b80cf816.0'})),
                     FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bKe949.e81c7601.0'})),
                     FrozenViaHeader('UDP', '10.226.20.23', 1708, frozendict({'rport': 1708, 'branch': 'z9hG4bK441290514'}))]},
 'reason': 'Method Not Allowed',
 'timestamp': datetime.datetime(2012, 8, 22, 11, 47, 10, 348599)}

Thanks a lot and appreciated, 

Regards, 
Tihomir

________________________________
 From: Adrian Georgescu <ag at ag-projects.com>
To: Tihomir Hadzhiev <thadgiev at yahoo.com> 
Cc: "sipbeyondvoip at lists.ag-projects.com" <sipbeyondvoip at lists.ag-projects.com> 
Sent: Tuesday, July 31, 2012 9:48 PM
Subject: Re: [SIP Beyond VoIP] Can't get sylkserver sending messages towards XMPP Server
 

Hi Tihomir,

When installing SylkServer from development branch you must install manually the required dependencies:

 * python-sipsimple (>= 0.20.0) http://sipsimpleclient.com
 * python-sqlobject (>= 0.12.4)
 * python-twisted-words
 * python-wokkel

Regards,
Adrian


On Jul 31, 2012, at 5:35 PM, Tihomir Hadzhiev wrote:

Hi All, 
>
>
>I have a problem with the latest SylkServer 2.0.x-dev where I can't get SIP messages, neither MSRP worked through the SylkServer towards XMPP server. I was trying to find some good documentation on that, but so far nothing. The default configuration files are fairly simple and I believe I had everything configured properly there. What I have currently is a whole working OpenIMS environment where SIP/MSRP messaging works OK. Then I have configured the OpenIMS ENV to route the messages towards the SylkServer which happens btw. However what I see is that the SylkServer tries to route the messages back to the OpenIMS, e.g. does a loop. 
>
>
>Please do advise what exactly might be wrong with the configuration. And exactly need to be configured on the SylkServer to have the triggering and traslation done towards the XMPP server. 
>
>
>I'm using the following command to start SylkServer:
>
>
>/usr/local/bin$ ./sylk-server /etc/sylkserver/config.ini --no-fork
>
>
>
>what I also noticed is that the sylkserver actually is not opening the xmpp logging file:
>
>
>Starting SylkServer 2.0.0-dev, config=/etc/sylkserver/config.ini
>Logging SIP trace to file "/var/log/sylkserver/sip_trace.txt"
>Logging MSRP trace to file "/var/log/sylkserver/msrp_trace.txt"
>Logging PJSIP trace to file "/var/log/sylkserver/core_trace.txt"
>Logging notifications trace to file "/var/log/sylkserver/notifications_trace.txt"
>
>
>as well  I see number of exceptions during the SylkServer startup:
>
>
>error: Exception occured in observer <sylk.server.SylkServer object at 0x32e0d90> while handling notification 'SIPApplicationDidStart'
>Traceback (most recent call last):
>  File "/usr/lib/pymodules/python2.6/application/notification.py", line 216, in post_notification
>    observer.handle_notification(notification)
>  File "<string>", line 1, in handle_notification
>  File "/usr/lib/pymodules/python2.6/sipsimple/threading/__init__.py", line 102, in wrapper
>    func(*args, **kwargs)
>  File "/usr/lib/pymodules/python2.6/sipsimple/application.py", line 335, in handle_notification
>    handler(notification)
>  File "/usr/local/lib/python2.6/dist-packages/sylk/server.py", line 224, in _NH_SIPApplicationDidStart
>    self.request_handler = IncomingRequestHandler()
>  File "/usr/lib/pymodules/python2.6/application/python/types.py", line 37, in __call__
>    return cls.__instantiate__(*args, **kw)
>  File "<string>", line 1, in __init__
>  File "/usr/lib/pymodules/python2.6/application/python/types.py", line 31, in instance_creator
>    cls.__instances__[key] = super(Singleton, cls).__call__(*args, **kw)
>  File "/usr/local/lib/python2.6/dist-packages/sylk/applications/__init__.py", line 92, in __init__
>    load_applications()
>  File "/usr/local/lib/python2.6/dist-packages/sylk/applications/__init__.py", line 77, in load_applications
>    map(__import__, app_list)
>  File "/usr/local/lib/python2.6/dist-packages/sylk/applications/xmppgateway/__init__.py", line 18, in <module>
>    from sylk.applications.xmppgateway.im import SIPMessageSender, SIPMessageError, ChatSessionHandler
>  File "/usr/local/lib/python2.6/dist-packages/sylk/applications/xmppgateway/im.py", line 27, in <module>
>    from sylk.applications.xmppgateway.xmpp import XMPPManager
>  File "/usr/local/lib/python2.6/dist-packages/sylk/applications/xmppgateway/xmpp/__init__.py", line 13, in <module>
>    from wokkel.component import InternalComponent, Router as _Router
>ImportError: No module named wokkel.component
>
>
>
>
>thanks, 
>
>
>Tiho_______________________________________________
>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/20120822/079fd07d/attachment-0001.html>
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: log-XMPP-MSRP.txt
URL: <http://lists.ag-projects.com/pipermail/sipbeyondvoip/attachments/20120822/079fd07d/attachment-0001.txt>


More information about the SIPBeyondVoIP mailing list