[SIP Beyond VoIP] Another case where Sylk would reject Notifications

Hadzhiev, Tihomir tihomir.hadzhiev at acision.com
Fri Nov 16 16:24:10 CET 2012


Hi,


1.       Again XMPP GUY logs in:

==> xmpp_trace.txt <==
2012-11-16T15:42:13.530226+01:00 [sylk-server 31059]: RECEIVED: Packet 1, +0:00:00
<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' from='testing.com' to='open-ims.test'>
--
2012-11-16T15:42:13.535403+01:00 [sylk-server 31059]: SENDING: Packet 2, +0:00:00.005177
<stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' from='open-ims.test' id='8e1873fe166b3f8e'>
--
2012-11-16T15:42:13.537253+01:00 [sylk-server 31059]: RECEIVED: Packet 3, +0:00:00.007027
<db:result from='testing.com' to='open-ims.test'>1513696473</db:result>
--
2012-11-16T15:42:13.556797+01:00 [sylk-server 31059]: SENDING: Packet 4, +0:00:00.026571
<stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' to='testing.com' version='1.0' from='open-ims.test'>
--
2012-11-16T15:42:13.558286+01:00 [sylk-server 31059]: RECEIVED: Packet 5, +0:00:00.028060
<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' id='4097169877'>
--
2012-11-16T15:42:13.559622+01:00 [sylk-server 31059]: SENDING: Packet 6, +0:00:00.029396
<db:verify to='testing.com' from='open-ims.test' id='8e1873fe166b3f8e'>1513696473</db:verify>
--
2012-11-16T15:42:13.560754+01:00 [sylk-server 31059]: RECEIVED: Packet 7, +0:00:00.030528
<db:verify from='testing.com' to='open-ims.test' id='8e1873fe166b3f8e' type='valid'/>
--
2012-11-16T15:42:13.561856+01:00 [sylk-server 31059]: SENDING: Packet 8, +0:00:00.031630
<db:result to='testing.com' from='open-ims.test' type='valid'/>
--
2012-11-16T15:42:13.564228+01:00 [sylk-server 31059]: RECEIVED: Packet 9, +0:00:00.034002
<presence from='tihoparvi at testing.com/CZ-R8LGKEG' to='alice at open-ims.test' type='probe'/>
--

==> notifications_trace.txt <==
2012-11-16 15:42:13.568205 [sylk-server 31059]: Notification name=XMPPGotPresenceProbe sender=<wokkel.component.InternalComponent object at 0x7f81a0ab6310>
{'presence_stanza': <sylk.applications.xmppgateway.xmpp.stanzas.ProbePresence object at 0x7f81a0b52f50>}
2012-11-16 15:42:13.569662 [sylk-server 31059]: Notification name=XMPPGotPresenceSubscriptionRequest sender=<sylk.applications.xmppgateway.xmpp.XMPPManager object at 0x7f81a0aac490>
{'stanza': <sylk.applications.xmppgateway.xmpp.stanzas.ProbePresence object at 0x7f81a0b52f50>}
2012-11-16 15:42:13.570073 [sylk-server 31059]: Notification name=XMPPIncomingSubscriptionDidStart sender=<sylk.applications.xmppgateway.xmpp.subscription.XMPPIncomingSubscription object at 0x7f81a0b5b2d0>
{}
2012-11-16 15:42:13.571027 [sylk-server 31059]: Notification name=X2SPresenceHandlerDidStart sender=<sylk.applications.xmppgateway.presence.X2SPresenceHandler object at 0x7f81a0b5b090>
{}
2012-11-16 15:42:13.573382 [sylk-server 31059]: Notification name=DNSResolverDidInitialize sender=<sipsimple.lookup.DNSManager object at 0x7f81a0b52e10>
{'nameservers': ['127.0.0.1']}

==> sip_trace.txt <==
2012-11-16 15:42:13.578833 [sylk-server 31059]: DNS lookup NAPTR open-ims.test succeeded, ttl=86400: 20 50 "s" "SIP+D2T" "" _sip._tcp.open-ims.test., 10 50 "s" "SIP+D2U" "" _sip._udp.open-ims.test.

==> notifications_trace.txt <==
2012-11-16 15:42:13.579990 [sylk-server 31059]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x7f81a0b527d0>
{'answer': <dns.resolver.Answer object at 0x7f81a0b52c50>,
'context': 'lookup_sip_proxy',
'error': None,
'nameservers': ['127.0.0.1'],
'query_name': 'open-ims.test',
'query_type': 'NAPTR',
'uri': SIPURI('open-ims.test', None, None, None, False, {}, {})}
2012-11-16 15:42:13.580942 [sylk-server 31059]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x7f81a0b527d0>
{'result': [Route('10.226.20.240', 5060, 'udp'),
            Route('10.226.20.240', 5060, 'tcp')]}

==> xmpp_trace.txt <==
2012-11-16T15:42:13.601294+01:00 [sylk-server 31059]: RECEIVED: Packet 10, +0:00:00.071068
<presence from='tihoparvi at testing.com/CZ-R8LGKEG' to='alice at open-ims.test' xml:lang='en'>
<priority>5</priority>
<c xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps' ver='caps-b75d8d2b25' ext='ca cs ep-notify-2 html'/>
</presence>
--

==> notifications_trace.txt <==
2012-11-16 15:42:13.604610 [sylk-server 31059]: Notification name=XMPPGotPresenceAvailability sender=<wokkel.component.InternalComponent object at 0x7f81a0ab6310>
{'presence_stanza': <sylk.applications.xmppgateway.xmpp.stanzas.AvailabilityPresence object at 0x7f81a0b65250>}

