==> core_trace.txt <== 2012-09-18 13:47:22.866261 [sylk-server 2132] (5) sip_endpoint.c: Processing incoming message: Request msg REGISTER/cseq=10 (rdata0x7fcea0163278) ==> sip_trace.txt <== 2012-09-18 13:47:22.867683 [sylk-server 2132]: RECEIVED: Packet 1, +0:00:00 10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.31:5070 REGISTER sip:10.226.20.31:5070 SIP/2.0 Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK124f.0e320371.0 To: sip:alice@open-ims.test From: sip:scscf.open-ims.test:6060;tag=fe1333654d776e39dec8456928d98e62-30a2 CSeq: 10 REGISTER Call-ID: 225750a07d800563-23773@10.226.20.240 Content-Length: 0 User-Agent: Sip EXpress router(2.1.0-dev1 OpenIMSCore (x86_64/linux)) Event: registration Max-Forwards: 10 Expires: 600120 Contact: P-Visited-Network-ID: open-ims.test P-Access-Network-Info: ADSL;utran-cell-id-3gpp=00000000 P-Charging-Vector: icid-value="P-CSCFabcd0000000050585f3a00000045";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test" -- ==> core_trace.txt <== 2012-09-18 13:47:22.868557 [sylk-server 2132] (5) endpoint: Response msg 405/REGISTER/cseq=10 (tdta0x7fce9c010620) created 2012-09-18 13:47:22.868788 [sylk-server 2132] (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-18 13:47:22.869006 [sylk-server 2132]: SENDING: Packet 2, +0:00:00.001323 10.226.20.31: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=z9hG4bK124f.0e320371.0 Call-ID: 225750a07d800563-23773@10.226.20.240 From: ;tag=fe1333654d776e39dec8456928d98e62-30a2 To: CSeq: 10 REGISTER Server: SylkServer-2.0.0 Content-Length: 0 -- ==> core_trace.txt <== 2012-09-18 13:47:22.869263 [sylk-server 2132] (5) tdta0x7fce9c01: Destroying txdata Response msg 405/REGISTER/cseq=10 (tdta0x7fce9c010620) 2012-09-18 13:47:22.910077 [sylk-server 2132] (5) sip_endpoint.c: Processing incoming message: Request msg SUBSCRIBE/cseq=201 (rdata0x7fce9c010648) ==> sip_trace.txt <== 2012-09-18 13:47:22.914264 [sylk-server 2132]: RECEIVED: Packet 3, +0:00:00.046581 10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.31:5070 SUBSCRIBE sip:alice@open-ims.test SIP/2.0 Record-Route: Route: , Record-Route: Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK605a.7dde8ea2.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK605a.f7db6be2.0 Via: SIP/2.0/UDP 10.226.52.41:1691;rport=1691;branch=z9hG4bK1347966662302 From: ;tag=17807 To: Call-ID: M-fcdca921ea69f457aea74d2185dc812e CSeq: 201 SUBSCRIBE Max-Forwards: 15 Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER Contact: ;+g.oma.sip-im User-Agent: IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0 Expires: 600000 Event: message-summary Accept: application/simple-message-summary 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: P-Charging-Vector: icid-value="P-CSCFabcd0000000050585f3a00000047";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test" -- ==> core_trace.txt <== 2012-09-18 13:47:22.914312 [sylk-server 2132] (5) endpoint: Response msg 489/SUBSCRIBE/cseq=201 (tdta0x7fce9c0224c0) created 2012-09-18 13:47:22.914901 [sylk-server 2132] (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-18 13:47:22.916423 [sylk-server 2132]: SENDING: Packet 4, +0:00:00.048740 10.226.20.31:5070 -(SIP over UDP)-> 10.226.20.240:6060 SIP/2.0 489 Bad Event Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bK605a.7dde8ea2.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK605a.f7db6be2.0 Via: SIP/2.0/UDP 10.226.52.41:1691;rport=1691;branch=z9hG4bK1347966662302 Record-Route: Record-Route: Call-ID: M-fcdca921ea69f457aea74d2185dc812e From: ;tag=17807 To: CSeq: 201 SUBSCRIBE Server: SylkServer-2.0.0 Content-Length: 0 -- ==> core_trace.txt <== 2012-09-18 13:47:22.917732 [sylk-server 2132] (5) tdta0x7fce9c02: Destroying txdata Response msg 489/SUBSCRIBE/cseq=201 (tdta0x7fce9c0224c0) 2012-09-18 13:47:22.919838 [sylk-server 2132] (5) sip_endpoint.c: Processing incoming message: Request msg SUBSCRIBE/cseq=101 (rdata0x7fce9c010648) ==> sip_trace.txt <== 2012-09-18 13:47:22.920962 [sylk-server 2132]: RECEIVED: Packet 5, +0:00:00.053279 10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.31:5070 SUBSCRIBE sip:alice@open-ims.test SIP/2.0 Record-Route: Route: , Record-Route: Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK0c8c.d23a1e35.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK0c8c.b303ca51.0 Via: SIP/2.0/UDP 10.226.52.41:1691;rport=1691;branch=z9hG4bK1347966662303 From: ;tag=6617 To: Call-ID: M-496172f27eca2e054d4b68b10626aeea CSeq: 101 SUBSCRIBE Max-Forwards: 15 Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER Contact: ;+g.oma.sip-im User-Agent: IM-client/OMA1.0 Mercuro-Gold/v4.0.1631.0 Expires: 600000 Event: presence.winfo Accept: application/watcherinfo+xml 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: P-Charging-Vector: icid-value="P-CSCFabcd0000000050585f3a00000048";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test" -- ==> core_trace.txt <== 2012-09-18 13:47:22.922393 [sylk-server 2132] (5) endpoint: Response msg 489/SUBSCRIBE/cseq=101 (tdta0x7fce9c0224c0) created 2012-09-18 13:47:22.923320 [sylk-server 2132] (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-18 13:47:22.924223 [sylk-server 2132]: SENDING: Packet 6, +0:00:00.056540 10.226.20.31:5070 -(SIP over UDP)-> 10.226.20.240:6060 SIP/2.0 489 Bad Event Via: SIP/2.0/UDP 10.226.20.240:6060;received=10.226.20.240;branch=z9hG4bK0c8c.d23a1e35.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK0c8c.b303ca51.0 Via: SIP/2.0/UDP 10.226.52.41:1691;rport=1691;branch=z9hG4bK1347966662303 Record-Route: Record-Route: Call-ID: M-496172f27eca2e054d4b68b10626aeea From: ;tag=6617 To: CSeq: 101 SUBSCRIBE Server: SylkServer-2.0.0 Content-Length: 0 -- ==> core_trace.txt <== 2012-09-18 13:47:22.926138 [sylk-server 2132] (5) tdta0x7fce9c02: Destroying txdata Response msg 489/SUBSCRIBE/cseq=101 (tdta0x7fce9c0224c0) 2012-09-18 13:47:22.972169 [sylk-server 2132] (5) sip_endpoint.c: Processing incoming message: Request msg SUBSCRIBE/cseq=201 (rdata0x7fce9c010648) ==> sip_trace.txt <== 2012-09-18 13:47:22.980210 [sylk-server 2132]: RECEIVED: Packet 7, +0:00:00.112527 10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.31:5070 SUBSCRIBE sip:tihoparvi@testing.com SIP/2.0 Record-Route: Route: , Record-Route: Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK8aab.cd1f5796.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK8aab.a3f5a017.0 Via: SIP/2.0/UDP 10.226.52.41:1691;rport=1691;branch=z9hG4bK1347966662304 From: ;tag=14309 To: Call-ID: M-fa59d5705c0109e32f513b338ca78a83 CSeq: 201 SUBSCRIBE Max-Forwards: 15 Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER Contact: ;+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: P-Charging-Vector: icid-value="P-CSCFabcd0000000050585f3a00000049";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test" -- ==> core_trace.txt <== 2012-09-18 13:47:22.983458 [sylk-server 2132] (5) tsx0x7fce9c023: Transaction created for Request msg SUBSCRIBE/cseq=201 (rdata0x7fce9c010648) 2012-09-18 13:47:22.984381 [sylk-server 2132] (5) tsx0x7fce9c023: Incoming Request msg SUBSCRIBE/cseq=201 (rdata0x7fce9c010648) in state Null 2012-09-18 13:47:22.985116 [sylk-server 2132] (5) tsx0x7fce9c023: State changed from Null to Trying, event=RX_MSG 2012-09-18 13:47:22.986068 [sylk-server 2132] (5) dlg0x7fce9c023: Transaction tsx0x7fce9c023e48 state changed to Trying 2012-09-18 13:47:22.986318 [sylk-server 2132] (5) dlg0x7fce9c023: UAS dialog created 2012-09-18 13:47:22.986549 [sylk-server 2132] (5) dlg0x7fce9c023: Session count inc to 1 by mod-core 2012-09-18 13:47:22.986793 [sylk-server 2132] (5) dlg0x7fce9c023: Module mod-evsub added as dialog usage, data=0x7fce9c024ae0 2012-09-18 13:47:22.987018 [sylk-server 2132] (5) evsub0x7fce9c0: UAS subscription created, using dialog dlg0x7fce9c023218 2012-09-18 13:47:22.987270 [sylk-server 2132] (5) dlg0x7fce9c023: Session count inc to 3 by mod-evsub 2012-09-18 13:47:22.987513 [sylk-server 2132] (5) endpoint: Response msg 500/SUBSCRIBE/cseq=201 (tdta0x7fce9c024fe0) created ==> notifications_trace.txt <== 2012-09-18 13:47:23.002371 [sylk-server 2132]: Notification name=SIPIncomingSubscriptionGotSubscribe sender= {'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': (201, 'SUBSCRIBE'), 'Call-ID': FrozenHeader('Call-ID', 'M-fa59d5705c0109e32f513b338ca78a83'), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.52.41', 'alice', None, 1691, 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': '14309'})), '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', ''), 'P-Charging-Vector': FrozenHeader('P-Charging-Vector', 'icid-value="P-CSCFabcd0000000050585f3a00000049";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"'), '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({}))], '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': 'z9hG4bK8aab.cd1f5796.0'})), FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bK8aab.a3f5a017.0'})), FrozenViaHeader('UDP', '10.226.52.41', 1691, frozendict({'rport': 1691, 'branch': 'z9hG4bK1347966662304'}))]}, 'method': 'SUBSCRIBE', 'request_uri': FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({}))} 2012-09-18 13:47:23.003792 [sylk-server 2132]: Notification name=XMPPSubscriptionDidStart sender= {} 2012-09-18 13:47:23.004102 [sylk-server 2132]: Notification name=XMPPSubscriptionChangedState sender= {'prev_state': None, 'state': 'subscribe_sent'} ==> core_trace.txt <== 2012-09-18 13:47:22.993958 [sylk-server 2132] (5) sip_endpoint.c: Processing incoming message: Request msg SUBSCRIBE/cseq=901 (rdata0x7fce9c010648) ==> sip_trace.txt <== 2012-09-18 13:47:22.994060 [sylk-server 2132]: RECEIVED: Packet 8, +0:00:00.126377 10.226.20.240:6060 -(SIP over UDP)-> 10.226.20.31:5070 SUBSCRIBE sip:tihovroti@testing.com SIP/2.0 Record-Route: Route: , Record-Route: Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK05a8.09fb5ee3.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK05a8.f6d05172.0 Via: SIP/2.0/UDP 10.226.52.41:1691;rport=1691;branch=z9hG4bK1347966662305 From: ;tag=17451 To: Call-ID: M-a850173bffdd8b826ae86adc29341e8e CSeq: 901 SUBSCRIBE Max-Forwards: 15 Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER Contact: ;+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: P-Charging-Vector: icid-value="P-CSCFabcd0000000050585f3a0000004a";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test" -- ==> core_trace.txt <== 2012-09-18 13:47:22.994106 [sylk-server 2132] (5) tsx0x7fce9c02a: Transaction created for Request msg SUBSCRIBE/cseq=901 (rdata0x7fce9c010648) 2012-09-18 13:47:22.994148 [sylk-server 2132] (5) tsx0x7fce9c02a: Incoming Request msg SUBSCRIBE/cseq=901 (rdata0x7fce9c010648) in state Null 2012-09-18 13:47:22.994190 [sylk-server 2132] (5) tsx0x7fce9c02a: State changed from Null to Trying, event=RX_MSG 2012-09-18 13:47:22.994286 [sylk-server 2132] (5) dlg0x7fce9c029: Transaction tsx0x7fce9c02ab48 state changed to Trying 2012-09-18 13:47:22.994326 [sylk-server 2132] (5) dlg0x7fce9c029: UAS dialog created 2012-09-18 13:47:22.994393 [sylk-server 2132] (5) dlg0x7fce9c029: Session count inc to 1 by mod-core 2012-09-18 13:47:22.994434 [sylk-server 2132] (5) dlg0x7fce9c029: Module mod-evsub added as dialog usage, data=0x7fce9c02b7e0 2012-09-18 13:47:22.994473 [sylk-server 2132] (5) evsub0x7fce9c0: UAS subscription created, using dialog dlg0x7fce9c0298e8 2012-09-18 13:47:22.994617 [sylk-server 2132] (5) dlg0x7fce9c029: Session count inc to 3 by mod-evsub 2012-09-18 13:47:22.994661 [sylk-server 2132] (5) endpoint: Response msg 500/SUBSCRIBE/cseq=901 (tdta0x7fce9c02bd40) created ==> notifications_trace.txt <== 2012-09-18 13:47:23.008699 [sylk-server 2132]: Notification name=SIPIncomingSubscriptionGotSubscribe sender= {'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': (901, 'SUBSCRIBE'), 'Call-ID': FrozenHeader('Call-ID', 'M-a850173bffdd8b826ae86adc29341e8e'), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.52.41', 'alice', None, 1691, 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': '17451'})), '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', ''), 'P-Charging-Vector': FrozenHeader('P-Charging-Vector', 'icid-value="P-CSCFabcd0000000050585f3a0000004a";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test"'), '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({}))], 'Supported': ['eventlist'], 'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihovroti', 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': 'z9hG4bK05a8.09fb5ee3.0'})), FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bK05a8.f6d05172.0'})), FrozenViaHeader('UDP', '10.226.52.41', 1691, frozendict({'rport': 1691, 'branch': 'z9hG4bK1347966662305'}))]}, 'method': 'SUBSCRIBE', 'request_uri': FrozenSIPURI('testing.com', 'tihovroti', None, None, False, frozendict({}), frozendict({}))} 2012-09-18 13:47:23.015473 [sylk-server 2132]: Notification name=S2XPresenceHandlerDidStart sender= {} 2012-09-18 13:47:23.023266 [sylk-server 2132]: Notification name=XMPPSubscriptionDidStart sender= {} 2012-09-18 13:47:23.023679 [sylk-server 2132]: Notification name=XMPPSubscriptionChangedState sender= {'prev_state': None, 'state': 'subscribe_sent'} 2012-09-18 13:47:23.025066 [sylk-server 2132]: Notification name=S2XPresenceHandlerDidStart sender= {} ==> xmpp_trace.txt <== 2012-09-18T13:47:23.040522+02:00 [sylk-server 2132]: SENDING: Packet 1, +0:00:00 -- 2012-09-18T13:47:23.042823+02:00 [sylk-server 2132]: RECEIVED: Packet 2, +0:00:00.002301 -- 2012-09-18T13:47:23.045045+02:00 [sylk-server 2132]: SENDING: Packet 3, +0:00:00.004523 e3869c1f555915f334d3b59f259182779ec861a0e18c4ab824941633090288e3 -- 2012-09-18T13:47:23.048864+02:00 [sylk-server 2132]: RECEIVED: Packet 4, +0:00:00.008342 -- 2012-09-18T13:47:23.050481+02:00 [sylk-server 2132]: SENDING: Packet 5, +0:00:00.009959 -- 2012-09-18T13:47:23.050842+02:00 [sylk-server 2132]: SENDING: Packet 6, +0:00:00.010320 -- 2012-09-18T13:47:23.051745+02:00 [sylk-server 2132]: RECEIVED: Packet 7, +0:00:00.011223 999684078 -- 2012-09-18T13:47:23.056619+02:00 [sylk-server 2132]: SENDING: Packet 8, +0:00:00.016097 -- 2012-09-18T13:47:23.058027+02:00 [sylk-server 2132]: RECEIVED: Packet 9, +0:00:00.017505 -- 2012-09-18T13:47:23.058914+02:00 [sylk-server 2132]: SENDING: Packet 10, +0:00:00.018392 999684078 -- 2012-09-18T13:47:23.060279+02:00 [sylk-server 2132]: RECEIVED: Packet 11, +0:00:00.019757 -- 2012-09-18T13:47:23.060864+02:00 [sylk-server 2132]: SENDING: Packet 12, +0:00:00.020342 -- 2012-09-18T13:47:23.063066+02:00 [sylk-server 2132]: RECEIVED: Packet 13, +0:00:00.022544 e3869c1f555915f334d3b59f259182779ec861a0e18c4ab824941633090288e3 -- 2012-09-18T13:47:23.064010+02:00 [sylk-server 2132]: SENDING: Packet 14, +0:00:00.023488 -- 2012-09-18T13:47:23.064840+02:00 [sylk-server 2132]: RECEIVED: Packet 15, +0:00:00.024318 -- 2012-09-18T13:47:23.065792+02:00 [sylk-server 2132]: SENDING: Packet 16, +0:00:00.025270 -- 2012-09-18T13:47:23.066095+02:00 [sylk-server 2132]: SENDING: Packet 17, +0:00:00.025573 -- 2012-09-18T13:47:23.066400+02:00 [sylk-server 2132]: SENDING: Packet 18, +0:00:00.025878 -- 2012-09-18T13:47:23.066741+02:00 [sylk-server 2132]: SENDING: Packet 19, +0:00:00.026219 -- 2012-09-18T13:47:23.067825+02:00 [sylk-server 2132]: RECEIVED: Packet 20, +0:00:00.027303 -- ==> notifications_trace.txt <== 2012-09-18 13:47:23.069441 [sylk-server 2132]: Notification name=XMPPGotPresenceSubscriptionStatus sender= {'presence_stanza': } 2012-09-18 13:47:23.074934 [sylk-server 2132]: Notification name=XMPPSubscriptionChangedState sender= {'prev_state': 'subscribe_sent', 'state': 'active'} ==> core_trace.txt <== 2012-09-18 13:47:23.097912 [sylk-server 2132] (5) dlg0x7fce9c023: Sending Response msg 202/SUBSCRIBE/cseq=201 (tdta0x7fce9c024fe0) 2012-09-18 13:47:23.100307 [sylk-server 2132] (5) tsx0x7fce9c023: Sending Response msg 202/SUBSCRIBE/cseq=201 (tdta0x7fce9c024fe0) in state Trying 2012-09-18 13:47:23.103314 [sylk-server 2132] (5) sip_resolve.c: Target '10.226.20.240:6060' type=UDP resolved to '10.226.20.240:6060' type=UDP (UDP transport) ==> xmpp_trace.txt <== 2012-09-18T13:47:23.106601+02:00 [sylk-server 2132]: RECEIVED: Packet 21, +0:00:00.066079 5 -- ==> notifications_trace.txt <== 2012-09-18 13:47:23.110502 [sylk-server 2132]: Notification name=XMPPGotPresenceAvailability sender= {'presence_stanza': } 2012-09-18 13:47:23.110869 [sylk-server 2132]: Notification name=XMPPSubscriptionGotNotify sender= {'presence': }