Hi Tahir, This looks like a problem with the ACK not being sent correctly. However, the detailed Bono logs you sent don't cover the whole call, so I can't see from them whether the caller is just not sending an ACK at all, or if Bono is rejecting the ACK.
Can you please check whether the caller is sending ACKs, and also please send debug Bono logs for the whole call? Ellie From: Tahir Masood [mailto:[email protected]] Sent: 18 February 2016 05:25 To: Eleanor Merry; [email protected] Subject: RE: [Clearwater] Call disconnects after 30 seconds Hi Ellie Detailed Bono logs are also attached Regards, Tahir Masood From: Tahir Masood [mailto:[email protected]] Sent: Thursday, February 18, 2016 10:08 AM To: 'Eleanor Merry'; '[email protected]' Subject: RE: [Clearwater] Call disconnects after 30 seconds Hi Ellie Here are the attached sprout logs the deployment method is manual in OpenStack environment Regards, Tahir Masood From: Eleanor Merry [mailto:[email protected]] Sent: Wednesday, February 17, 2016 7:32 PM To: Tahir Masood; [email protected]<mailto:[email protected]> Subject: RE: [Clearwater] Call disconnects after 30 seconds Hi Tahir, How have you set up your deployment? Is it a manual install/all-in-one install/etc..? Also, can you please send me over the full debug logs from Sprout and Bono (the logs you've pasted in below don't have an INVITE in them)? Thanks, Ellie From: Clearwater [mailto:[email protected]] On Behalf Of Tahir Masood Sent: 17 February 2016 13:04 To: [email protected]<mailto:[email protected]> Subject: [Clearwater] Call disconnects after 30 seconds Dear all, I am facing an issue of call disconnection after 30 seconds have used both Xlite and Zoiper but the problem persists. I have change the log_level to 5 in sprout and here are the logs. Can you please suggest me a solution 17-02-2016 12:59:42.374 UTC Debug pjsip: sip_endpoint.c Processing incoming mess age: Request msg OPTIONS/cseq=97398 (rdata0x7ff14c06fb50) 17-02-2016 12:59:42.374 UTC Verbose common_sip_processing.cpp:120: RX 342 bytes Request msg OPTIONS/cseq=97398 (rdata0x7ff14c06fb50) from TCP 192.168.0.6:50982: --start msg-- OPTIONS sip:[email protected]:5054 SIP/2.0 Via: SIP/2.0/TCP 192.168.0.6;rport;branch=z9hG4bK-97398 Max-Forwards: 2 To: <sip:[email protected]:5054> From: poll-sip <sip:[email protected]>;tag=97398 Call-ID: poll-sip-97398 CSeq: 97398 OPTIONS Contact: <sip:192.168.0.6> Accept: application/sdp Content-Length: 0 User-Agent: poll-sip --end msg-- 17-02-2016 12:59:42.374 UTC Debug uri_classifier.cpp:167: home domain: false, lo cal_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 17-02-2016 12:59:42.374 UTC Debug uri_classifier.cpp:197: Classified URI as 3 17-02-2016 12:59:42.374 UTC Debug common_sip_processing.cpp:212: Skipping SAS lo gging for OPTIONS request 17-02-2016 12:59:42.374 UTC Debug thread_dispatcher.cpp:253: Queuing cloned rece ived message 0x7ff14c01d7c8 for worker threads 17-02-2016 12:59:42.374 UTC Debug thread_dispatcher.cpp:149: Worker thread deque ue message 0x7ff14c01d7c8 17-02-2016 12:59:42.374 UTC Debug pjsip: sip_endpoint.c Distributing rdata to mo dules: Request msg OPTIONS/cseq=97398 (rdata0x7ff14c01d7c8) 17-02-2016 12:59:42.374 UTC Debug uri_classifier.cpp:167: home domain: false, lo cal_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 17-02-2016 12:59:42.374 UTC Debug uri_classifier.cpp:197: Classified URI as 3 17-02-2016 12:59:42.374 UTC Debug pjsip: endpoint Response msg 200/OPTIONS /cseq=97398 (tdta0x7ff13c408040) created 17-02-2016 12:59:42.374 UTC Verbose common_sip_processing.cpp:136: TX 273 bytes Response msg 200/OPTIONS/cseq=97398 (tdta0x7ff13c408040) to TCP 192.168.0.6:5098 2: --start msg-- SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.0.6;rport=50982;received=192.168.0.6;branch=z9hG4bK-973 98 Call-ID: poll-sip-97398 From: "poll-sip" <sip:[email protected]>;tag=97398 To: <sip:[email protected]>;tag=z9hG4bK-97398 CSeq: 97398 OPTIONS Content-Length: 0 --end msg-- 17-02-2016 12:59:42.374 UTC Debug common_sip_processing.cpp:254: Skipping SAS lo gging for OPTIONS response 17-02-2016 12:59:42.374 UTC Debug pjsip: tdta0x7ff13c40 Destroying txdata Respon se msg 200/OPTIONS/cseq=97398 (tdta0x7ff13c408040) 17-02-2016 12:59:42.375 UTC Debug thread_dispatcher.cpp:193: Worker thread compl eted processing message 0x7ff14c01d7c8 17-02-2016 12:59:42.375 UTC Debug thread_dispatcher.cpp:199: Request latency = 6 61us 17-02-2016 12:59:42.385 UTC Verbose httpstack.cpp:286: Process request for URL / ping, args (null) 17-02-2016 12:59:42.385 UTC Verbose httpstack.cpp:69: Sending response 200 to re quest for URL /ping, args (null) 17-02-2016 12:59:43.375 UTC Verbose pjsip: tcps0x7ff14c06 TCP connection closed 17-02-2016 12:59:43.375 UTC Debug connection_tracker.cpp:91: Connection 0x7ff14c 06f818 has been destroyed 17-02-2016 12:59:43.376 UTC Verbose pjsip: tcps0x7ff14c06 TCP transport destroye d with reason 70016: End of file (PJ_EEOF) 17-02-2016 12:59:43.519 UTC Verbose pjsip: tcplis:5054 TCP listener 192.168.0 .6:5054: got incoming TCP connection from 192.168.0.4:34463, sock=1055 17-02-2016 12:59:43.519 UTC Verbose pjsip: tcps0x7ff14c06 TCP server transport c reated 17-02-2016 12:59:43.520 UTC Verbose pjsip: tcps0x7ff14c11 TCP connection closed 17-02-2016 12:59:43.520 UTC Debug connection_tracker.cpp:91: Connection 0x7ff14c 114c98 has been destroyed 17-02-2016 12:59:43.520 UTC Verbose pjsip: tcps0x7ff14c11 TCP transport destroye d with reason 70016: End of file (PJ_EEOF) 17-02-2016 12:59:44.483 UTC Debug pjsip: sip_endpoint.c Processing incoming mess age: Request msg REGISTER/cseq=30 (rdata0x7ff14c04bf60) 17-02-2016 12:59:44.483 UTC Verbose common_sip_processing.cpp:120: RX 1242 bytes Request msg REGISTER/cseq=30 (rdata0x7ff14c04bf60) from TCP 192.168.0.4:53691: --start msg-- REGISTER sip:dellnfv.com;transport=UDP SIP/2.0 Via: SIP/2.0/TCP 192.168.0.4:53691;rport;branch=z9hG4bKPjcGZ7eF5y6OvGqDehOqxpk4M EbqS4Ag4l Path: <sip:[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/UDP 192.168.1.8:64835;rport=64835;received=192.168.1.8;branch=z9hG4 bK-524287-1---1c645317b5676c22 Max-Forwards: 70 Contact: <sip:[email protected]:64835;transport=UDP;rinstance=907814e95ea68 ac1<sip:[email protected]:64835;transport=UDP;rinstance=907814e95ea68 %20ac1>> To: <sip:[email protected]> From: <sip:[email protected]>;tag=698b4951 Call-ID: Pp7e4umpNXHLsITvW6y7RA.. CSeq: 30 REGISTER Expires: 60 Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIB E Supported: replaces, norefersub, extended-refer, timer, outbound, path, X-cisco- serviceuri User-Agent: Zoiper r35079 Authorization: Digest response="49157d3d9e710e40b06a6d4a6c9af137", username="201 [email protected]<mailto:[email protected]>", realm="dellnfv.com", nonce="0d8f08d16e444374", uri="sip:de llnfv.com;transport=UDP<sip:de %20llnfv.com;transport=UDP>", algorithm=MD5, cnonce="450410c6c32d2ff38597f3468504591 d", opaque="2975ef5f2182abff", qop=auth, nc=0000001d,integrity-protected=ip-asso c-yes Allow-Events: presence, kpml P-Visited-Network-ID: dellnfv.com Route: <sip:sprout.dellnfv.com:5054;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 17-02-2016 12:59:44.484 UTC Debug pjutils.cpp:1648: Logging SAS Call-ID marker, Call-ID Pp7e4umpNXHLsITvW6y7RA.. 17-02-2016 12:59:44.484 UTC Debug thread_dispatcher.cpp:253: Queuing cloned rece ived message 0x7ff14c114d18 for worker threads 17-02-2016 12:59:44.484 UTC Debug thread_dispatcher.cpp:149: Worker thread deque ue message 0x7ff14c114d18 17-02-2016 12:59:44.484 UTC Debug pjsip: sip_endpoint.c Distributing rdata to mo dules: Request msg REGISTER/cseq=30 (rdata0x7ff14c114d18) 17-02-2016 12:59:44.484 UTC Debug uri_classifier.cpp:167: home domain: true, loc al_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 17-02-2016 12:59:44.485 UTC Debug uri_classifier.cpp:197: Classified URI as 4 17-02-2016 12:59:44.485 UTC Debug authentication.cpp:673: Authentication module invoked 17-02-2016 12:59:44.485 UTC Debug authentication.cpp:581: Authorization header i n request 17-02-2016 12:59:44.485 UTC Info authentication.cpp:595: SIP Digest authenticate d request integrity protected by edge proxy 17-02-2016 12:59:44.485 UTC Debug authentication.cpp:683: Request does not need authentication 17-02-2016 12:59:44.485 UTC Debug uri_classifier.cpp:167: home domain: true, loc al_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 17-02-2016 12:59:44.485 UTC Debug uri_classifier.cpp:197: Classified URI as 4 17-02-2016 12:59:44.485 UTC Debug uri_classifier.cpp:167: home domain: false, lo cal_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 17-02-2016 12:59:44.485 UTC Debug uri_classifier.cpp:197: Classified URI as 3 17-02-2016 12:59:44.485 UTC Debug acr.cpp:1763: Create RalfACR for node type S-C SCF with role Originating 17-02-2016 12:59:44.485 UTC Debug acr.cpp:49: Created ACR (0x7ff144148500) 17-02-2016 12:59:44.485 UTC Debug acr.cpp:175: Created S-CSCF Ralf ACR 17-02-2016 12:59:44.485 UTC Debug acr.cpp:214: Set record type for P/S-CSCF 17-02-2016 12:59:44.485 UTC Debug acr.cpp:222: Non-dialog message => EVENT_RECOR D 17-02-2016 12:59:44.485 UTC Debug acr.cpp:1491: Stored 0 subscription identifier s 17-02-2016 12:59:44.485 UTC Debug registrar.cpp:541: Process REGISTER for public ID sip:[email protected] 17-02-2016 12:59:44.485 UTC Debug registrar.cpp:549: Report SAS start marker - t rail (1e3) 17-02-2016 12:59:44.485 UTC Debug hssconnection.cpp:585: Making Homestead reques t for /impu/sip%3A2010000007%40dellnfv.com/reg-data?private_id=2010000007%40dell nfv.com 17-02-2016 12:59:44.485 UTC Debug httpresolver.cpp:71: HttpResolver::resolve for host hs.dellnfv.com, port 8888, family 2 17-02-2016 12:59:44.485 UTC Debug baseresolver.cpp:513: Attempt to parse hs.dell nfv.com as IP address 17-02-2016 12:59:44.485 UTC Debug dnscachedresolver.cpp:667: Removing record for hs.dellnfv.com (type 1, expiry time 1455713976) from the expiry list 17-02-2016 12:59:44.485 UTC Verbose dnscachedresolver.cpp:240: Check cache for h s.dellnfv.com type 1 17-02-2016 12:59:44.485 UTC Debug dnscachedresolver.cpp:326: Pulling 1 records f rom cache for hs.dellnfv.com A 17-02-2016 12:59:44.485 UTC Debug baseresolver.cpp:361: Found 1 A/AAAA records, randomizing 17-02-2016 12:59:44.485 UTC Debug baseresolver.cpp:503: 192.168.0.8:8888 transpo rt 6 is not blacklisted 17-02-2016 12:59:44.485 UTC Debug baseresolver.cpp:382: Added a server, now have 1 of 5 17-02-2016 12:59:44.485 UTC Debug baseresolver.cpp:420: Adding 0 servers from bl acklist 17-02-2016 12:59:44.485 UTC Debug httpconnection.cpp:623: Sending HTTP request : http://hs.dellnfv.com:8888/impu/sip%3A2010000007%40dellnfv.com/reg-data?private _id=2010000007%40dellnfv.com (trying 192.168.0.8) on new connection 17-02-2016 12:59:44.494 UTC Debug httpconnection.cpp:915: Received header http/1 .1200ok with value 17-02-2016 12:59:44.495 UTC Debug httpconnection.cpp:915: Received header conten t-length with value 869 17-02-2016 12:59:44.495 UTC Debug httpconnection.cpp:915: Received header conten t-type with value text/plain 17-02-2016 12:59:44.495 UTC Debug httpconnection.cpp:915: Received header with value 17-02-2016 12:59:44.495 UTC Debug httpconnection.cpp:638: Received HTTP response : status=200, doc=<ClearwaterRegData> <RegistrationState>REGISTERED</RegistrationState> <IMSSubscription xsi="http://www.w3.org/2001/XMLSchema-instance"; noNames paceSchemaLocation="CxDataType.xsd"> <PrivateID>[email protected]</PrivateID<mailto:[email protected]%3c/PrivateID>> <ServiceProfile> <InitialFilterCriteria> <TriggerPoint> <ConditionTypeCNF>0</ConditionTypeCNF> <SPT> <ConditionNegated>0</ConditionNe gated> <Group>0</Group> <Method>INVITE</Method> <Extension/> </SPT> </TriggerPoint> <ApplicationServer> <ServerName>sip:mmtel.dellnfv.com</Serve<sip:mmtel.dellnfv.com%3c/Serve> rName> <DefaultHandling>0</DefaultHandling> </ApplicationServer> </InitialFilterCriteria> <PublicIdentity> <BarringIndication>1</BarringIndication> <Identity>sip:[email protected]</Identity<sip:[email protected]%3c/Identity>> </PublicIdentity> </ServiceProfile> </IMSSubscription> </ClearwaterRegData> 17-02-2016 12:59:44.495 UTC Debug communicationmonitor.cpp:82: Checking communic ation changes - successful attempts 1, failures 0 17-02-2016 12:59:44.495 UTC Debug hssconnection.cpp:366: Processing Identity nod e from HSS XML - sip:[email protected] 17-02-2016 12:59:44.495 UTC Debug registrar.cpp:651: REGISTER for public ID sip: [email protected]<mailto:[email protected]> uses AOR sip:[email protected] 17-02-2016 12:59:44.495 UTC Debug subscriber_data_manager.cpp:366: Get AoR data for sip:[email protected] 17-02-2016 12:59:44.495 UTC Debug memcachedstore.cpp:195: Key reg\\sip:201000000 [email protected]<mailto:[email protected]> hashes to vbucket 19 via hash 0x9f135593 17-02-2016 12:59:44.495 UTC Debug memcachedstore.cpp:367: 1 read replicas for ke y reg\\sip:[email protected] 17-02-2016 12:59:44.495 UTC Debug memcachedstore.cpp:402: Attempt to read from r eplica 0 (connection 0x7ff1440ae680) 17-02-2016 12:59:44.496 UTC Debug memcachedstore.cpp:780: Fetch result 17-02-2016 12:59:44.496 UTC Debug memcachedstore.cpp:788: Found record on replic a 17-02-2016 12:59:44.496 UTC Debug memcachedstore.cpp:410: Read for reg\\sip:2010 [email protected]<mailto:[email protected]> on replica 0 returned SUCCESS 17-02-2016 12:59:44.496 UTC Debug memcachedstore.cpp:453: Read 469 bytes from ta ble reg key sip:[email protected], CAS = 1537 17-02-2016 12:59:44.496 UTC Debug communicationmonitor.cpp:82: Checking communic ation changes - successful attempts 4, failures 0 17-02-2016 12:59:44.496 UTC Debug subscriber_data_manager.cpp:376: Data store re turned a record, CAS = 1537 17-02-2016 12:59:44.496 UTC Debug subscriber_data_manager.cpp:477: Try to deseri alize record for sip:[email protected] with 'JSON' deserializer 17-02-2016 12:59:44.496 UTC Debug subscriber_data_manager.cpp:969: Deserialize J SON document: {"bindings":{"sip:[email protected]:64835;transport=UDP;rinst ance=907814e95ea68ac1<sip:[email protected]:64835;transport=UDP;rinst %20ance=907814e95ea68ac1>":{"uri":"sip:[email protected]:64835;transport=UDP;ri nstance=907814e95ea68ac1<sip:[email protected]:64835;transport=UDP;ri %20nstance=907814e95ea68ac1>","cid":"Pp7e4umpNXHLsITvW6y7RA..","cseq":29,"expires":1 455713990,"priority":0,"params":{},"paths":["sip:[email protected]:5058;tra nsport=TCP;lr;ob<sip:[email protected]:5058;tra %20nsport=TCP;lr;ob>"],"timer_id":"016dc709400001210040001000104104","private_id":"2 [email protected]","emergency_reg":false}},"subscriptions":{},"notify_cseq<mailto:[email protected]%22,%22emergency_reg%22:false%7d%7d,%22subscriptions%22:%7b%7d,%22notify_cseq>": 29} 17-02-2016 12:59:44.496 UTC Debug subscriber_data_manager.cpp:994: Binding: si p:[email protected]:64835;transport=UDP;rinstance=907814e95ea68ac1 17-02-2016 12:59:44.496 UTC Debug subscriber_data_manager.cpp:482: Deserializati on suceeded 17-02-2016 12:59:44.496 UTC Debug registrar.cpp:249: Retrieved AoR data 0x7ff144 23a0a0 17-02-2016 12:59:44.496 UTC Debug registrar.cpp:342: Binding identifier for cont act = sip:[email protected]:64835;transport=UDP;rinstance=907814e95ea68ac1 17-02-2016 12:59:44.496 UTC Debug registrar.cpp:369: Path header sip:rP6Yw8PkfR@ 192.168.0.4:5058;transport=TCP;lr;ob 17-02-2016 12:59:44.496 UTC Debug subscriber_data_manager.cpp:196: Set AoR data for sip:[email protected], CAS=1537, expiry = 1455714054 17-02-2016 12:59:44.496 UTC Debug httpresolver.cpp:71: HttpResolver::resolve for host 127.0.0.1, port 7253, family 2 17-02-2016 12:59:44.496 UTC Debug baseresolver.cpp:513: Attempt to parse 127.0.0 .1 as IP address 17-02-2016 12:59:44.496 UTC Debug httpresolver.cpp:79: Target is an IP address 17-02-2016 12:59:44.496 UTC Debug httpconnection.cpp:623: Sending HTTP request : http://127.0.0.1:7253/timers/016dc709400001210040001000104104 (trying 127.0.0.1 ) on new connection 17-02-2016 12:59:44.498 UTC Debug httpconnection.cpp:915: Received header http/1 .1200ok with value 17-02-2016 12:59:44.498 UTC Debug httpconnection.cpp:915: Received header locati on with value /timers/016dc709400001210040001000104104 17-02-2016 12:59:44.498 UTC Debug httpconnection.cpp:915: Received header conten t-length with value 0 17-02-2016 12:59:44.498 UTC Debug httpconnection.cpp:915: Received header with value 17-02-2016 12:59:44.498 UTC Debug httpconnection.cpp:638: Received HTTP response : status=200, doc= 17-02-2016 12:59:44.498 UTC Debug communicationmonitor.cpp:82: Checking communic ation changes - successful attempts 1, failures 0 17-02-2016 12:59:44.498 UTC Debug memcachedstore.cpp:542: Writing 469 bytes to t able reg key sip:[email protected], CAS = 1537, expiry = 70 17-02-2016 12:59:44.498 UTC Debug memcachedstore.cpp:195: Key reg\\sip:201000000 [email protected]<mailto:[email protected]> hashes to vbucket 19 via hash 0x9f135593 17-02-2016 12:59:44.498 UTC Debug memcachedstore.cpp:562: 1 write replicas for k ey reg\\sip:[email protected] 17-02-2016 12:59:44.498 UTC Debug memcachedstore.cpp:616: Attempt conditional wr ite to vbucket 19 on replica 0 (connection 0x7ff1440ae680), CAS = 1537, expiry = 70 17-02-2016 12:59:44.499 UTC Debug memcachedstore.cpp:657: Conditional write succ eeded to replica 0 17-02-2016 12:59:44.499 UTC Debug subscriber_data_manager.cpp:438: Data store se t_data returned 1 17-02-2016 12:59:44.499 UTC Debug registrar.cpp:116: Bindings for sip:2010000007 @dellnfv.com 17-02-2016 12:59:44.499 UTC Debug registrar.cpp:130: sip:[email protected]. 8:64835;transport=UDP;rinstance=907814e95ea68ac1 URI=sip:[email protected]: 64835;transport=UDP;rinstance=907814e95ea68ac1 expires=1455714044 q=0 from=Pp7e4 umpNXHLsITvW6y7RA.. cseq=30 timer=016dc709400001210040001000104104 private_id=20 [email protected]<mailto:[email protected]> emergency_registration=false 17-02-2016 12:59:44.499 UTC Debug pjsip: endpoint Response msg 200/REGISTE R/cseq=30 (tdta0x7ff14423a790) created 17-02-2016 12:59:44.499 UTC Debug acr.cpp:1550: Store associated URIs 17-02-2016 12:59:44.499 UTC Verbose common_sip_processing.cpp:136: TX 765 bytes Response msg 200/REGISTER/cseq=30 (tdta0x7ff14423a790) to TCP 192.168.0.4:53691: --start msg-- SIP/2.0 200 OK Service-Route: <sip:sprout.dellnfv.com:5054;transport=TCP;lr;orig> Via: SIP/2.0/TCP 192.168.0.4:53691;rport=53691;received=192.168.0.4;branch=z9hG4 bKPjcGZ7eF5y6OvGqDehOqxpk4MEbqS4Ag4l Via: SIP/2.0/UDP 192.168.1.8:64835;rport=64835;received=192.168.1.8;branch=z9hG4 bK-524287-1---1c645317b5676c22 Call-ID: Pp7e4umpNXHLsITvW6y7RA.. From: <sip:[email protected]>;tag=698b4951 To: <sip:[email protected]>;tag=z9hG4bKPjcGZ7eF5y6OvGqDehOqxpk4MEbqS4Ag4l CSeq: 30 REGISTER Supported: outbound Contact: <sip:[email protected]:64835;transport=UDP;rinstance=907814e95ea68 ac1<sip:[email protected]:64835;transport=UDP;rinstance=907814e95ea68 %20ac1>>;expires=60 Require: outbound Path: <sip:[email protected]:5058;transport=TCP;lr;ob> P-Associated-URI: <sip:[email protected]> Content-Length: 0 --end msg-- 17-02-2016 12:59:44.499 UTC Info acr.cpp:658: No CCF or ECF to send ACR for sess ion Pp7e4umpNXHLsITvW6y7RA.. to - dropping! 17-02-2016 12:59:44.499 UTC Debug acr.cpp:54: Destroyed ACR (0x7ff144148500) 17-02-2016 12:59:44.499 UTC Debug ifchandler.cpp:763: Interpreting orig IFC info rmation 17-02-2016 12:59:44.499 UTC Debug ifchandler.cpp:437: SPT class Method: result f alse 17-02-2016 12:59:44.499 UTC Debug ifchandler.cpp:541: Add to group 0 val false 17-02-2016 12:59:44.499 UTC Debug ifchandler.cpp:559: Result group 0 val false 17-02-2016 12:59:44.499 UTC Debug ifchandler.cpp:572: iFC does not match 17-02-2016 12:59:44.499 UTC Info registration_utils.cpp:187: Found 0 Application Servers 17-02-2016 12:59:44.499 UTC Debug pjsip: tdta0x7ff14423 Destroying txdata Respon se msg 200/REGISTER/cseq=30 (tdta0x7ff14423a790) 17-02-2016 12:59:44.499 UTC Debug registrar.cpp:1036: Report SAS end marker - tr ail (1e3) 17-02-2016 12:59:44.499 UTC Debug thread_dispatcher.cpp:193: Worker thread compl eted processing message 0x7ff14c114d18 17-02-2016 12:59:44.499 UTC Debug thread_dispatcher.cpp:199: Request latency = 1 5474us 17-02-2016 12:59:46.381 UTC Verbose pjsip: tcps0x7ff14c15 TCP transport destroye d normally 17-02-2016 12:59:46.520 UTC Verbose pjsip: tcplis:5054 TCP listener 192.168.0 .6:5054: got incoming TCP connection from 192.168.0.4:35812, sock=408 17-02-2016 12:59:46.520 UTC Verbose pjsip: tcps0x7ff14c11 TCP server transport c reated 17-02-2016 12:59:47.520 UTC Verbose pjsip: tcplis:5054 TCP listener 192.168.0 .6:5054: got incoming TCP connection from 192.168.0.4:41045, sock=938 17-02-2016 12:59:47.520 UTC Verbose pjsip: tcps0x7ff14c15 TCP server transport c reated 17-02-2016 12:59:47.521 UTC Verbose pjsip: tcps0x7ff14c05 TCP connection closed 17-02-2016 12:59:47.521 UTC Debug connection_tracker.cpp:91: Connection 0x7ff14c 05d228 has been destroyed 17-02-2016 12:59:47.521 UTC Verbose pjsip: tcps0x7ff14c05 TCP transport destroye d with reason 70016: End of file (PJ_EEOF) 17-02-2016 12:59:49.521 UTC Verbose pjsip: tcplis:5054 TCP listener 192.168.0 .6:5054: got incoming TCP connection from 192.168.0.4:51223, sock=429 17-02-2016 12:59:49.521 UTC Verbose pjsip: tcps0x7ff14c05 TCP server transport c reated 17-02-2016 12:59:49.521 UTC Verbose pjsip: tcps0x7ff14c07 TCP connection closed 17-02-2016 12:59:49.521 UTC Verbose pjsip: tcps0x7ff14c07 TCP transport destroye d with reason 70016: End of file (PJ_EEOF) 17-02-2016 12:59:52.359 UTC Verbose pjsip: tcplis:5054 TCP listener 192.168.0 .6:5054: got incoming TCP connection from 192.168.0.6:51013, sock=970 17-02-2016 12:59:52.359 UTC Verbose pjsip: tcps0x7ff14c07 TCP server transport c reated 17-02-2016 12:59:52.359 UTC Debug pjsip: sip_endpoint.c Processing incoming mess age: Request msg OPTIONS/cseq=97408 (rdata0x7ff14c0747e0) 17-02-2016 12:59:52.359 UTC Verbose common_sip_processing.cpp:120: RX 342 bytes Request msg OPTIONS/cseq=97408 (rdata0x7ff14c0747e0) from TCP 192.168.0.6:51013: --start msg-- OPTIONS sip:[email protected]:5054 SIP/2.0 Via: SIP/2.0/TCP 192.168.0.6;rport;branch=z9hG4bK-97408 Max-Forwards: 2 To: <sip:[email protected]:5054> From: poll-sip <sip:[email protected]>;tag=97408 Call-ID: poll-sip-97408 CSeq: 97408 OPTIONS Contact: <sip:192.168.0.6> Accept: application/sdp Content-Length: 0 User-Agent: poll-sip --end msg-- 17-02-2016 12:59:52.359 UTC Debug uri_classifier.cpp:167: home domain: false, lo cal_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 17-02-2016 12:59:52.359 UTC Debug uri_classifier.cpp:197: Classified URI as 3 17-02-2016 12:59:52.359 UTC Debug common_sip_processing.cpp:212: Skipping SAS lo gging for OPTIONS request 17-02-2016 12:59:52.359 UTC Debug thread_dispatcher.cpp:253: Queuing cloned rece ived message 0x7ff14c01d7c8 for worker threads 17-02-2016 12:59:52.359 UTC Debug thread_dispatcher.cpp:149: Worker thread deque ue message 0x7ff14c01d7c8 17-02-2016 12:59:52.360 UTC Debug pjsip: sip_endpoint.c Distributing rdata to mo dules: Request msg OPTIONS/cseq=97408 (rdata0x7ff14c01d7c8) 17-02-2016 12:59:52.360 UTC Debug uri_classifier.cpp:167: home domain: false, lo cal_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 17-02-2016 12:59:52.360 UTC Debug uri_classifier.cpp:197: Classified URI as 3 17-02-2016 12:59:52.360 UTC Debug pjsip: endpoint Response msg 200/OPTIONS /cseq=97408 (tdta0x7ff14c298780) created 17-02-2016 12:59:52.360 UTC Verbose common_sip_processing.cpp:136: TX 273 bytes Response msg 200/OPTIONS/cseq=97408 (tdta0x7ff14c298780) to TCP 192.168.0.6:5101 3: --start msg-- SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.0.6;rport=51013;received=192.168.0.6;branch=z9hG4bK-974 08 Call-ID: poll-sip-97408 From: "poll-sip" <sip:[email protected]>;tag=97408 To: <sip:[email protected]>;tag=z9hG4bK-97408 CSeq: 97408 OPTIONS Content-Length: 0 --end msg-- 17-02-2016 12:59:52.360 UTC Debug common_sip_processing.cpp:254: Skipping SAS lo gging for OPTIONS response 17-02-2016 12:59:52.360 UTC Debug pjsip: tdta0x7ff14c29 Destroying txdata Respon se msg 200/OPTIONS/cseq=97408 (tdta0x7ff14c298780) 17-02-2016 12:59:52.360 UTC Debug thread_dispatcher.cpp:193: Worker thread compl eted processing message 0x7ff14c01d7c8 17-02-2016 12:59:52.360 UTC Debug thread_dispatcher.cpp:199: Request latency = 2 42us 17-02-2016 12:59:52.360 UTC Info load_monitor.cpp:212: Accepted 100.000000% of r equests, latency error = -0.953790, overload responses = 0 17-02-2016 12:59:52.360 UTC Status load_monitor.cpp:260: Maximum incoming reques t rate/second unchanged - only handled 20 requests in last 73256ms, minimum thre shold for a change is 18314.000000 17-02-2016 12:59:52.360 UTC Debug snmp_continuous_accumulator_table.cpp:108: Acc umulating sample 500ui into continuous accumulator statistic 17-02-2016 12:59:52.360 UTC Debug snmp_continuous_accumulator_table.cpp:108: Acc umulating sample 500ui into continuous accumulator statistic 17-02-2016 12:59:52.361 UTC Verbose httpstack.cpp:286: Process request for URL / ping, args (null) 17-02-2016 12:59:52.361 UTC Verbose httpstack.cpp:69: Sending response 200 to re quest for URL /ping, args (null) 17-02-2016 12:59:53.362 UTC Verbose pjsip: tcps0x7ff14c07 TCP connection closed 17-02-2016 12:59:53.362 UTC Debug connection_tracker.cpp:91: Connection 0x7ff14c 0744a8 has been destroyed 17-02-2016 12:59:53.362 UTC Verbose pjsip: tcps0x7ff14c07 TCP transport destroye d with reason 70016: End of file (PJ_EEOF) 17-02-2016 12:59:53.522 UTC Verbose pjsip: tcplis:5054 TCP listener 192.168.0 .6:5054: got incoming TCP connection from 192.168.0.4:49292, sock=970 17-02-2016 12:59:53.522 UTC Verbose pjsip: tcps0x7ff14c07 TCP server transport c reated 17-02-2016 12:59:53.522 UTC Verbose pjsip: tcps0x7ff14c08 TCP connection closed 17-02-2016 12:59:53.522 UTC Debug connection_tracker.cpp:91: Connection 0x7ff14c 085a08 has been destroyed 17-02-2016 12:59:53.522 UTC Verbose pjsip: tcps0x7ff14c08 TCP transport destroye d with reason 70016: End of file (PJ_EEOF) Regards, Tahir Masood
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