==> sip_trace.txt <==
2012-11-16 15:42:13.642982 [sylk-server 31059]: SENDING: Packet 1, +0:00:00
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:5060
SUBSCRIBE sip:alice at open-ims.test SIP/2.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport;branch=z9hG4bKPjjk0WPviI5XdtE.TxLFX75PmpGbYf9GXE
Max-Forwards: 70
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>
Contact: <sip:jctplkgd at 10.226.20.56:6060>
Call-ID: m7PQto36WRuZNqaBP4rTIFtofi3pSXPo
CSeq: 26351 SUBSCRIBE
Event: presence
Expires: 3600
Accept: application/pidf+xml
Allow-Events: conference, refer, presence
User-Agent: SylkServer-2.2.1
Content-Length:  0


--

==> notifications_trace.txt <==
2012-11-16 15:42:13.644537 [sylk-server 31059]: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x7f81a0bd59e0>
{'prev_state': 'NULL', 'state': 'SENT'}
2012-11-16 15:42:13.644813 [sylk-server 31059]: Notification name=SIPSubscriptionWillStart sender=<sipsimple.core._core.Subscription object at 0x7f81a0bd59e0>
{}

==> sip_trace.txt <==
2012-11-16 15:42:13.662226 [sylk-server 31059]: RECEIVED: Packet 2, +0:00:00.019244
10.226.20.240:5060 -(SIP over UDP)-> 10.226.20.56:6060
SIP/2.0 202 OK
Record-Route: <sip:mt at 10.226.20.240:6060;lr>
Via: SIP/2.0/UDP 10.226.20.56:6060;rport=6060;branch=z9hG4bKPjjk0WPviI5XdtE.TxLFX75PmpGbYf9GXE
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>;tag=48b5b8952e8d0bca6256941910840e90-6daa
Call-ID: m7PQto36WRuZNqaBP4rTIFtofi3pSXPo
CSeq: 26351 SUBSCRIBE
Expires: 3600
Contact: <sip:10.226.20.56:5080;transport=udp>
Server: kamailio (3.3.2 (x86_64/linux))
Content-Length: 0


--

==> notifications_trace.txt <==
2012-11-16 15:42:13.666927 [sylk-server 31059]: Notification name=SIPSubscriptionDidStart sender=<sipsimple.core._core.Subscription object at 0x7f81a0bd59e0>
{}
2012-11-16 15:42:13.667735 [sylk-server 31059]: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x7f81a0bd59e0>
{'prev_state': 'SENT', 'state': 'ACCEPTED'}

==> sip_trace.txt <==
2012-11-16 15:42:13.668144 [sylk-server 31059]: RECEIVED: Packet 3, +0:00:00.025162
10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.56:6060
NOTIFY sip:jctplkgd at 10.226.20.56:6060 SIP/2.0
Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK8492.758999a1.0
Via: SIP/2.0/UDP 10.226.20.56:5080;branch=z9hG4bK8492.a1be02f7.0
To: sip:tihoparvi at testing.com;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
From: sip:alice at open-ims.test;tag=48b5b8952e8d0bca6256941910840e90-6daa
CSeq: 2 NOTIFY
Call-ID: m7PQto36WRuZNqaBP4rTIFtofi3pSXPo
Content-Length: 0
User-Agent: kamailio (3.3.2 (x86_64/linux))
Max-Forwards: 16
Event: presence
Contact: <sip:10.226.20.56:5080;transport=udp>
Subscription-State: active;expires=3600


--

==> notifications_trace.txt <==
2012-11-16 15:42:13.672282 [sylk-server 31059]: Notification name=XMPPIncomingSubscriptionChangedState sender=<sylk.applications.xmppgateway.xmpp.subscription.XMPPIncomingSubscription object at 0x7f81a0b5b2d0>
{'prev_state': None, 'state': 'active'}
2012-11-16 15:42:13.679013 [sylk-server 31059]: Notification name=SIPSubscriptionGotNotify sender=<sipsimple.core._core.Subscription object at 0x7f81a0bd59e0>
{'body': None,
'content_type': None,
'event': 'presence',
'from_header': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '48b5b8952e8d0bca6256941910840e90-6daa'})),
'headers': {'CSeq': (2, 'NOTIFY'),
             'Call-ID': FrozenHeader('Call-ID', 'm7PQto36WRuZNqaBP4rTIFtofi3pSXPo'),
             'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.56', None, None, 5080, False, frozendict({'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0'}))],
             'Content-Length': 0,
             'Event': FrozenEventHeader('presence', frozendict({})),
             'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '48b5b8952e8d0bca6256941910840e90-6daa'})),
             'Max-Forwards': 16,
             'Subscription-State': FrozenSubscriptionStateHeader('active', frozendict({'expires': '3600'})),
             'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'User-Agent': FrozenHeader('User-Agent', 'kamailio (3.3.2 (x86_64/linux))'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.240', 6060, frozendict({'received': '10.226.20.240', 'branch': 'z9hG4bK8492.758999a1.0'})),
                     FrozenViaHeader('UDP', '10.226.20.56', 5080, frozendict({'branch': 'z9hG4bK8492.a1be02f7.0'}))]},
'request_uri': FrozenSIPURI('10.226.20.56', 'jctplkgd', None, 6060, False, frozendict({}), frozendict({})),
'to_header': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'}))}

