Hi Ying, And here is the debug log when the UE (Arris eDVA) on 6505550745 attempts an outgoing call. Registration debug follows below. Thanks! Roger
11-01-2018 21:16:01.038 UTC Verbose pjsip: tcplis:5060 TCP listener cw-aio:5060: got incoming TCP connection from 10.237.15.136:58560, sock=148 11-01-2018 21:16:01.038 UTC Verbose pjsip: tcps0x7f36e010 tcp->base.local_name: cw-aio 11-01-2018 21:16:01.038 UTC Verbose pjsip: tcps0x7f36e010 TCP server transport created 11-01-2018 21:16:01.055 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=1 (rdata0x7f36e0105c00) 11-01-2018 21:16:01.055 UTC Verbose common_sip_processing.cpp:120: RX 1168 bytes Request msg INVITE/cseq=1 (rdata0x7f36e0105c00) from TCP 10.237.15.136:58560: --start msg-- INVITE sip:[email protected];user=phone SIP/2.0 From: <sip:[email protected]:5060>;tag=472618-aed0f88-13c4-50029-5a575562-15aaac23-5a575562 To: <sip:[email protected];user=phone> Call-ID: 475b38-aed0f88-13c4-50029-5a575562-fdab92d-5a575562 CSeq: 1 INVITE Via: SIP/2.0/TCP 10.237.15.136:5060;branch=z9hG4bK-5a575562-e525889c-1f65b70 P-Preferred-Identity: <sip:[email protected];user=phone> Max-Forwards: 70 Supported: timer,replaces,join,tdialog,100rel,histinfo,path User-Agent: ARRIS-TM822G release v.9.1.103S5P.SIP.PC20 SN/001DD5F31A69 Contact: <sip:[email protected]:5060;user=phone> Session-Expires: 1800;refresher=uac Min-SE: 90 Allow: INVITE,ACK,BYE,CANCEL,NOTIFY,PRACK,UPDATE,OPTIONS Route: <sip:10.237.20.101:5060> Route: <sip:scscf.cw-aio:5054;transport=TCP;lr;orig> Content-Type: application/sdp Content-Length: 294 v=0 o=- 103984729 103984729 IN IP4 10.237.15.136 s=- c=IN IP4 10.237.15.136 t=0 0 m=audio 52646 RTP/AVP 9 0 8 101 b=AS:80 b=TIAS:64000 a=ptime:20 a=sendrecv a=rtpmap:101 telephone-event/16000 a=fmtp:101 0-15 a=maxprate:50 a=rtcp-xr:voip-metrics a=sqn:0 a=cdsc:1 image udptl t38 --end msg-- 11-01-2018 21:16:01.055 UTC Debug pjutils.cpp:1689: Logging SAS Call-ID marker, Call-ID 475b38-aed0f88-13c4-50029-5a575562-fdab92d-5a575562 11-01-2018 21:16:01.055 UTC Debug thread_dispatcher.cpp:264: Queuing cloned received message 0x7f36e0109118 for worker threads 11-01-2018 21:16:01.055 UTC Debug thread_dispatcher.cpp:150: Worker thread dequeue message 0x7f36e0109118 11-01-2018 21:16:01.055 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7f36e0109118) 11-01-2018 21:16:01.055 UTC Debug uri_classifier.cpp:174: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:16:01.055 UTC Debug uri_classifier.cpp:204: Classified URI as 2 11-01-2018 21:16:01.055 UTC Debug bono.cpp:278: Proxy RX request 11-01-2018 21:16:01.055 UTC Debug pjutils.cpp:699: Cloned Request msg INVITE/cseq=1 (rdata0x7f36e0109118) to tdta0x7f36d801f520 11-01-2018 21:16:01.055 UTC Debug bono.cpp:817: Request received on non-trusted port 5060 11-01-2018 21:16:01.055 UTC Debug bono.cpp:1057: Perform access proxy routing for INVITE request 11-01-2018 21:16:01.055 UTC Debug uri_classifier.cpp:174: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:16:01.055 UTC Debug uri_classifier.cpp:204: Classified URI as 3 11-01-2018 21:16:01.055 UTC Debug pjutils.cpp:509: Found Route header, URI = sip:10.237.20.101:5060 11-01-2018 21:16:01.055 UTC Debug pjutils.cpp:513: Route header is local 11-01-2018 21:16:01.055 UTC Debug uri_classifier.cpp:174: home domain: false, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:16:01.055 UTC Debug uri_classifier.cpp:204: Classified URI as 5 11-01-2018 21:16:01.055 UTC Debug pjutils.cpp:509: Found Route header, URI = sip:scscf.cw-aio:5054;transport=TCP;lr;orig 11-01-2018 21:16:01.055 UTC Debug bono.cpp:1194: Message received on non-trusted port 5060 11-01-2018 21:16:01.055 UTC Debug flowtable.cpp:136: Find flow for transport tcps0x7f36e01058c8 (2), remote address 10.237.15.136:58560 11-01-2018 21:16:01.055 UTC Info bono.cpp:1384: Rejecting request from untrusted source 11-01-2018 21:16:01.055 UTC Debug acr.cpp:49: Created ACR (0x7f36d8006b30) 11-01-2018 21:16:01.055 UTC Info bono.cpp:771: Reject INVITE request with 403 status code 11-01-2018 21:16:01.056 UTC Debug pjsip: endpoint Response msg 403/INVITE/cseq=1 (tdta0x7f36d8006cb0) created 11-01-2018 21:16:01.056 UTC Verbose common_sip_processing.cpp:136: TX 401 bytes Response msg 403/INVITE/cseq=1 (tdta0x7f36d8006cb0) to TCP 10.237.15.136:58560: --start msg-- SIP/2.0 403 Forbidden Via: SIP/2.0/TCP 10.237.15.136:5060;received=10.237.15.136;branch=z9hG4bK-5a575562-e525889c-1f65b70 Call-ID: 475b38-aed0f88-13c4-50029-5a575562-fdab92d-5a575562 From: <sip:[email protected]>;tag=472618-aed0f88-13c4-50029-5a575562-15aaac23-5a575562 To: <sip:[email protected];user=phone>;tag=z9hG4bK-5a575562-e525889c-1f65b70 CSeq: 1 INVITE Content-Length: 0 --end msg-- 11-01-2018 21:16:01.056 UTC Debug pjsip: tdta0x7f36d800 Destroying txdata Response msg 403/INVITE/cseq=1 (tdta0x7f36d8006cb0) 11-01-2018 21:16:01.056 UTC Debug acr.cpp:83: Sending Null ACR (0x7f36d8006b30) 11-01-2018 21:16:01.056 UTC Debug acr.cpp:54: Destroyed ACR (0x7f36d8006b30) 11-01-2018 21:16:01.056 UTC Debug pjsip: tdta0x7f36d801 Destroying txdata Request msg INVITE/cseq=1 (tdta0x7f36d801f520) 11-01-2018 21:16:01.056 UTC Debug thread_dispatcher.cpp:200: Worker thread completed processing message 0x7f36e0109118 11-01-2018 21:16:01.056 UTC Debug thread_dispatcher.cpp:206: Request latency = 567us 11-01-2018 21:16:01.095 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=1 (rdata0x7f36e0105c00) 11-01-2018 21:16:01.095 UTC Verbose common_sip_processing.cpp:120: RX 555 bytes Request msg ACK/cseq=1 (rdata0x7f36e0105c00) from TCP 10.237.15.136:58560: --start msg-- ACK sip:[email protected];user=phone SIP/2.0 From: <sip:[email protected]:5060>;tag=472618-aed0f88-13c4-50029-5a575562-15aaac23-5a575562 To: <sip:[email protected];user=phone>;tag=z9hG4bK-5a575562-e525889c-1f65b70 Call-ID: 475b38-aed0f88-13c4-50029-5a575562-fdab92d-5a575562 CSeq: 1 ACK Via: SIP/2.0/TCP 10.237.15.136:5060;branch=z9hG4bK-5a575562-e525889c-1f65b70 Max-Forwards: 70 User-Agent: ARRIS-TM822G release v.9.1.103S5P.SIP.PC20 SN/001DD5F31A69 Contact: <sip:[email protected]:5060;user=phone> Content-Length: 0 --end msg-- 11-01-2018 21:16:01.095 UTC Debug pjutils.cpp:1689: Logging SAS Call-ID marker, Call-ID 475b38-aed0f88-13c4-50029-5a575562-fdab92d-5a575562 11-01-2018 21:16:01.095 UTC Debug thread_dispatcher.cpp:264: Queuing cloned received message 0x7f36e0108168 for worker threads 11-01-2018 21:16:01.095 UTC Debug thread_dispatcher.cpp:150: Worker thread dequeue message 0x7f36e0108168 11-01-2018 21:16:01.095 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=1 (rdata0x7f36e0108168) 11-01-2018 21:16:01.095 UTC Debug uri_classifier.cpp:174: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:16:01.095 UTC Debug uri_classifier.cpp:204: Classified URI as 2 11-01-2018 21:16:01.095 UTC Debug bono.cpp:278: Proxy RX request 11-01-2018 21:16:01.095 UTC Debug pjutils.cpp:699: Cloned Request msg ACK/cseq=1 (rdata0x7f36e0108168) to tdta0x7f36d801f520 11-01-2018 21:16:01.095 UTC Debug bono.cpp:817: Request received on non-trusted port 5060 11-01-2018 21:16:01.095 UTC Debug bono.cpp:1057: Perform access proxy routing for ACK request 11-01-2018 21:16:01.095 UTC Debug bono.cpp:1194: Message received on non-trusted port 5060 11-01-2018 21:16:01.095 UTC Debug flowtable.cpp:136: Find flow for transport tcps0x7f36e01058c8 (2), remote address 10.237.15.136:58560 11-01-2018 21:16:01.095 UTC Info bono.cpp:1384: Rejecting request from untrusted source 11-01-2018 21:16:01.095 UTC Debug acr.cpp:49: Created ACR (0x7f36d8006b30) 11-01-2018 21:16:01.096 UTC Debug acr.cpp:83: Sending Null ACR (0x7f36d8006b30) 11-01-2018 21:16:01.096 UTC Debug acr.cpp:54: Destroyed ACR (0x7f36d8006b30) 11-01-2018 21:16:01.096 UTC Debug pjsip: tdta0x7f36d801 Destroying txdata Request msg ACK/cseq=1 (tdta0x7f36d801f520) 11-01-2018 21:16:01.096 UTC Debug thread_dispatcher.cpp:200: Worker thread completed processing message 0x7f36e0108168 11-01-2018 21:16:01.096 UTC Debug thread_dispatcher.cpp:206: Request latency = 394us 11-01-2018 21:16:01.106 UTC Verbose pjsip: tcps0x7f36e010 TCP connection closed 11-01-2018 21:16:01.107 UTC Status connection_tracker.cpp:92: Connection 0x7f36e01058c8 has been destroyed 11-01-2018 21:16:01.107 UTC Verbose pjsip: tcps0x7f36e010 TCP transport destroyed with reason 70016: End of file (PJ_EEOF) 11-01-2018 21:16:01.458 UTC Verbose pjsip: tcps0x7f36e01e TCP connection closed 11-01-2018 21:16:01.458 UTC Status connection_tracker.cpp:92: Connection 0x7f36e01e4ed8 has been destroyed 11-01-2018 21:16:01.458 UTC Verbose pjsip: tcps0x7f36e01e TCP transport destroyed with reason 70016: End of file (PJ_EEOF) ############################## Registration of 6505550745: 11-01-2018 21:28:27.761 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=1726 (rdata0x7f36e0105c00) 11-01-2018 21:28:27.761 UTC Verbose common_sip_processing.cpp:120: RX 938 bytes Request msg REGISTER/cseq=1726 (rdata0x7f36e0105c00) from TCP 10.237.15.136:36754: --start msg-- REGISTER sip:example.com SIP/2.0 From: <sip:[email protected]:5060>;tag=470ef0-aed0f88-13c4-50029-5a555eb9-40adda66-5a555eb9 To: <sip:[email protected]:5060> Call-ID: 478378-aed0f88-13c4-50029-5a555eb9-3667940-5a555eb9 CSeq: 1726 REGISTER Via: SIP/2.0/TCP 10.237.15.136:5060;branch=z9hG4bK-5a57584d-e530ed72-6696d8d Max-Forwards: 70 Supported: timer,replaces,join,tdialog,100rel,histinfo,path User-Agent: ARRIS-TM822G release v.9.1.103S5P.SIP.PC20 SN/001DD5F31A69 Authorization: Digest username="[email protected]<mailto:[email protected]>",realm="example.com",nonce="7aed3cde60bca4f0",uri="sip:example.com",response="402b48d7a9645a922aca71ac2ca09e7d",algorithm=MD5,cnonce="e530ed72",opaque="6d7a8a5f509faace",qop=auth,nc=00000001 Contact: <sip:[email protected]:5060>;expires=3600 Allow: INVITE,ACK,BYE,CANCEL,NOTIFY,PRACK,UPDATE,OPTIONS Allow-Events: vq-rtcpxr Route: <sip:10.237.20.101;transport=udp;lr> Content-Length: 0 --end msg-- 11-01-2018 21:28:27.761 UTC Debug pjutils.cpp:1689: Logging SAS Call-ID marker, Call-ID 478378-aed0f88-13c4-50029-5a555eb9-3667940-5a555eb9 11-01-2018 21:28:27.761 UTC Debug thread_dispatcher.cpp:264: Queuing cloned received message 0x7f36e0024638 for worker threads 11-01-2018 21:28:27.761 UTC Debug thread_dispatcher.cpp:150: Worker thread dequeue message 0x7f36e0024638 11-01-2018 21:28:27.761 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=1726 (rdata0x7f36e0024638) 11-01-2018 21:28:27.761 UTC Debug uri_classifier.cpp:174: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:28:27.761 UTC Debug uri_classifier.cpp:204: Classified URI as 4 11-01-2018 21:28:27.761 UTC Debug bono.cpp:278: Proxy RX request 11-01-2018 21:28:27.762 UTC Debug pjutils.cpp:699: Cloned Request msg REGISTER/cseq=1726 (rdata0x7f36e0024638) to tdta0x7f36d803b360 11-01-2018 21:28:27.762 UTC Debug bono.cpp:817: Request received on non-trusted port 5060 11-01-2018 21:28:27.762 UTC Debug bono.cpp:1057: Perform access proxy routing for REGISTER request 11-01-2018 21:28:27.762 UTC Debug bono.cpp:1094: Message requires outbound support 11-01-2018 21:28:27.762 UTC Debug flowtable.cpp:90: Find or create flow for transport tcps0x7f36e01058c8 (2), remote address 10.237.15.136:36754 11-01-2018 21:28:27.762 UTC Debug flowtable.cpp:293: Added transport listener for flow 0x7f36d803c990 11-01-2018 21:28:27.762 UTC Debug flowtable.cpp:105: Added flow record 0x7f36d803c990 11-01-2018 21:28:27.762 UTC Debug flowtable.cpp:232: Reporting current flow count: 7 11-01-2018 21:28:27.762 UTC Debug flowtable.cpp:599: Dialog count now 2 for flow 11-01-2018 21:28:27.762 UTC Debug bono.cpp:1106: Found or created flow data record, token = 3ptyUGaJM/ 11-01-2018 21:28:27.762 UTC Info pjutils.cpp:389: Adding integrity-protected=ip-assoc-pending indicator to message 11-01-2018 21:28:27.762 UTC Debug flowtable.cpp:616: Dialog count now 1 for flow 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:174: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:204: Classified URI as 4 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:174: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:204: Classified URI as 3 11-01-2018 21:28:27.762 UTC Debug pjutils.cpp:509: Found Route header, URI = sip:10.237.20.101;transport=udp;lr 11-01-2018 21:28:27.762 UTC Debug pjutils.cpp:513: Route header is local 11-01-2018 21:28:27.762 UTC Debug bono.cpp:1015: Mark originating 11-01-2018 21:28:27.762 UTC Info bono.cpp:1036: Route request to upstream proxy sip:scscf.cw-aio:5052;transport=TCP;lr;orig 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:174: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:204: Classified URI as 4 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:174: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:204: Classified URI as 3 11-01-2018 21:28:27.762 UTC Debug pjutils.cpp:509: Found Route header, URI = sip:10.237.20.101;transport=udp;lr 11-01-2018 21:28:27.762 UTC Debug pjutils.cpp:513: Route header is local 11-01-2018 21:28:27.762 UTC Debug bono.cpp:1604: Top Route header is local - erasing 11-01-2018 21:28:27.762 UTC Debug acr.cpp:49: Created ACR (0x7f36d8006bd0) 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:174: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 11-01-2018 21:28:27.762 UTC Debug uri_classifier.cpp:204: Classified URI as 4 11-01-2018 21:28:27.762 UTC Debug bono.cpp:486: Trust mode INBOUND_EDGE_CLIENT(,-rsp,-pch), serving state None 11-01-2018 21:28:27.762 UTC Debug pjsip: tsx0x7f36d8089 Transaction created for Request msg REGISTER/cseq=1726 (rdata0x7f36e0024638) 11-01-2018 21:28:27.762 UTC Debug bono.cpp:1786: UASTransaction constructor (0x7f36d8042e20) 11-01-2018 21:28:27.762 UTC Debug bono.cpp:1787: ACR (0x7f36d8006bd0) 11-01-2018 21:28:27.762 UTC Debug pjsip: tsx0x7f36d8089 Incoming Request msg REGISTER/cseq=1726 (rdata0x7f36e0024638) in state Null 11-01-2018 21:28:27.762 UTC Debug pjsip: tsx0x7f36d8089 State changed from Null to Trying, event=RX_MSG 11-01-2018 21:28:27.762 UTC Debug bono.cpp:390: tsx0x7f36d8089098 - tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying 11-01-2018 21:28:27.762 UTC Debug pjsip: endpoint Response msg 408/REGISTER/cseq=1726 (tdta0x7f36d809e880) created 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2418: Report SAS start marker - trail (b6) 11-01-2018 21:28:27.762 UTC Debug trustboundary.cpp:69: Add P-Charging headers 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2492: Allocating transaction and data for target 0 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2749: Stripping loose routes from proxied message 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2776: Adding a Route header to sip:scscf.cw-aio:5052;transport=TCP 11-01-2018 21:28:27.762 UTC Debug pjsip: tsx0x7f36d8037 Transaction created for Request msg REGISTER/cseq=1726 (tdta0x7f36d8027870) 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2519: Adding trail identifier 182 to UAC transaction 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2538: Updating request URI and route for target 0 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2844: Transport tcpc0x7f36d809d098 (TCP to 10.237.20.101:5052) pre-selected for transaction 11-01-2018 21:28:27.762 UTC Debug bono.cpp:2862: Sending request for sip:example.com 11-01-2018 21:28:27.762 UTC Debug pjsip: tsx0x7f36d8037 Sending Request msg REGISTER/cseq=1726 (tdta0x7f36d8027870) in state Null 11-01-2018 21:28:27.762 UTC Debug pjsip: endpoint Request msg REGISTER/cseq=1726 (tdta0x7f36d8027870): skipping target resolution because address is already set 11-01-2018 21:28:27.762 UTC Verbose common_sip_processing.cpp:136: TX 1210 bytes Request msg REGISTER/cseq=1726 (tdta0x7f36d8027870) to TCP 10.237.20.101:5052: --start msg-- REGISTER sip:example.com SIP/2.0 Via: SIP/2.0/TCP 10.237.20.101:5058;rport;branch=z9hG4bKPjY-uiB2yim8VSRPwMd7oV-5M7Zdr4xerU Path: <sip:3ptyUGaJM/@10.237.20.101:5058;transport=TCP;lr;ob> From: <sip:[email protected]>;tag=470ef0-aed0f88-13c4-50029-5a555eb9-40adda66-5a555eb9 To: <sip:[email protected]> Call-ID: 478378-aed0f88-13c4-50029-5a555eb9-3667940-5a555eb9 CSeq: 1726 REGISTER Via: SIP/2.0/TCP 10.237.15.136:5060;received=10.237.15.136;branch=z9hG4bK-5a57584d-e530ed72-6696d8d Max-Forwards: 70 Supported: timer, replaces, join, tdialog, 100rel, histinfo, path User-Agent: ARRIS-TM822G release v.9.1.103S5P.SIP.PC20 SN/001DD5F31A69 Authorization: Digest response="402b48d7a9645a922aca71ac2ca09e7d", username="[email protected]<mailto:[email protected]>", realm="example.com", nonce="7aed3cde60bca4f0", uri="sip:example.com", algorithm=MD5, cnonce="e530ed72", opaque="6d7a8a5f509faace", qop=auth, nc=00000001,integrity-protected=ip-assoc-pending Contact: <sip:[email protected]:5060>;expires=3600 Allow: INVITE, ACK, BYE, CANCEL, NOTIFY, PRACK, UPDATE, OPTIONS Allow-Events: vq-rtcpxr P-Visited-Network-ID: example.com Route: <sip:scscf.cw-aio:5052;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 11-01-2018 21:28:27.764 UTC Debug pjsip: tsx0x7f36d8037 State changed from Null to Calling, event=TX_MSG 11-01-2018 21:28:27.764 UTC Debug bono.cpp:390: tsx0x7f36d8037de8 - tu_on_tsx_state UAC, TSX_STATE TX_MSG state=Calling 11-01-2018 21:28:27.764 UTC Debug bono.cpp:2962: tsx0x7f36d8037de8 - uac_data = 0x7f36d803cd20, uas_data = 0x7f36d8042e20 11-01-2018 21:28:27.764 UTC Debug thread_dispatcher.cpp:200: Worker thread completed processing message 0x7f36e0024638 11-01-2018 21:28:27.764 UTC Debug thread_dispatcher.cpp:206: Request latency = 2476us 11-01-2018 21:28:27.768 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=1726 (rdata0x7f36d809d3d0) 11-01-2018 21:28:27.768 UTC Verbose common_sip_processing.cpp:120: RX 787 bytes Response msg 200/REGISTER/cseq=1726 (rdata0x7f36d809d3d0) from TCP 10.237.20.101:5052: --start msg-- SIP/2.0 200 OK Service-Route: <sip:scscf.cw-aio:5054;transport=TCP;lr;orig> Via: SIP/2.0/TCP 10.237.20.101:5058;rport=59420;received=10.237.20.101;branch=z9hG4bKPjY-uiB2yim8VSRPwMd7oV-5M7Zdr4xerU Via: SIP/2.0/TCP 10.237.15.136:5060;received=10.237.15.136;branch=z9hG4bK-5a57584d-e530ed72-6696d8d Call-ID: 478378-aed0f88-13c4-50029-5a555eb9-3667940-5a555eb9 From: <sip:[email protected]>;tag=470ef0-aed0f88-13c4-50029-5a555eb9-40adda66-5a555eb9 To: <sip:[email protected]>;tag=z9hG4bKPjY-uiB2yim8VSRPwMd7oV-5M7Zdr4xerU CSeq: 1726 REGISTER Supported: outbound Contact: <sip:[email protected]:5060>;expires=300 Require: outbound Path: <sip:3ptyUGaJM/@10.237.20.101:5058;transport=TCP;lr;ob> P-Associated-URI: <sip:[email protected]> Content-Length: 0 --end msg-- 11-01-2018 21:28:27.768 UTC Debug thread_dispatcher.cpp:264: Queuing cloned received message 0x7f36e0024638 for worker threads 11-01-2018 21:28:27.768 UTC Debug thread_dispatcher.cpp:150: Worker thread dequeue message 0x7f36e0024638 11-01-2018 21:28:27.768 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/REGISTER/cseq=1726 (rdata0x7f36e0024638) 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8037 Incoming Response msg 200/REGISTER/cseq=1726 (rdata0x7f36e0024638) in state Calling 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8037 State changed from Calling to Completed, event=RX_MSG 11-01-2018 21:28:27.768 UTC Debug bono.cpp:390: tsx0x7f36d8037de8 - tu_on_tsx_state UAC, TSX_STATE RX_MSG state=Completed 11-01-2018 21:28:27.768 UTC Debug bono.cpp:2962: tsx0x7f36d8037de8 - uac_data = 0x7f36d803cd20, uas_data = 0x7f36d8042e20 11-01-2018 21:28:27.768 UTC Debug bono.cpp:3001: tsx0x7f36d8037de8 - RX_MSG on active UAC transaction 11-01-2018 21:28:27.768 UTC Debug flowtable.cpp:164: Find flow for flow token 3ptyUGaJM/ 11-01-2018 21:28:27.768 UTC Debug flowtable.cpp:599: Dialog count now 2 for flow 11-01-2018 21:28:27.768 UTC Debug flowtable.cpp:177: Found flow record 0x7f36d803c990 11-01-2018 21:28:27.768 UTC Debug bono.cpp:1694: Maximum contact expiry is 300 11-01-2018 21:28:27.768 UTC Debug bono.cpp:1720: Found P-Associated-URI header 11-01-2018 21:28:27.768 UTC Debug flowtable.cpp:413: Setting identity sip:[email protected] on flow 0x7f36d803c990, expires = 300 11-01-2018 21:28:27.768 UTC Debug flowtable.cpp:616: Dialog count now 1 for flow sip:[email protected] 11-01-2018 21:28:27.768 UTC Debug trustboundary.cpp:57: Strip trusted headers 11-01-2018 21:28:27.768 UTC Debug bono.cpp:2194: tsx0x7f36d8037de8 - Final response, so disconnect UAS and UAC transactions 11-01-2018 21:28:27.768 UTC Debug pjsip: tdta0x7f36d809 Destroying txdata Response msg 408/REGISTER/cseq=1726 (tdta0x7f36d809e880) 11-01-2018 21:28:27.768 UTC Debug bono.cpp:2629: Dissociate UAC transaction 0x7f36d803cd20 (0) 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8089 Sending Response msg 200/REGISTER/cseq=1726 (tdta0x7f36d80296a0) in state Trying 11-01-2018 21:28:27.768 UTC Verbose common_sip_processing.cpp:136: TX 666 bytes Response msg 200/REGISTER/cseq=1726 (tdta0x7f36d80296a0) to TCP 10.237.15.136:36754: --start msg-- SIP/2.0 200 OK Service-Route: <sip:scscf.cw-aio:5054;transport=TCP;lr;orig> Via: SIP/2.0/TCP 10.237.15.136:5060;received=10.237.15.136;branch=z9hG4bK-5a57584d-e530ed72-6696d8d Call-ID: 478378-aed0f88-13c4-50029-5a555eb9-3667940-5a555eb9 From: <sip:[email protected]>;tag=470ef0-aed0f88-13c4-50029-5a555eb9-40adda66-5a555eb9 To: <sip:[email protected]>;tag=z9hG4bKPjY-uiB2yim8VSRPwMd7oV-5M7Zdr4xerU CSeq: 1726 REGISTER Supported: outbound Contact: <sip:[email protected]:5060>;expires=300 Require: outbound Path: <sip:3ptyUGaJM/@10.237.20.101:5058;transport=TCP;lr;ob> P-Associated-URI: <sip:[email protected]> Content-Length: 0 --end msg-- 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8089 State changed from Trying to Completed, event=TX_MSG 11-01-2018 21:28:27.768 UTC Debug bono.cpp:390: tsx0x7f36d8089098 - tu_on_tsx_state UAS, TSX_STATE TX_MSG state=Completed 11-01-2018 21:28:27.768 UTC Debug bono.cpp:817: Request received on non-trusted port 5060 11-01-2018 21:28:27.768 UTC Debug bono.cpp:2427: Report SAS end marker - trail (b6) 11-01-2018 21:28:27.768 UTC Debug thread_dispatcher.cpp:200: Worker thread completed processing message 0x7f36e0024638 11-01-2018 21:28:27.768 UTC Debug thread_dispatcher.cpp:206: Request latency = 281us 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8037 Timeout timer event 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8037 State changed from Completed to Terminated, event=TIMER 11-01-2018 21:28:27.768 UTC Debug bono.cpp:390: tsx0x7f36d8037de8 - tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated 11-01-2018 21:28:27.768 UTC Debug bono.cpp:2962: tsx0x7f36d8037de8 - uac_data = 0x7f36d803cd20, uas_data = (nil) 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8089 Timeout timer event 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8089 State changed from Completed to Terminated, event=TIMER 11-01-2018 21:28:27.768 UTC Debug bono.cpp:390: tsx0x7f36d8089098 - tu_on_tsx_state UAS, TSX_STATE TIMER state=Terminated 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8037 Timeout timer event 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8037 State changed from Terminated to Destroyed, event=TIMER 11-01-2018 21:28:27.768 UTC Debug bono.cpp:390: tsx0x7f36d8037de8 - tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed 11-01-2018 21:28:27.768 UTC Debug bono.cpp:2962: tsx0x7f36d8037de8 - uac_data = 0x7f36d803cd20, uas_data = (nil) 11-01-2018 21:28:27.768 UTC Debug bono.cpp:3049: tsx0x7f36d8037de8 - UAC tsx destroyed 11-01-2018 21:28:27.768 UTC Debug pjsip: tdta0x7f36d802 Destroying txdata Request msg REGISTER/cseq=1726 (tdta0x7f36d8027870) 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8089 Timeout timer event 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8089 State changed from Terminated to Destroyed, event=TIMER 11-01-2018 21:28:27.768 UTC Debug bono.cpp:390: tsx0x7f36d8089098 - tu_on_tsx_state UAS, TSX_STATE TIMER state=Destroyed 11-01-2018 21:28:27.768 UTC Debug bono.cpp:2276: tsx0x7f36d8089098 - UAS tsx destroyed 11-01-2018 21:28:27.768 UTC Debug bono.cpp:1831: UASTransaction destructor (0x7f36d8042e20) 11-01-2018 21:28:27.768 UTC Debug bono.cpp:1851: Disconnect UAC transactions from UAS transaction 11-01-2018 21:28:27.768 UTC Debug bono.cpp:1897: Upstream ACR = 0x7f36d8006bd0, Downstream ACR = 0x7f36d8006bd0 11-01-2018 21:28:27.768 UTC Debug acr.cpp:83: Sending Null ACR (0x7f36d8006bd0) 11-01-2018 21:28:27.768 UTC Debug acr.cpp:54: Destroyed ACR (0x7f36d8006bd0) 11-01-2018 21:28:27.768 UTC Debug bono.cpp:1922: Free original request (0x7f36d803b408) 11-01-2018 21:28:27.768 UTC Debug pjsip: tdta0x7f36d803 Destroying txdata Request msg REGISTER/cseq=1726 (tdta0x7f36d803b360) 11-01-2018 21:28:27.768 UTC Debug bono.cpp:1938: UASTransaction destructor completed 11-01-2018 21:28:27.768 UTC Debug pjsip: tdta0x7f36d802 Destroying txdata Response msg 200/REGISTER/cseq=1726 (tdta0x7f36d80296a0) 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8089 Transaction destroyed! 11-01-2018 21:28:27.768 UTC Debug pjsip: tsx0x7f36d8037 Transaction destroyed! 11-01-2018 21:28:27.792 UTC Verbose pjsip: tcps0x7f36e010 TCP connection closed 11-01-2018 21:28:27.792 UTC Debug flowtable.cpp:652: Transport state changed for flow 0x7f36d803c990, state = 1 11-01-2018 21:28:27.792 UTC Debug flowtable.cpp:205: Remove flow 0x7f36d803c990 11-01-2018 21:28:27.792 UTC Debug flowtable.cpp:232: Reporting current flow count: 6 11-01-2018 21:28:27.792 UTC Debug flowtable.cpp:197: Checked quiescing state: flow_map is not empty, is_quiescing() result is false, _qm (QuiescingManager reference) is not NULL 11-01-2018 21:28:27.793 UTC Status connection_tracker.cpp:92: Connection 0x7f36e01058c8 has been destroyed 11-01-2018 21:28:27.793 UTC Verbose pjsip: tcps0x7f36e010 TCP transport destroyed with reason 70016: End of file (PJ_EEOF)
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
