2012-08-22 14:29:27.587357 [sylk-server 10451]: RECEIVED: Packet 15, +0:02:01.588096 10.226.20.240:6060 -(SIP over UDP)-> 192.168.56.101:5070 INVITE sip:tihoparvi@testing.com SIP/2.0 Record-Route: Route: , Record-Route: Via: SIP/2.0/UDP 10.226.20.240:6060;branch=z9hG4bK9012.425118c4.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK9012.c226c957.0 Via: SIP/2.0/UDP 10.226.20.23:2639;branch=z9hG4bK451045079;rport=2639 From: ;tag=451023268 To: Contact: ;+g.oma.sip-im;language="en,fr" Call-ID: 215b1340-b89e-ab1a-4545-7244bffc205d CSeq: 18795 INVITE Content-Type: application/sdp Content-Length: 344 Max-Forwards: 15 Subject: FIXME 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 Supported: 100rel P-Asserted-Identity: P-Charging-Vector: icid-value="P-CSCFabcd000000005034d0a800000092";icid-generated-at=10.226.20.240;orig-ioi="open-ims.test" v=0 o=doubango 1983 678901 IN IP4 10.226.20.23 s=- c=IN IP4 10.226.20.23 t=0 0 m=message 2641 TCP/MSRP * c=IN IP4 10.226.20.23 a=path:msrp://10.226.20.23:2641/451019577;tcp a=connection:new a=setup:actpass a=accept-types:text/plain message/CPIM a=accept-wrapped-types:text/plain image/jpeg image/gif image/bmp image/png a=sendrecv -- ==> core_trace.txt <== 2012-08-22 14:29:27.587000 [sylk-server 10451] (5) tsx0x39a5db8: Transaction created for Request msg INVITE/cseq=18795 (rdata0x3079b88) 2012-08-22 14:29:27.587000 [sylk-server 10451] (5) tsx0x39a5db8: Incoming Request msg INVITE/cseq=18795 (rdata0x3079b88) in state Null 2012-08-22 14:29:27.587000 [sylk-server 10451] (5) tsx0x39a5db8: State changed from Null to Trying, event=RX_MSG 2012-08-22 14:29:27.588000 [sylk-server 10451] (5) dlg0x39e1c38: Transaction tsx0x39a5db8 state changed to Trying 2012-08-22 14:29:27.588000 [sylk-server 10451] (5) dlg0x39e1c38: UAS dialog created 2012-08-22 14:29:27.588000 [sylk-server 10451] (5) dlg0x39e1c38: Module mod-invite added as dialog usage, data=0x39ce608 2012-08-22 14:29:27.588000 [sylk-server 10451] (5) dlg0x39e1c38: Session count inc to 2 by mod-invite 2012-08-22 14:29:27.588000 [sylk-server 10451] (5) inv0x39e1c38: UAS invite session created for dialog dlg0x39e1c38 2012-08-22 14:29:27.588000 [sylk-server 10451] (5) endpoint: Response msg 100/INVITE/cseq=18795 (tdta0x39ded30) created 2012-08-22 14:29:27.588000 [sylk-server 10451] (5) dlg0x39e1c38: Initial answer Response msg 100/INVITE/cseq=18795 (tdta0x39ded30) ==> notifications_trace.txt <== 2012-08-22 14:29:27.613304 [sylk-server 10451]: Notification name=SIPInvitationChangedState sender= {'body': 'v=0\r\no=doubango 1983 678901 IN IP4 10.226.20.23\r\ns=-\r\nc=IN IP4 10.226.20.23\r\nt=0 0\r\nm=message 2641 TCP/MSRP *\r\nc=IN IP4 10.226.20.23\r\na=path:msrp://10.226.20.23:2641/451019577;tcp\r\na=connection:new\r\na=setup:actpass\r\na=accept-types:text/plain message/CPIM\r\na=accept-wrapped-types:text/plain image/jpeg image/gif image/bmp image/png\r\na=sendrecv\r\n', 'headers': {'Allow': ['INVITE', 'ACK', 'CANCEL', 'BYE', 'MESSAGE', 'OPTIONS', 'NOTIFY', 'PRACK', 'UPDATE', 'REFER'], 'CSeq': (18795, 'INVITE'), 'Call-ID': FrozenHeader('Call-ID', '215b1340-b89e-ab1a-4545-7244bffc205d'), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.23', 'alice', None, 2639, False, frozendict({'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0', 'language': '"en,fr"', '+g.oma.sip-im': None}))], 'Content-Length': 344, 'Content-Type': ('application/sdp', ''), 'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '451023268'})), '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-CSCFabcd000000005034d0a800000092";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': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('pcscf.open-ims.test', 'mo', None, 4060, False, frozendict({'lr': 1}), frozendict({})), None, frozendict({}))], '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({}))], 'Subject': FrozenSubjectHeader(u'FIXME'), 'Supported': ['100rel'], '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': 'z9hG4bK9012.425118c4.0'})), FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bK9012.c226c957.0'})), FrozenViaHeader('UDP', '10.226.20.23', 2639, frozendict({'rport': 2639, 'branch': 'z9hG4bK451045079'}))]}, 'method': 'INVITE', 'originator': 'remote', 'prev_state': None, 'request_uri': FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), 'state': 'incoming', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 589489)} 2012-08-22 14:29:27.616392 [sylk-server 10451]: Notification name=SIPSessionNewIncoming sender= {'headers': {'Allow': ['INVITE', 'ACK', 'CANCEL', 'BYE', 'MESSAGE', 'OPTIONS', 'NOTIFY', 'PRACK', 'UPDATE', 'REFER'], 'CSeq': (18795, 'INVITE'), 'Call-ID': FrozenHeader('Call-ID', '215b1340-b89e-ab1a-4545-7244bffc205d'), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.23', 'alice', None, 2639, False, frozendict({'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0', 'language': '"en,fr"', '+g.oma.sip-im': None}))], 'Content-Length': 344, 'Content-Type': ('application/sdp', ''), 'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '451023268'})), '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-CSCFabcd000000005034d0a800000092";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': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('pcscf.open-ims.test', 'mo', None, 4060, False, frozendict({'lr': 1}), frozendict({})), None, frozendict({}))], '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({}))], 'Subject': FrozenSubjectHeader(u'FIXME'), 'Supported': ['100rel'], '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': 'z9hG4bK9012.425118c4.0'})), FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bK9012.c226c957.0'})), FrozenViaHeader('UDP', '10.226.20.23', 2639, frozendict({'rport': 2639, 'branch': 'z9hG4bK451045079'}))]}, 'streams': [], 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 604004)} 2012-08-22 14:29:27.616828 [sylk-server 10451]: Notification name=MediaStreamDidInitialize sender= {'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 609828)} 2012-08-22 14:29:27.617103 [sylk-server 10451]: Notification name=SIPSessionWillStart sender= {'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 615536)} ==> core_trace.txt <== 2012-08-22 14:29:27.600000 [sylk-server 10451] (5) inv0x39e1c38: Sending Response msg 100/INVITE/cseq=18795 (tdta0x39ded30) 2012-08-22 14:29:27.600000 [sylk-server 10451] (5) dlg0x39e1c38: Sending Response msg 100/INVITE/cseq=18795 (tdta0x39ded30) 2012-08-22 14:29:27.601000 [sylk-server 10451] (5) tsx0x39a5db8: Sending Response msg 100/INVITE/cseq=18795 (tdta0x39ded30) in state Trying 2012-08-22 14:29:27.601000 [sylk-server 10451] (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 14:29:27.601142 [sylk-server 10451]: SENDING: Packet 16, +0:02:01.601881 192.168.56.101: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=z9hG4bK9012.425118c4.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK9012.c226c957.0 Via: SIP/2.0/UDP 10.226.20.23:2639;rport=2639;branch=z9hG4bK451045079 Record-Route: Record-Route: Call-ID: 215b1340-b89e-ab1a-4545-7244bffc205d From: ;tag=451023268 To: CSeq: 18795 INVITE Server: SylkServer-2.0.0-dev Content-Length: 0 -- ==> core_trace.txt <== 2012-08-22 14:29:27.601000 [sylk-server 10451] (5) tsx0x39a5db8: State changed from Trying to Proceeding, event=TX_MSG 2012-08-22 14:29:27.601000 [sylk-server 10451] (5) dlg0x39e1c38: Transaction tsx0x39a5db8 state changed to Proceeding 2012-08-22 14:29:27.610000 [sylk-server 10451] (5) inv0x39e1c38: SDP negotiation done, status=0 2012-08-22 14:29:27.613000 [sylk-server 10451] (5) inv0x39e1c38: Sending Response msg 200/INVITE/cseq=18795 (tdta0x39ded30) 2012-08-22 14:29:27.613000 [sylk-server 10451] (5) dlg0x39e1c38: Sending Response msg 200/INVITE/cseq=18795 (tdta0x39ded30) 2012-08-22 14:29:27.613000 [sylk-server 10451] (5) tsx0x39a5db8: Sending Response msg 200/INVITE/cseq=18795 (tdta0x39ded30) in state Proceeding ==> sip_trace.txt <== 2012-08-22 14:29:27.613445 [sylk-server 10451]: SENDING: Packet 17, +0:02:01.614184 192.168.56.101:5070 -(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=z9hG4bK9012.425118c4.0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=z9hG4bK9012.c226c957.0 Via: SIP/2.0/UDP 10.226.20.23:2639;rport=2639;branch=z9hG4bK451045079 Record-Route: Record-Route: Call-ID: 215b1340-b89e-ab1a-4545-7244bffc205d From: ;tag=451023268 To: ;tag=AL0djXVhQ-2bhCl7KfmDaxTxf.Pjv-1O CSeq: 18795 INVITE Server: SylkServer-2.0.0-dev Contact: ;isfocus Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER Supported: 100rel, replaces, norefersub Content-Type: application/sdp Content-Length: 337 v=0 o=- 3554627367 3554627368 IN IP4 192.168.56.101 s=SylkServer-2.0.0-dev c=IN IP4 192.168.56.101 t=0 0 m=message 2855 TCP/MSRP * a=path:msrp://192.168.56.101:2855/dd5f443e85a4d99944db;tcp a=accept-types:message/cpim a=accept-wrapped-types:* a=setup:active a=chatroom:nickname private-messages com.ag-projects.screen-sharing -- ==> core_trace.txt <== 2012-08-22 14:29:27.614000 [sylk-server 10451] (5) tsx0x39a5db8: State changed from Proceeding to Completed, event=TX_MSG 2012-08-22 14:29:27.614000 [sylk-server 10451] (5) dlg0x39e1c38: Transaction tsx0x39a5db8 state changed to Completed 2012-08-22 14:29:27.623000 [sylk-server 10451] (5) sip_endpoint.c: Processing incoming message: Request msg ACK/cseq=18795 (rdata0x3079b88) ==> sip_trace.txt <== 2012-08-22 14:29:27.623987 [sylk-server 10451]: RECEIVED: Packet 18, +0:02:01.624726 10.226.20.240:6060 -(SIP over UDP)-> 192.168.56.101:5070 ACK sip:tihoparvi@192.168.56.101:5070 SIP/2.0 Via: SIP/2.0/UDP 10.226.20.240:6060;branch=0 Via: SIP/2.0/UDP 10.226.20.240:4060;branch=0 Via: SIP/2.0/UDP 10.226.20.23:2639;branch=z9hG4bK451043153;rport=2639 From: ;tag=451023268 To: ;tag=AL0djXVhQ-2bhCl7KfmDaxTxf.Pjv-1O Contact: ;+g.oma.sip-im;language="en,fr" Call-ID: 215b1340-b89e-ab1a-4545-7244bffc205d CSeq: 18795 ACK Content-Length: 0 Max-Forwards: 15 Subject: FIXME 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: -- ==> core_trace.txt <== 2012-08-22 14:29:27.624000 [sylk-server 10451] (5) dlg0x39e1c38: Received Request msg ACK/cseq=18795 (rdata0x3079b88) 2012-08-22 14:29:27.624000 [sylk-server 10451] (5) tsx0x39a5db8: Request to terminate transaction 2012-08-22 14:29:27.624000 [sylk-server 10451] (5) tsx0x39a5db8: State changed from Completed to Terminated, event=USER 2012-08-22 14:29:27.624000 [sylk-server 10451] (5) dlg0x39e1c38: Transaction tsx0x39a5db8 state changed to Terminated ==> notifications_trace.txt <== 2012-08-22 14:29:27.643797 [sylk-server 10451]: Notification name=SIPInvitationGotSDPUpdate sender= {'local_sdp': FrozenSDPSession('192.168.56.101', 3554627367L, 3554627368L, '-', 'IN', 'IP4', 'SylkServer-2.0.0-dev', None, FrozenSDPConnection('192.168.56.101', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('message', 2855, 'TCP/MSRP', 1, frozenlist(['*']), None, None, frozenlist([FrozenSDPAttribute('path', 'msrp://192.168.56.101:2855/dd5f443e85a4d99944db;tcp'), FrozenSDPAttribute('accept-types', 'message/cpim'), FrozenSDPAttribute('accept-wrapped-types', '*'), FrozenSDPAttribute('setup', 'active'), FrozenSDPAttribute('chatroom', 'nickname private-messages com.ag-projects.screen-sharing')]))])), 'remote_sdp': FrozenSDPSession('10.226.20.23', 1983L, 678901L, 'doubango', 'IN', 'IP4', '-', None, FrozenSDPConnection('10.226.20.23', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('message', 2641, 'TCP/MSRP', 0, frozenlist(['*']), None, FrozenSDPConnection('10.226.20.23', 'IN', 'IP4'), frozenlist([FrozenSDPAttribute('path', 'msrp://10.226.20.23:2641/451019577;tcp'), FrozenSDPAttribute('connection', 'new'), FrozenSDPAttribute('setup', 'actpass'), FrozenSDPAttribute('accept-types', 'text/plain message/CPIM'), FrozenSDPAttribute('accept-wrapped-types', 'text/plain image/jpeg image/gif image/bmp image/png'), FrozenSDPAttribute('sendrecv', '')]))])), 'succeeded': True, 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 624385)} 2012-08-22 14:29:27.645670 [sylk-server 10451]: Notification name=SIPInvitationChangedState sender= {'body': '', 'code': 200, 'headers': {'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE', 'REFER'], 'CSeq': (18795, 'INVITE'), 'Call-ID': FrozenHeader('Call-ID', '215b1340-b89e-ab1a-4545-7244bffc205d'), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.56.101', 'tihoparvi', None, 5070, False, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'isfocus': None}))], 'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '451023268'})), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('scscf.open-ims.test', 'mo', None, 6060, False, frozendict({'lr': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('pcscf.open-ims.test', 'mo', None, 4060, False, frozendict({'lr': 1}), frozendict({})), None, frozendict({}))], 'Server': FrozenHeader('Server', 'SylkServer-2.0.0-dev'), 'Supported': ['100rel', 'replaces', 'norefersub'], 'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': 'AL0djXVhQ-2bhCl7KfmDaxTxf.Pjv-1O'})), 'Via': [FrozenViaHeader('UDP', '10.226.20.240', 6060, frozendict({'received': '10.226.20.240', 'branch': 'z9hG4bK9012.425118c4.0'})), FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': 'z9hG4bK9012.c226c957.0'})), FrozenViaHeader('UDP', '10.226.20.23', 2639, frozendict({'rport': 2639, 'branch': 'z9hG4bK451045079'}))]}, 'originator': 'local', 'prev_state': 'incoming', 'reason': 'OK', 'state': 'connecting', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 624415)} 2012-08-22 14:29:27.649016 [sylk-server 10451]: Notification name=SIPInvitationChangedState sender= {'body': None, 'headers': {'Allow': ['INVITE', 'ACK', 'CANCEL', 'BYE', 'MESSAGE', 'OPTIONS', 'NOTIFY', 'PRACK', 'UPDATE', 'REFER'], 'CSeq': (18795, 'ACK'), 'Call-ID': FrozenHeader('Call-ID', '215b1340-b89e-ab1a-4545-7244bffc205d'), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.226.20.23', 'alice', None, 2639, False, frozendict({'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0', 'language': '"en,fr"', '+g.oma.sip-im': None}))], 'Content-Length': 0, 'From': FrozenFromHeader(FrozenSIPURI('open-ims.test', 'alice', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': '451023268'})), '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', ''), 'Privacy': FrozenHeader('Privacy', 'none'), 'Subject': FrozenSubjectHeader(u'FIXME'), 'To': FrozenToHeader(FrozenSIPURI('testing.com', 'tihoparvi', None, None, False, frozendict({}), frozendict({})), None, frozendict({'tag': 'AL0djXVhQ-2bhCl7KfmDaxTxf.Pjv-1O'})), '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': '0'})), FrozenViaHeader('UDP', '10.226.20.240', 4060, frozendict({'branch': '0'})), FrozenViaHeader('UDP', '10.226.20.23', 2639, frozendict({'rport': 2639, 'branch': 'z9hG4bK451043153'}))]}, 'method': 'ACK', 'originator': 'remote', 'prev_state': 'connecting', 'request_uri': FrozenSIPURI('192.168.56.101', 'tihoparvi', None, 5070, False, frozendict({}), frozendict({})), 'state': 'connected', 'sub_state': 'normal', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 624432)} 2012-08-22 14:29:27.649299 [sylk-server 10451]: Notification name=SIPSessionDidProcessTransaction sender= {'ack_received': True, 'code': 200, 'method': 'INVITE', 'originator': 'remote', 'reason': 'OK', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 632457)} 2012-08-22 14:29:27.649543 [sylk-server 10451]: Notification name=MSRPLibraryLog sender=UnknownSender {'level': INFO, 'message': 'Connecting to msrp://10.226.20.23:2641/451019577;tcp', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 633965)} 2012-08-22 14:29:27.649802 [sylk-server 10451]: Notification name=MSRPLibraryLog sender=UnknownSender {'level': INFO, 'message': 'Connected to 10.226.20.23:2641', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 637282)} 2012-08-22 14:29:27.650865 [sylk-server 10451]: Notification name=MediaStreamDidFail sender= {'context': 'start', 'failure': >, 'reason': '481 Chunk received while binding session: MSRP 451037071 SEND', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 641754)} 2012-08-22 14:29:27.651117 [sylk-server 10451]: Notification name=MSRPLibraryLog sender=UnknownSender {'level': INFO, 'message': 'Closed connection to 10.226.20.23:2641', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 642152)} 2012-08-22 14:29:27.651277 [sylk-server 10451]: Notification name=SIPSessionWillEnd sender= {'originator': 'local', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 646664)} 2012-08-22 14:29:27.653098 [sylk-server 10451]: Notification name=SIPSessionDidFail sender= {'code': 0, 'failure_reason': 'media stream failed: 481 Chunk received while binding session: MSRP 451037071 SEND', 'originator': 'local', 'reason': None, 'redirect_identities': None, 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 651817)} 2012-08-22 14:29:27.653272 [sylk-server 10451]: Notification name=MediaStreamWillEnd sender= {'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 651991)} 2012-08-22 14:29:27.653445 [sylk-server 10451]: Notification name=MediaStreamDidEnd sender= {'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 652014)} ==> core_trace.txt <== 2012-08-22 14:29:27.630000 [sylk-server 10451] (5) tsx0x39a5db8: Timeout timer event 2012-08-22 14:29:27.631000 [sylk-server 10451] (5) tsx0x39a5db8: State changed from Terminated to Destroyed, event=TIMER 2012-08-22 14:29:27.631000 [sylk-server 10451] (5) tdta0x39ded30: Destroying txdata Response msg 200/INVITE/cseq=18795 (tdta0x39ded30) 2012-08-22 14:29:27.631000 [sylk-server 10451] (5) tsx0x39a5db8: Transaction destroyed! 2012-08-22 14:29:27.646000 [sylk-server 10451] (5) endpoint: Request msg BYE/cseq=30483 (tdta0x3978540) created. 2012-08-22 14:29:27.647000 [sylk-server 10451] (5) inv0x39e1c38: Sending Request msg BYE/cseq=30483 (tdta0x3978540) 2012-08-22 14:29:27.647000 [sylk-server 10451] (5) dlg0x39e1c38: Sending Request msg BYE/cseq=30483 (tdta0x3978540) 2012-08-22 14:29:27.647000 [sylk-server 10451] (5) tsx0x39a5db8: Transaction created for Request msg BYE/cseq=30482 (tdta0x3978540) 2012-08-22 14:29:27.648000 [sylk-server 10451] (5) tsx0x39a5db8: Sending Request msg BYE/cseq=30482 (tdta0x3978540) in state Null 2012-08-22 14:29:27.648000 [sylk-server 10451] (5) sip_resolve.c: Starting async DNS A query: target=scscf.open-ims.test, transport=Unspecified, port=6060 2012-08-22 14:29:27.648000 [sylk-server 10451] (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 14:29:27.648000 [sylk-server 10451] (2) tsx0x39a5db8: Failed to send Request msg BYE/cseq=30482 (tdta0x3978540)! err=320045 (No nameserver is in DNS resolver (PJLIB_UTIL_EDNSNONS)) 2012-08-22 14:29:27.648000 [sylk-server 10451] (5) tsx0x39a5db8: State changed from Null to Terminated, event=TRANSPORT_ERROR 2012-08-22 14:29:27.648000 [sylk-server 10451] (5) dlg0x39e1c38: Transaction tsx0x39a5db8 state changed to Terminated 2012-08-22 14:29:27.651000 [sylk-server 10451] (5) dlg0x39e1c38: Session count dec to 2 by mod-invite 2012-08-22 14:29:27.651000 [sylk-server 10451] (5) dlg0x39e1c38: Dialog destroyed ==> notifications_trace.txt <== 2012-08-22 14:29:27.755846 [sylk-server 10451]: Notification name=SIPInvitationChangedState sender= {'disconnect_reason': 'user request', 'originator': 'local', 'prev_state': 'connected', 'prev_sub_state': 'normal', 'state': 'disconnected', 'timestamp': datetime.datetime(2012, 8, 22, 14, 29, 27, 731647)} ==> core_trace.txt <== 2012-08-22 14:29:27.753000 [sylk-server 10451] (5) tsx0x39a5db8: Timeout timer event 2012-08-22 14:29:27.753000 [sylk-server 10451] (5) tsx0x39a5db8: State changed from Terminated to Destroyed, event=TIMER 2012-08-22 14:29:27.753000 [sylk-server 10451] (5) tdta0x3978540: Destroying txdata Request msg BYE/cseq=30482 (tdta0x3978540) 2012-08-22 14:29:27.753000 [sylk-server 10451] (5) tsx0x39a5db8: Transaction destroyed!