==> sip_trace.txt <==
2012-11-16 15:42:13.680295 [sylk-server 31059]: SENDING: Packet 4, +0:00:00.037313
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:6060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bK8492.758999a1.0
Via: SIP/2.0/UDP 10.226.20.56:5080;branch=z9hG4bK8492.a1be02f7.0
Call-ID: m7PQto36WRuZNqaBP4rTIFtofi3pSXPo
From: <sip:alice at open-ims.test>;tag=48b5b8952e8d0bca6256941910840e90-6daa
To: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
CSeq: 2 NOTIFY
Contact: <sip:jctplkgd at 10.226.20.56:6060>
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Supported: 100rel, replaces, norefersub, gruu
Server: SylkServer-2.2.1
Content-Length:  0


--

==> notifications_trace.txt <==
2012-11-16 15:42:13.682690 [sylk-server 31059]: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x7f81a0bd59e0>
{'prev_state': 'ACCEPTED', 'state': 'ACTIVE'}

==> xmpp_trace.txt <==
2012-11-16T15:42:13.685778+01:00 [sylk-server 31059]: SENDING: Packet 11, +0:00:00.155552
<stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' to='testing.com' version='1.0' from='open-ims.test'>
--
2012-11-16T15:42:13.687606+01:00 [sylk-server 31059]: RECEIVED: Packet 12, +0:00:00.157380
<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' id='769234699'>
--
2012-11-16T15:42:13.689429+01:00 [sylk-server 31059]: SENDING: Packet 13, +0:00:00.159203
<db:result to='testing.com' from='open-ims.test'>1b6e7d926a24830d871800e660100c6214ef5ea5ebdaaa12717a83757ffd22ea</db:result>
--
2012-11-16T15:42:13.695047+01:00 [sylk-server 31059]: RECEIVED: Packet 14, +0:00:00.164821
<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' from='testing.com' to='open-ims.test'>
--
2012-11-16T15:42:13.695881+01:00 [sylk-server 31059]: SENDING: Packet 15, +0:00:00.165655
<stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:server' xmlns:db='jabber:server:dialback' from='open-ims.test' id='7e81ecbc30bd7d91'>
--
2012-11-16T15:42:13.697477+01:00 [sylk-server 31059]: RECEIVED: Packet 16, +0:00:00.167251
<db:verify from='testing.com' to='open-ims.test' id='769234699'>1b6e7d926a24830d871800e660100c6214ef5ea5ebdaaa12717a83757ffd22ea</db:verify>
--
2012-11-16T15:42:13.698740+01:00 [sylk-server 31059]: SENDING: Packet 17, +0:00:00.168514
<db:verify to='testing.com' from='open-ims.test' id='769234699' type='valid'/>
--
2012-11-16T15:42:13.700122+01:00 [sylk-server 31059]: RECEIVED: Packet 18, +0:00:00.169896
<db:result from='testing.com' to='open-ims.test' type='valid'/>
--
2012-11-16T15:42:13.700968+01:00 [sylk-server 31059]: SENDING: Packet 19, +0:00:00.170742
<presence to='tihoparvi at testing.com' from='alice at open-ims.test' type='subscribed'/>









2.       IMS guy logs in:

==> sip_trace.txt <==
2012-11-16 15:44:15.293888 [sylk-server 31059]: RECEIVED: Packet 5, +0:02:01.650906
10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.56:6060
SUBSCRIBE sip:tihoparvi at testing.com SIP/2.0
Record-Route: <sip:mo at 10.226.20.240:6060;lr>
Route: <sip:10.226.20.56:6060;lr>, <sip:iscmark at scscf.open-ims.test:6060;lr;s=3;h=0;d=0;a=7369703a616c696365406f70656e2d696d732e74657374>
Record-Route: <sip:mo at 10.226.20.240:4060;lr>
Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bKa836.e63424b3.0
Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bKa836.8bc6a685.0
Via: SIP/2.0/UDP 10.226.20.14:55305;rport=55305;branch=z9hG4bK1353054401714
From: <sip:alice at open-ims.test>;tag=31001
To: <sip:tihoparvi at testing.com>
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
CSeq: 701 SUBSCRIBE
Max-Forwards: 15
Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER
Contact: <sip:alice at 10.226.20.14:55305;transport=udp>;+g.oma.sip-im
User-Agent: IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0
Expires: 600000
Event: presence
Supported: eventlist
Accept: multipart/related, application/rlmi+xml, application/pidf+xml, application/rpid+xml, application/xcap-diff+xml, message/external-body
Accept-Contact: *;+g.oma.sip-im
P-Access-Network-Info: ADSL;utran-cell-id-3gpp=00000000
Privacy: none
Supported: timer
Allow-Events: refer, presence, presence.winfo, xcap-diff, conference
Content-Length: 0
P-Asserted-Identity: <sip:alice at open-ims.test>
P-Charging-Vector: icid-value="P-CSCFabcd0000000050a659810000003c";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.312271 [sylk-server 31059]: Notification name=XMPPSubscriptionDidStart sender=<sylk.applications.xmppgateway.xmpp.subscription.XMPPSubscription object at 0x7f81a0b6e350>
{}
2012-11-16 15:44:15.312926 [sylk-server 31059]: Notification name=XMPPSubscriptionChangedState sender=<sylk.applications.xmppgateway.xmpp.subscription.XMPPSubscription object at 0x7f81a0b6e350>
{'prev_state': None, 'state': 'subscribe_sent'}

==> xmpp_trace.txt <==
2012-11-16T15:44:15.309284+01:00 [sylk-server 31059]: SENDING: Packet 20, +0:02:01.779058
<presence to='tihoparvi at testing.com' from='alice at open-ims.test' type='subscribe'/>
--
2012-11-16T15:44:15.310452+01:00 [sylk-server 31059]: SENDING: Packet 21, +0:02:01.780226
<presence to='tihoparvi at testing.com' from='alice at open-ims.test' type='probe'/>
--

==> notifications_trace.txt <==
2012-11-16 15:44:15.320184 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionGotSubscribe sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': None,
'headers': {'Accept': ['multipart/related',
                        'application/rlmi+xml',
                        'application/pidf+xml',
                        'application/rpid+xml',
                        'application/xcap-diff+xml',
                        'message/external-body'],
             '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': (701, 'SUBSCRIBE'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.14', 'alice', None, 55305, False, frozendict({'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0', '+g.oma.sip-im': None}))],
             'Content-Length': 0,
             'Event': FrozenEventHeader('presence', frozendict({})),
             'Expires': 600000,
             'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             '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-CSCFabcd0000000050a659810000003c";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"'),
             'Privacy': FrozenHeader('Privacy', 'none'),
             'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
                              FrozenRecordRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 4060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({}))],
             'Route': [FrozenRouteHeader(FrozenSIPURI('10.226.20.56', None, None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
                       FrozenRouteHeader(FrozenSIPURI('scscf.open-ims.test', 'iscmark', None, 6060, False, frozendict({'a': '7369703a616c696365406f70656e2d696d732e74657374', 'h': '0', 's': '3', 'lr': None, 'd': '0'}), frozendict({})), None, frozendict({}))],
             'Supported': ['eventlist'],
             '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': 'z9hG4bKa836.e63424b3.0'})),
                     FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bKa836.8bc6a685.0'})),
                     FrozenViaHeader('UDP', '10.226.20.14', 55305, frozendict({'rport': 55305, 'branch': 'z9hG4bK1353054401714'}))]},
'method': 'SUBSCRIBE',
'request_uri': FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({}))}

==> sip_trace.txt <==
2012-11-16 15:44:15.321518 [sylk-server 31059]: RECEIVED: Packet 6, +0:02:01.678536
10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.56:6060
NOTIFY sip:jctplkgd at 10.226.20.56:6060 SIP/2.0
Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK9492.69c10d12.0
Via: SIP/2.0/UDP 10.226.20.56:5080;branch=z9hG4bK9492.091a96c1.0
To: sip:tihoparvi at testing.com;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
From: sip:alice at open-ims.test;tag=48b5b8952e8d0bca6256941910840e90-6daa
CSeq: 3 NOTIFY
Call-ID: m7PQto36WRuZNqaBP4rTIFtofi3pSXPo
Content-Length: 1210
User-Agent: kamailio (3.3.2 (x86_64/linux))
Max-Forwards: 16
Event: presence
Contact: <sip:10.226.20.56:5080;transport=udp>
Subscription-State: active;expires=3478
Content-Type: application/pidf+xml

<?xml version="1.0" encoding="utf-8"?>
<presence xmlns:cp="urn:ietf:params:xml:ns:pidf:cipid" xmlns:caps="urn:ietf:params:xml:ns:pidf:caps" xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid" xmlns:pdm="urn:ietf:params:xml:ns:pidf:data-model" xmlns:p="urn:ietf:params:xml:ns:pidf-diff" xmlns:op="urn:oma:xml:prs:pidf:oma-pres" xmlns="urn:ietf:params:xml:ns:pidf" entity="sip:alice at open-ims.test">
  <pdm:person id="JXEEVCMM">
    <op:overriding-willingness>
      <op:basic>open</op:basic>
    </op:overriding-willingness>
    <rpid:activities>
      <rpid:unknown/>
    </rpid:activities>
    <rpid:mood>
      <rpid:neutral/>
    </rpid:mood>
    <cp:homepage>http://dir.bg</cp:homepage>
    <pdm:note>TEST TEXT</pdm:note>
  </pdm:person>
  <pdm:device id="d0001">
    <status>
      <basic>open</basic>
    </status>
    <caps:devcaps>
      <caps:mobility>
        <caps:supported>
          <caps:fixed/>
        </caps:supported>
      </caps:mobility>
    </caps:devcaps>
    <op:network-availability>
      <op:network id="IMS">
        <op:active/>
      </op:network>
    </op:network-availability>
    <pdm:deviceID>urn:uuid:3ca50bcb-7a67-44f1-afd0-994a55f930f4</pdm:deviceID>
  </pdm:device>
</presence>

--
2012-11-16 15:44:15.321776 [sylk-server 31059]: SENDING: Packet 7, +0:02:01.678794
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:6060
SIP/2.0 481 Call/Transaction Does Not Exist
Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bK9492.69c10d12.0
Via: SIP/2.0/UDP 10.226.20.56:5080;branch=z9hG4bK9492.091a96c1.0
Call-ID: m7PQto36WRuZNqaBP4rTIFtofi3pSXPo
From: <sip:alice at open-ims.test>;tag=48b5b8952e8d0bca6256941910840e90-6daa
To: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
CSeq: 3 NOTIFY
Server: SylkServer-2.2.1
Content-Length:  0


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.327180 [sylk-server 31059]: Notification name=S2XPresenceHandlerDidStart sender=<sylk.applications.xmppgateway.presence.S2XPresenceHandler object at 0x7f81a0b6e310>
{}

==> xmpp_trace.txt <==
2012-11-16T15:44:15.329338+01:00 [sylk-server 31059]: RECEIVED: Packet 22, +0:02:01.799112
<presence from='tihoparvi at testing.com' to='alice at open-ims.test' type='subscribed'/>
--

==> notifications_trace.txt <==
2012-11-16 15:44:15.333220 [sylk-server 31059]: Notification name=XMPPGotPresenceSubscriptionStatus sender=<wokkel.component.InternalComponent object at 0x7f81a0ab6310>
{'presence_stanza': <sylk.applications.xmppgateway.xmpp.stanzas.SubscriptionPresence object at 0x7f81a0b6e9d0>}
2012-11-16 15:44:15.333685 [sylk-server 31059]: Notification name=XMPPSubscriptionChangedState sender=<sylk.applications.xmppgateway.xmpp.subscription.XMPPSubscription object at 0x7f81a0b6e350>
{'prev_state': 'subscribe_sent', 'state': 'active'}

==> xmpp_trace.txt <==
2012-11-16T15:44:15.334316+01:00 [sylk-server 31059]: RECEIVED: Packet 23, +0:02:01.804090
<presence from='tihoparvi at testing.com/CZ-R8LGKEG' to='alice at open-ims.test' xml:lang='en'>
<priority>5</priority>
<c xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps' ver='caps-b75d8d2b25' ext='ca cs ep-notify-2 html'/>
<delay xmlns='urn:xmpp:delay' from='tihoparvi at testing.com/CZ-R8LGKEG' stamp='2012-11-16T15:17:25Z'></delay><x xmlns='jabber:x:delay' stamp='20121116T15:17:25'/></presence><message from='tihoparvi at testing.com' to='alice at open-ims.test'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='http://jabber.org/protocol/mood'><item id='0'><mood xmlns='http://jabber.org/protocol/mood'/></item></items></event><delay xmlns='urn:xmpp:delay' from='tihoparvi at testing.com/Gajim' stamp='2012-11-15T12:38:18Z'></delay></message><message from='tihoparvi at testing.com' to='alice at open-ims.test'><event xmlns='http://jabber.org/protocol/pubsub#event'><items node='http://jabber.org/protocol/activity'><item id='0'><activity xmlns='http://jabber.org/protocol/activity'/></item></items></event><delay xmlns='urn:xmpp:delay' from='tihoparvi at testing.com/Gajim' stamp='2012-11-15T12:38:18Z'></delay></message>
--

==> notifications_trace.txt <==
2012-11-16 15:44:15.336868 [sylk-server 31059]: Notification name=XMPPGotPresenceAvailability sender=<wokkel.component.InternalComponent object at 0x7f81a0ab6310>
{'presence_stanza': <sylk.applications.xmppgateway.xmpp.stanzas.AvailabilityPresence object at 0x7f81a0b6e810>}

==> sip_trace.txt <==
2012-11-16 15:44:15.339397 [sylk-server 31059]: SENDING: Packet 8, +0:02:01.696415
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:6060
SIP/2.0 202 Accepted
Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bKa836.e63424b3.0
Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bKa836.8bc6a685.0
Via: SIP/2.0/UDP 10.226.20.14:55305;rport=55305;branch=z9hG4bK1353054401714
Record-Route: <sip:mo at 10.226.20.240:6060;lr>
Record-Route: <sip:mo at 10.226.20.240:4060;lr>
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
From: <sip:alice at open-ims.test>;tag=31001
To: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
CSeq: 701 SUBSCRIBE
Contact: <sip:tihoparvi at 10.226.20.56:6060>
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Supported: 100rel, replaces, norefersub, gruu
Expires: 3600
Server: SylkServer-2.2.1
Content-Length:  0


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.344579 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionAnsweredSubscribe sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': None,
'code': 202,
'headers': {'Allow': ['SUBSCRIBE',
                       'NOTIFY',
                       'PRACK',
                       'INVITE',
                       'ACK',
                       'BYE',
                       'CANCEL',
                       'UPDATE',
                       'MESSAGE',
                       'REFER'],
             'CSeq': (701, 'SUBSCRIBE'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.56', 'tihoparvi', None, 6060, False, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))],
             'Expires': 3600,
             'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
                              FrozenRecordRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 4060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({}))],
             'Server': FrozenHeader('Server', 'SylkServer-2.2.1'),
             'Supported': ['100rel', 'replaces', 'norefersub', 'gruu'],
             'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'Via': [FrozenViaHeader('UDP', '10.226.20.240', 6060, frozendict({'received': '10.226.20.240', 'branch': 'z9hG4bKa836.e63424b3.0'})),
                     FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bKa836.8bc6a685.0'})),
                     FrozenViaHeader('UDP', '10.226.20.14', 55305, frozendict({'rport': 55305, 'branch': 'z9hG4bK1353054401714'}))]},
'reason': 'Accepted'}
2012-11-16 15:44:15.353857 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionChangedState sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'prev_state': 'incoming', 'state': 'pending'}

==> sip_trace.txt <==
2012-11-16 15:44:15.340274 [sylk-server 31059]: SENDING: Packet 9, +0:02:01.697292
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:6060
NOTIFY sip:alice at 10.226.20.14:55305;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport;branch=z9hG4bKPjm7PQto36WRuZNqaBP4rTIFtofi3pSXPo
Max-Forwards: 70
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>;tag=31001
Contact: <sip:tihoparvi at 10.226.20.56:6060>
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
CSeq: 26351 NOTIFY
Route: <sip:mo at 10.226.20.240:6060;lr>
Route: <sip:mo at 10.226.20.240:4060;lr>
Event: presence
Subscription-State: pending;expires=599999
Allow-Events: conference, refer, presence
User-Agent: SylkServer-2.2.1
Content-Length:  0


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.357248 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionSentNotify sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': None,
'headers': {'Allow-Events': ['conference', 'refer', 'presence'],
             'CSeq': (26351, 'NOTIFY'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.56', 'tihoparvi', None, 6060, False, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))],
             'Event': FrozenEventHeader('presence', frozendict({})),
             'From': FrozenFromHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'Max-Forwards': 70,
             'Route': [FrozenRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
                       FrozenRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 4060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({}))],
             'Subscription-State': FrozenSubscriptionStateHeader('pending', frozendict({'expires': '599999'})),
             'To': FrozenToHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             'User-Agent': FrozenHeader('User-Agent', 'SylkServer-2.2.1'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.56', 6060, frozendict({'rport': 0, 'branch': 'z9hG4bKPjm7PQto36WRuZNqaBP4rTIFtofi3pSXPo'}))]},
'method': 'NOTIFY',
'request_uri': FrozenSIPURI('10.226.20.14', 'alice', None, 55305, False, frozendict({'transport': 'udp'}), frozendict({}))}
2012-11-16 15:44:15.361748 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionChangedState sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'prev_state': 'pending', 'state': 'active'}

==> sip_trace.txt <==
2012-11-16 15:44:15.341041 [sylk-server 31059]: SENDING: Packet 10, +0:02:01.698059
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:6060
NOTIFY sip:alice at 10.226.20.14:55305;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport;branch=z9hG4bKPjjk0WPviI5XdtE.TxLFX75PmpGbYf9GXE
Max-Forwards: 70
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>;tag=31001
Contact: <sip:tihoparvi at 10.226.20.56:6060>
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
CSeq: 26352 NOTIFY
Route: <sip:mo at 10.226.20.240:6060;lr>
Route: <sip:mo at 10.226.20.240:4060;lr>
Event: presence
Subscription-State: active;expires=599999
Allow-Events: conference, refer, presence
User-Agent: SylkServer-2.2.1
Content-Length:  0


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.364647 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionSentNotify sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': None,
'headers': {'Allow-Events': ['conference', 'refer', 'presence'],
             'CSeq': (26352, 'NOTIFY'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.56', 'tihoparvi', None, 6060, False, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))],
             'Event': FrozenEventHeader('presence', frozendict({})),
             'From': FrozenFromHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'Max-Forwards': 70,
             'Route': [FrozenRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
                       FrozenRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 4060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({}))],
             'Subscription-State': FrozenSubscriptionStateHeader('active', frozendict({'expires': '599999'})),
             'To': FrozenToHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             'User-Agent': FrozenHeader('User-Agent', 'SylkServer-2.2.1'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.56', 6060, frozendict({'rport': 0, 'branch': 'z9hG4bKPjjk0WPviI5XdtE.TxLFX75PmpGbYf9GXE'}))]},
'method': 'NOTIFY',
'request_uri': FrozenSIPURI('10.226.20.14', 'alice', None, 55305, False, frozendict({'transport': 'udp'}), frozendict({}))}

==> sip_trace.txt <==
2012-11-16 15:44:15.345068 [sylk-server 31059]: RECEIVED: Packet 11, +0:02:01.702086
10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.56:6060
SIP/2.0 200 OK
Max-Forwards: 70
User-Agent: IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport=6060;branch=z9hG4bKPjm7PQto36WRuZNqaBP4rTIFtofi3pSXPo
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>;tag=31001
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
CSeq: 26351 NOTIFY
Privacy: none
Content-Length: 0


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.368829 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionNotifyDidSucceed sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': None,
'code': 200,
'headers': {'CSeq': (26351, 'NOTIFY'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Content-Length': 0,
             'From': FrozenFromHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'Max-Forwards': 70,
             'Privacy': FrozenHeader('Privacy', 'none'),
             'To': FrozenToHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             'User-Agent': FrozenHeader('User-Agent', 'IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.56', 6060, frozendict({'rport': 6060, 'branch': 'z9hG4bKPjm7PQto36WRuZNqaBP4rTIFtofi3pSXPo'}))]},
'reason': 'OK'}

==> sip_trace.txt <==
2012-11-16 15:44:15.345842 [sylk-server 31059]: RECEIVED: Packet 12, +0:02:01.702860
10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.56:6060
SIP/2.0 200 OK
Max-Forwards: 70
User-Agent: IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport=6060;branch=z9hG4bKPjjk0WPviI5XdtE.TxLFX75PmpGbYf9GXE
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>;tag=31001
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
CSeq: 26352 NOTIFY
Privacy: none
Content-Length: 0


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.370922 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionNotifyDidSucceed sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': None,
'code': 200,
'headers': {'CSeq': (26352, 'NOTIFY'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Content-Length': 0,
             'From': FrozenFromHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'Max-Forwards': 70,
             'Privacy': FrozenHeader('Privacy', 'none'),
             'To': FrozenToHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             'User-Agent': FrozenHeader('User-Agent', 'IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.56', 6060, frozendict({'rport': 6060, 'branch': 'z9hG4bKPjjk0WPviI5XdtE.TxLFX75PmpGbYf9GXE'}))]},
'reason': 'OK'}
2012-11-16 15:44:15.371366 [sylk-server 31059]: Notification name=XMPPSubscriptionGotNotify sender=<sylk.applications.xmppgateway.xmpp.subscription.XMPPSubscription object at 0x7f81a0b6e350>
{'presence': <sylk.applications.xmppgateway.xmpp.stanzas.AvailabilityPresence object at 0x7f81a0b6e810>}

==> sip_trace.txt <==
2012-11-16 15:44:15.367186 [sylk-server 31059]: SENDING: Packet 13, +0:02:01.724204
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:6060
NOTIFY sip:alice at 10.226.20.14:55305;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport;branch=z9hG4bKPjjRrym3OyF.CV3C6NnC6WwkBVMgwFWPZT
Max-Forwards: 70
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>;tag=31001
Contact: <sip:tihoparvi at 10.226.20.56:6060>
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
CSeq: 26353 NOTIFY
Route: <sip:mo at 10.226.20.240:6060;lr>
Route: <sip:mo at 10.226.20.240:4060;lr>
Event: presence
Subscription-State: active;expires=599999
Allow-Events: conference, refer, presence
User-Agent: SylkServer-2.2.1
Content-Type: application/pidf+xml
Content-Length:   873

<?xml version='1.0' encoding='UTF-8'?>
<presence xmlns:dm="urn:ietf:params:xml:ns:pidf:data-model" xmlns:agp-pidf="urn:ag-projects:xml:ns:pidf" xmlns:caps="urn:ietf:params:xml:ns:pidf:caps" xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid" xmlns="urn:ietf:params:xml:ns:pidf" entity="tihoparvi%40testing.com"><tuple id="ID-435a2d52384c474b4547"><status><basic>open</basic><agp-pidf:extended>available</agp-pidf:extended></status><dm:deviceID>435a2d52384c474b4547</dm:deviceID><agp-pidf:device-info id="435a2d52384c474b4547"><agp-pidf:description>CZ-R8LGKEG</agp-pidf:description></agp-pidf:device-info><caps:servcaps><caps:message>true</caps:message><caps:text>true</caps:text></caps:servcaps><contact>sip%3Atihoparvi%40testing.com%3Bxmpp%3Bgr%3D435a2d52384c474b4547</contact></tuple><dm:person id="ID-ed8975ecb63f91ca1146ca625b6fca2d"><rpid:activities/></dm:person></presence>
--

==> notifications_trace.txt <==
2012-11-16 15:44:15.375133 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionSentNotify sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': '<?xml version=\'1.0\' encoding=\'UTF-8\'?>\n<presence xmlns:dm="urn:ietf:params:xml:ns:pidf:data-model" xmlns:agp-pidf="urn:ag-projects:xml:ns:pidf" xmlns:caps="urn:ietf:params:xml:ns:pidf:caps" xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid" xmlns="urn:ietf:params:xml:ns:pidf" entity="tihoparvi%40testing.com"><tuple id="ID-435a2d52384c474b4547"><status><basic>open</basic><agp-pidf:extended>available</agp-pidf:extended></status><dm:deviceID>435a2d52384c474b4547</dm:deviceID><agp-pidf:device-info id="435a2d52384c474b4547"><agp-pidf:description>CZ-R8LGKEG</agp-pidf:description></agp-pidf:device-info><caps:servcaps><caps:message>true</caps:message><caps:text>true</caps:text></caps:servcaps><contact>sip%3Atihoparvi%40testing.com%3Bxmpp%3Bgr%3D435a2d52384c474b4547</contact></tuple><dm:person id="ID-ed8975ecb63f91ca1146ca625b6fca2d"><rpid:activities/></dm:person></presence>',
'headers': {'Allow-Events': ['conference', 'refer', 'presence'],
             'CSeq': (26353, 'NOTIFY'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.56', 'tihoparvi', None, 6060, False, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))],
             'Event': FrozenEventHeader('presence', frozendict({})),
             'From': FrozenFromHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'Max-Forwards': 70,
             'Route': [FrozenRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 6060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({})),
                       FrozenRouteHeader(FrozenSIPURI('10.226.20.240', 'mo', None, 4060, False, frozendict({'lr': None}), frozendict({})), None, frozendict({}))],
             'Subscription-State': FrozenSubscriptionStateHeader('active', frozendict({'expires': '599999'})),
             'To': FrozenToHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             'User-Agent': FrozenHeader('User-Agent', 'SylkServer-2.2.1'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.56', 6060, frozendict({'rport': 0, 'branch': 'z9hG4bKPjjRrym3OyF.CV3C6NnC6WwkBVMgwFWPZT'}))]},
'method': 'NOTIFY',
'request_uri': FrozenSIPURI('10.226.20.14', 'alice', None, 55305, False, frozendict({'transport': 'udp'}), frozendict({}))}

==> sip_trace.txt <==
2012-11-16 15:44:15.367537 [sylk-server 31059]: RECEIVED: Packet 14, +0:02:01.724555
10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.56:6060
SIP/2.0 200 OK
Max-Forwards: 70
User-Agent: IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport=6060;branch=z9hG4bKPjjRrym3OyF.CV3C6NnC6WwkBVMgwFWPZT
From: <sip:tihoparvi at testing.com>;tag=.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ
To: <sip:alice at open-ims.test>;tag=31001
Call-ID: M-332637331fafc0b9cc12b897c228d4d6
CSeq: 26353 NOTIFY
Privacy: none
Content-Length: 0


--

==> notifications_trace.txt <==
2012-11-16 15:44:15.377478 [sylk-server 31059]: Notification name=SIPIncomingSubscriptionNotifyDidSucceed sender=<sipsimple.core._core.IncomingSubscription object at 0x7f81a0b485f0>
{'body': None,
'code': 200,
'headers': {'CSeq': (26353, 'NOTIFY'),
             'Call-ID': FrozenHeader('Call-ID', 'M-332637331fafc0b9cc12b897c228d4d6'),
             'Content-Length': 0,
             'From': FrozenFromHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '.EfAhwd-0c-z52ozXnr.DNN8ET0Ek4wQ'})),
             'Max-Forwards': 70,
             'Privacy': FrozenHeader('Privacy', 'none'),
             'To': FrozenToHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '31001'})),
             'User-Agent': FrozenHeader('User-Agent', 'IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0'),
             'Via': [FrozenViaHeader('UDP', '10.226.20.56', 6060, frozendict({'rport': 6060, 'branch': 'z9hG4bKPjjRrym3OyF.CV3C6NnC6WwkBVMgwFWPZT'}))]},
'reason': 'OK'}






From: Adrian Georgescu [mailto:ag at ag-projects.com]
Sent: 16 November 2012 16:16
To: Hadzhiev, Tihomir
Cc: sipbeyondvoip at lists.ag-projects.com
Subject: Re: [SIP Beyond VoIP] Another case where Sylk would reject Notifications

please isolate the trace yourself, and paste again only the subscriber and notify. skip core traces

Adrian


On Nov 16, 2012, at 4:09 PM, Hadzhiev, Tihomir wrote:


As I wrote on top of the mail I have sent, disregard the admin at testing.com<mailto:admin at testing.com> user. The one that is in red is from alice at open-ims.test<mailto:alice at open-ims.test> towardsadmin at testing.com<mailto:admin at testing.com> that's not the call flow we are looking at.

Instead the target XMPP user is tihoparvi at testing.com<mailto:tihoparvi at testing.com>


Tiho

From: Adrian Georgescu [mailto:ag at ag-projects.com]
Sent: 16 November 2012 16:02
To: Hadzhiev, Tihomir
Cc: sipbeyondvoip at lists.ag-projects.com<mailto:sipbeyondvoip at lists.ag-projects.com>
Subject: Re: [SIP Beyond VoIP] Another case where Sylk would reject Notifications

The answer is in the line:

SIP/2.0 481 Call/Transaction Does Not Exist

The Notify received by SylkServer from IMS server does not match any subscription. SylkServer started a subscription with Call-ID: JA7JhBheIYEBluQMcw2-RQ2.lh35CntV and got 202 OK. Subsequent NOTIFY must have same call id, but it does not, it uses Call-ID: cwL-bWBXrIVO2VDXdhneNgOluVudateT instead.

Adrian

On Nov 16, 2012, at 3:33 PM, Hadzhiev, Tihomir wrote:



==> sip_trace.txt <==
2012-11-16 14:53:40.611456 [sylk-server 30934]: SENDING: Packet 1, +0:00:00
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:5060
SUBSCRIBE sip:alice at open-ims.test SIP/2.0
Via: SIP/2.0/UDP 10.226.20.56:6060;rport;branch=z9hG4bKPjAJwSi5xicEf5AurgbBADneVBfgqOAkTL
Max-Forwards: 70
From: <sip:tihoparvi at testing.com>;tag=BNdJ7hoAPdRZGMX.ehk3x80KWzp0946f
To: <sip:alice at open-ims.test>
Contact: <sip:clnheraz at 10.226.20.56:6060>
Call-ID: JA7JhBheIYEBluQMcw2-RQ2.lh35CntV


==> sip_trace.txt <==
2012-11-16 14:53:40.612043 [sylk-server 30934]: RECEIVED: Packet 2, +0:00:00.000587
10.226.20.240:5060 -(SIP over UDP)-> 10.226.20.56:6060
SIP/2.0 202 OK


==> sip_trace.txt <==
2012-11-16 14:54:37.258218 [sylk-server 30934]: RECEIVED: Packet 7, +0:00:56.646762
10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.56:6060
NOTIFY sip:wbfhcopd at 10.226.20.56:6060 SIP/2.0
Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bKd0b2.89150127.0
Via: SIP/2.0/UDP 10.226.20.56:5080;branch=z9hG4bKd0b2.62b4a8f4.0
To: sip:admin at testing.com;tag=MdlzJqoJndrpldssDBZ-77gVVv87J0fI
From: sip:alice at open-ims.test;tag=48b5b8952e8d0bca6256941910840e90-ce98
CSeq: 4 NOTIFY
Call-ID: cwL-bWBXrIVO2VDXdhneNgOluVudateT


==> sip_trace.txt <==
2012-11-16 14:54:37.258624 [sylk-server 30934]: SENDING: Packet 8, +0:00:56.647168
10.226.20.56:6060 -(SIP over UDP)-> 10.226.20.240:6060
SIP/2.0 481 Call/Transaction Does Not Exist
Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bKd0b2.89150127.0
Via: SIP/2.0/UDP 10.226.20.56:5080;branch=z9hG4bKd0b2.62b4a8f4.0
Call-ID: cwL-bWBXrIVO2VDXdhneNgOluVudateT
From: <sip:alice at open-ims.test>;tag=48b5b8952e8d0bca6256941910840e90-ce98
To: <sip:admin at testing.com>;tag=MdlzJqoJndrpldssDBZ-77gVVv87J0fI
CSeq: 4 NOTIFY
Server: SylkServer-2.2.1
Content-Length:  0


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


________________________________
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/20121116/e7652c7a/attachment-0001.html>


More information about the SIPBeyondVoIP mailing list