Hi, The REGISTERs are reaching Bono/Sprout – this rules out connectivity problems.
I don’t see any errors in the logs you’ve shown though – they all look like part of a registration attempt. In a successful registration, we expect the client to do a REGISTER with no authentication credentials. This then gets rejected with a 401 (which contains a WWW-authenticate header). The client will then resend the REGISTER, with the appropriate authorization, and this will then be accepted, and a 200 OK is returned. Can you send me more details about what errors you’re seeing when you run the stress tests? I’d like the logs from the stress run (in /var/log/clearwater-sip-stress/*), as well as the full logs from Sprout (in /var/log/sprout/sprout_current). Thanks, Ellie From: Doctor Mescaline [mailto:[email protected]] Sent: 07 January 2015 13:49 To: Eleanor Merry Cc: [email protected]<mailto:[email protected]> Subject: Re: [Clearwater] Problem with Stress testing Hi, the requests generated by the stress tests seem to reach Bono. In the following you can find the logs thanks REGISTER message of Bono: 06-01-2015 13:53:46.878 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=1 (rdata0x7f01a413e468) 06-01-2015 13:53:46.878 UTC Verbose stack.cpp:244: RX 683 bytes Request msg REGISTER/cseq=1 (rdata0x7f01a413e468) from TCP 10.40.7.177:53425: --start msg-- REGISTER sip:[email protected] SIP/2.0 Via: SIP/2.0/TCP 192.168.3.37:5060;rport;branch=z9hG4bK-28936-1-2-2010000000- Route: <sip:demo.clearwater;transport=TCP;lr> Max-Forwards: 70 From: <sip:[email protected]>;tag=28936SIPpTag001 To: <sip:[email protected]> Call-ID: 2010000000///[email protected]<mailto:2010000000///[email protected]> CSeq: 1 REGISTER User-Agent: Accession 4.0.0.0 Supported: outbound, path Contact: <sip:[email protected]:5060;transport=TCP;ob>;+sip.ice;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-000000000001>" Expires: 3600 Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Content-Length: 0 --end msg-- 06-01-2015 13:53:46.878 UTC Debug stack.cpp:470: Queuing cloned received message 0x7f01a40b1fa8 for worker threads 06-01-2015 13:53:46.878 UTC Debug stack.cpp:207: Worker thread dequeue message 0x7f01a40b1fa8 06-01-2015 13:53:46.878 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=1 (rdata0x7f01a40b1fa8) 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:258: Proxy RX request 06-01-2015 13:53:46.878 UTC Debug pjutils.cpp:676: Cloned Request msg REGISTER/cseq=1 (rdata0x7f01a40b1fa8) to tdta0x7f019c323420 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:951: Request received on non-trusted port 5060 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:1223: Perform access proxy routing for REGISTER request 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:1260: Message requires outbound support 06-01-2015 13:53:46.878 UTC Debug flowtable.cpp:91: Find or create flow for transport tcps0x7f01a413e178 (2), remote address 10.40.7.177:53425 06-01-2015 13:53:46.878 UTC Debug flowtable.cpp:296: Added transport listener for flow 0x7f019c2fbd00 06-01-2015 13:53:46.878 UTC Debug flowtable.cpp:106: Added flow record 0x7f019c2fbd00 06-01-2015 13:53:46.878 UTC Debug flowtable.cpp:233: Reporting current flow count: 1 06-01-2015 13:53:46.878 UTC Debug flowtable.cpp:602: Dialog count now 2 for flow 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:1272: Found or created flow data record, token = vz/ZAyleKa 06-01-2015 13:53:46.878 UTC Debug flowtable.cpp:619: Dialog count now 1 for flow 06-01-2015 13:53:46.878 UTC Debug pjutils.cpp:523: Found Route header, URI = sip:demo.clearwater;transport=TCP;lr 06-01-2015 13:53:46.878 UTC Debug pjutils.cpp:526: Route header is local 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:1181: Mark originating 06-01-2015 13:53:46.878 UTC Info stateful_proxy.cpp:1202: Route request to upstream proxy sip:sprout.demo.clearwater:5054;transport=TCP;lr;orig 06-01-2015 13:53:46.878 UTC Debug pjutils.cpp:523: Found Route header, URI = sip:demo.clearwater;transport=TCP;lr 06-01-2015 13:53:46.878 UTC Debug pjutils.cpp:526: Route header is local 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:1717: Top Route header is local - erasing 06-01-2015 13:53:46.878 UTC Debug acr.cpp:48: Created ACR (0x7f019c024dd0) 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:594: Trust mode INBOUND_EDGE_CLIENT(,-rsp,-pch), serving state None 06-01-2015 13:53:46.878 UTC Debug pjsip: tsx0x7f019c008 Transaction created for Request msg REGISTER/cseq=1 (rdata0x7f01a40b1fa8) 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:2245: UASTransaction constructor (0x7f019c3152e0) 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:2246: ACR (0x7f019c024dd0) 06-01-2015 13:53:46.878 UTC Debug pjsip: tsx0x7f019c008 Incoming Request msg REGISTER/cseq=1 (rdata0x7f01a40b1fa8) in state Null 06-01-2015 13:53:46.878 UTC Debug pjsip: tsx0x7f019c008 State changed from Null to Trying, event=RX_MSG 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c008028 - tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying 06-01-2015 13:53:46.878 UTC Debug pjsip: endpoint Response msg 408/REGISTER/cseq=1 (tdta0x7f019c319960) created 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:3692: Report SAS start marker - trail (167e37) 06-01-2015 13:53:46.878 UTC Debug trustboundary.cpp:67: Add P-Charging headers 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:3781: Allocating transaction and data for target 0 06-01-2015 13:53:46.878 UTC Debug pjsip: tsx0x7f019c333 Transaction created for Request msg REGISTER/cseq=1 (tdta0x7f019c003770) 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:3802: Adding trail identifier 1474103 to UAC transaction 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:3821: Updating request URI and route for target 0 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:4187: Stripping loose routes from proxied message 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:4217: Adding a Route header to sip:sprout.demo.clearwater:5054;transport=TCP 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:4275: Transport tcpc0x7f019809c568 (TCP to 192.168.3.33:5054) pre-selected for transaction 06-01-2015 13:53:46.878 UTC Debug stateful_proxy.cpp:4293: Sending request for sip:[email protected] 06-01-2015 13:53:46.878 UTC Debug pjsip: tsx0x7f019c333 Sending Request msg REGISTER/cseq=1 (tdta0x7f019c003770) in state Null 06-01-2015 13:53:46.878 UTC Debug pjsip: endpoint Request msg REGISTER/cseq=1 (tdta0x7f019c003770): skipping target resolution because address is already set 06-01-2015 13:53:46.878 UTC Verbose stack.cpp:260: TX 943 bytes Request msg REGISTER/cseq=1 (tdta0x7f019c003770) to TCP 192.168.3.33:5054: --start msg-- REGISTER sip:[email protected] SIP/2.0 Via: SIP/2.0/TCP 192.168.3.32:45742;rport;branch=z9hG4bKPjTXMe6OJnuutBuDL-Pgaqg5O3R.RUefuU Path: <sip:vz/[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/TCP 192.168.3.37:5060;rport=53425;received=10.40.7.177;branch=z9hG4bK-28936-1-2-2010000000- Max-Forwards: 70 From: <sip:[email protected]>;tag=28936SIPpTag001 To: <sip:[email protected]> Call-ID: 2010000000///[email protected]<mailto:2010000000///[email protected]> CSeq: 1 REGISTER User-Agent: Accession 4.0.0.0 Supported: outbound, path Contact: <sip:[email protected]:5060;transport=TCP;ob>;+sip.ice;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-000000000001>" Expires: 3600 Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS P-Visited-Network-ID: demo.clearwater Session-Expires: 600 Route: <sip:sprout.demo.clearwater:5054;transport=TCP;lr;orig> Content-Length: 0 --end msg-- 06-01-2015 13:53:46.879 UTC Debug pjsip: tsx0x7f019c333 State changed from Null to Calling, event=TX_MSG 06-01-2015 13:53:46.879 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c333ac8 - tu_on_tsx_state UAC, TSX_STATE TX_MSG state=Calling 06-01-2015 13:53:46.879 UTC Debug stateful_proxy.cpp:4400: tsx0x7f019c333ac8 - uac_data = 0x7f019c098800, uas_data = 0x7f019c3152e0 06-01-2015 13:53:46.879 UTC Debug stack.cpp:209: Worker thread completed processing message 0x7f01a40b1fa8 06-01-2015 13:53:46.879 UTC Debug stack.cpp:215: Request latency = 824us 06-01-2015 13:53:46.879 UTC Debug statistic.cpp:103: Send new value for statistic client_count, size 1 06-01-2015 13:53:46.879 UTC Debug zmq_lvc.cpp:167: Update to client_count statistic 06-01-2015 13:53:46.879 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f01ac0008c0 6-01-2015 13:53:46.910 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=1 (rdata0x7f019809c858) 06-01-2015 13:53:46.910 UTC Verbose stack.cpp:244: RX 607 bytes Response msg 401/REGISTER/cseq=1 (rdata0x7f019809c858) from TCP 192.168.3.33:5054: --start msg-- SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 192.168.3.32:45742;rport=45742;received=192.168.3.32;branch=z9hG4bKPjTXMe6OJnuutBuDL-Pgaqg5O3R.RUefuU Via: SIP/2.0/TCP 192.168.3.37:5060;rport=53425;received=10.40.7.177;branch=z9hG4bK-28936-1-2-2010000000- Call-ID: 2010000000///[email protected]<mailto:2010000000///[email protected]> From: <sip:[email protected]>;tag=28936SIPpTag001 To: <sip:[email protected]>;tag=z9hG4bKPjTXMe6OJnuutBuDL-Pgaqg5O3R.RUefuU CSeq: 1 REGISTER WWW-Authenticate: Digest realm="demo.clearwater",nonce="6e40524242a6faa9",opaque="2994bf2045959d83",algorithm=MD5,qop="auth" Content-Length: 0 --end msg-- 06-01-2015 13:53:46.910 UTC Debug stack.cpp:470: Queuing cloned received message 0x7f01a40b0ff8 for worker threads 06-01-2015 13:53:46.910 UTC Debug stack.cpp:207: Worker thread dequeue message 0x7f01a40b0ff8 06-01-2015 13:53:46.910 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 401/REGISTER/cseq=1 (rdata0x7f01a40b0ff8) 06-01-2015 13:53:46.910 UTC Debug pjsip: tsx0x7f019c333 Incoming Response msg 401/REGISTER/cseq=1 (rdata0x7f01a40b0ff8) in state Calling 06-01-2015 13:53:46.910 UTC Debug pjsip: tsx0x7f019c333 State changed from Calling to Completed, event=RX_MSG 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c333ac8 - tu_on_tsx_state UAC, TSX_STATE RX_MSG state=Completed 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:4400: tsx0x7f019c333ac8 - uac_data = 0x7f019c098800, uas_data = 0x7f019c3152e0 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:4439: tsx0x7f019c333ac8 - RX_MSG on active UAC transaction 06-01-2015 13:53:46.910 UTC Debug trustboundary.cpp:57: Strip trusted headers 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:3391: tsx0x7f019c333ac8 - Final response, so disconnect UAS and UAC transactions 06-01-2015 13:53:46.910 UTC Debug pjsip: tdta0x7f019c31 Destroying txdata Response msg 408/REGISTER/cseq=1 (tdta0x7f019c319960) 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:3912: Dissociate UAC transaction 0x7f019c098800 (0) 06-01-2015 13:53:46.910 UTC Debug pjsip: tsx0x7f019c008 Sending Response msg 401/REGISTER/cseq=1 (tdta0x7f019c3348d0) in state Trying 06-01-2015 13:53:46.910 UTC Verbose stack.cpp:260: TX 487 bytes Response msg 401/REGISTER/cseq=1 (tdta0x7f019c3348d0) to TCP 10.40.7.177:53425: --start msg-- SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 192.168.3.37:5060;rport=53425;received=10.40.7.177;branch=z9hG4bK-28936-1-2-2010000000- Call-ID: 2010000000///[email protected]<mailto:2010000000///[email protected]> From: <sip:[email protected]>;tag=28936SIPpTag001 To: <sip:[email protected]>;tag=z9hG4bKPjTXMe6OJnuutBuDL-Pgaqg5O3R.RUefuU CSeq: 1 REGISTER WWW-Authenticate: Digest realm="demo.clearwater",nonce="6e40524242a6faa9",opaque="2994bf2045959d83",algorithm=MD5,qop="auth" Content-Length: 0 --end msg-- 06-01-2015 13:53:46.910 UTC Debug pjsip: tsx0x7f019c008 State changed from Trying to Completed, event=TX_MSG 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c008028 - tu_on_tsx_state UAS, TSX_STATE TX_MSG state=Completed 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:951: Request received on non-trusted port 5060 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:3716: Report SAS end marker - trail (167e37) 06-01-2015 13:53:46.910 UTC Debug stack.cpp:209: Worker thread completed processing message 0x7f01a40b0ff8 06-01-2015 13:53:46.910 UTC Debug stack.cpp:215: Request latency = 561us 06-01-2015 13:53:46.910 UTC Debug pjsip: tsx0x7f019c008 Timeout timer event 06-01-2015 13:53:46.910 UTC Debug pjsip: tsx0x7f019c008 State changed from Completed to Terminated, event=TIMER 06-01-2015 13:53:46.910 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c008028 - tu_on_tsx_state UAS, TSX_STATE TIMER state=Terminated 06-01-2015 13:53:46.910 UTC Debug pjsip: tsx0x7f019c333 Timeout timer event 06-01-2015 13:53:46.911 UTC Debug pjsip: tsx0x7f019c333 State changed from Completed to Terminated, event=TIMER 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c333ac8 - tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:4400: tsx0x7f019c333ac8 - uac_data = 0x7f019c098800, uas_data = (nil) 06-01-2015 13:53:46.911 UTC Debug pjsip: tsx0x7f019c008 Timeout timer event 06-01-2015 13:53:46.911 UTC Debug pjsip: tsx0x7f019c008 State changed from Terminated to Destroyed, event=TIMER 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c008028 - tu_on_tsx_state UAS, TSX_STATE TIMER state=Destroyed 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:3482: tsx0x7f019c008028 - UAS tsx destroyed 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:2290: UASTransaction destructor (0x7f019c3152e0) 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:2310: Disconnect UAC transactions from UAS transaction 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:2356: Transaction is not linked to an AS chain(s) 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:2357: Upstream ACR = 0x7f019c024dd0, Downstream ACR = 0x7f019c024dd0 06-01-2015 13:53:46.911 UTC Debug acr.cpp:82: Sending Null ACR (0x7f019c024dd0) 06-01-2015 13:53:46.911 UTC Debug acr.cpp:53: Destroyed ACR (0x7f019c024dd0) 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:2386: Free original request (0x7f019c3234c8) 06-01-2015 13:53:46.911 UTC Debug pjsip: tdta0x7f019c32 Destroying txdata Request msg REGISTER/cseq=1 (tdta0x7f019c323420) 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:2417: UASTransaction destructor completed 06-01-2015 13:53:46.911 UTC Debug pjsip: tdta0x7f019c33 Destroying txdata Response msg 401/REGISTER/cseq=1 (tdta0x7f019c3348d0) 06-01-2015 13:53:46.911 UTC Debug pjsip: tsx0x7f019c333 Timeout timer event 06-01-2015 13:53:46.911 UTC Debug pjsip: tsx0x7f019c333 State changed from Terminated to Destroyed, event=TIMER 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:366: tsx0x7f019c333ac8 - tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:4400: tsx0x7f019c333ac8 - uac_data = 0x7f019c098800, uas_data = (nil) 06-01-2015 13:53:46.911 UTC Debug stateful_proxy.cpp:4487: tsx0x7f019c333ac8 - UAC tsx destroyed 06-01-2015 13:53:46.911 UTC Debug pjsip: tdta0x7f019c00 Destroying txdata Request msg REGISTER/cseq=1 (tdta0x7f019c003770) 06-01-2015 13:53:46.911 UTC Debug pjsip: tsx0x7f019c008 Transaction destroyed! 06-01-2015 13:53:46.911 UTC Debug pjsip: tsx0x7f019c333 Transaction destroyed! Bono log_current.txt: Call-Disconnected: CALL_ID=2010000000///[email protected]<mailto:CALL_ID=2010000000///[email protected]> REASON=401 Call-Disconnected: CALL_ID=2010000001///[email protected]<mailto:CALL_ID=2010000001///[email protected]> REASON=401 bono: Debug statistic.cpp:103: Send new value for statistic incoming_requests, size 1 Debug zmq_lvc.cpp:167: Update to incoming_requests statistic Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f01ac02a270 Debug stack.cpp:470: Queuing cloned received message 0x7f01a4124c18 for worker threads Debug statistic.cpp:103: Send new value for statistic queue_size, size 5 Debug zmq_lvc.cpp:167: Update to queue_size statistic Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f01ac0335b0 Debug stack.cpp:207: Worker thread dequeue message 0x7f01a4124c18 Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=1299406 (rdata0x7f01a4124c18) Debug pjsip: endpoint Response msg 200/OPTIONS/cseq=1299406 (tdta0x7f019c2e3420) created Verbose stack.cpp:260: TX 287 bytes Response msg 200/OPTIONS/cseq=1299406 (tdta0x7f019c2e3420) to TCP 192.168.3.32:46868: --start msg-- SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.3.32;rport=46868;received=192.168.3.32;branch=z9hG4bK-1299406 Call-ID: poll-sip-1299406 From: "poll-sip" <sip:[email protected]>;tag=1299406 To: <sip:[email protected]>;tag=z9hG4bK-1299406 CSeq: 1299406 OPTIONS Content-Length: 0 --end msg-- Debug pjsip: tdta0x7f019c2e Destroying txdata Response msg 200/OPTIONS/cseq=1299406 (tdta0x7f019c2e3420) Debug stack.cpp:209: Worker thread completed processing message 0x7f01a4124c18 Debug stack.cpp:215: Request latency = 270us Debug statistic.cpp:103: Send new value for statistic latency_us, size 5 Debug zmq_lvc.cpp:167: Update to latency_us statistic Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f01ac012ff0 Verbose pjsip: tcps0x7f01a412 TCP connection closed Debug connection_tracker.cpp:91: Connection 0x7f01a4123388 has been destroyed Verbose pjsip: tcps0x7f01a412 TCP transport destroyed with reason 70016: End of file (PJ_EEOF) Sprout log_current.txt: Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:5060;transport=TCP;ob EXPIRES=300 Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:5060;transport=TCP;ob EXPIRES=300 Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:53424;transport=TCP;ob EXPIRES=300 Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:53424;transport=TCP;ob EXPIRES=300 Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:53424;transport=TCP;ob EXPIRES=300 Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:53424;transport=TCP;ob EXPIRES=300 Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:53424;transport=TCP;ob EXPIRES=300 Registration: USER_URI=sip:[email protected] BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 CONTACT_URI=sip:[email protected]:53424;transport=TCP;ob EXPIRES=300 Sprout sprout_current.txt: Verbose pjsip: tcps0x7ffba003 TCP transport destroyed normallyVerbose pjsip: tcplis:5054 TCP listener 192.168.3.33:5054: got incoming TCP connection from 192.168.3.32:53291, sock=147 Verbose pjsip: tcps0x7ffba03a TCP server transport created Verbose pjsip: tcplis:5054 TCP listener 192.168.3.33:5054: got incoming TCP connection from 192.168.3.32:35625, sock=197 Verbose pjsip: tcps0x7ffba003 TCP server transport created Verbose pjsip: tcps0x7ffba04c TCP connection closed Verbose pjsip: tcps0x7ffba04c TCP transport destroyed with reason 70016: End of file (PJ_EEOF) Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=1 (rdata0x7ffba02fa6a8) Verbose stack.cpp:244: RX 940 bytes Request msg REGISTER/cseq=1 (rdata0x7ffba02fa6a8) from TCP 192.168.3.32:52567: --start msg-- REGISTER sip:[email protected] SIP/2.0 Via: SIP/2.0/TCP 192.168.3.32:52567;rport;branch=z9hG4bKPjjgL-HazTwdApln.7hr7Qi2H0fM-TSuTg Path: <sip:[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/TCP 192.168.3.37:5060;rport=53424;received=10.40.7.177;branch=z9hG4bK-8556-1-2-2010000000- Max-Forwards: 70 Il giorno 23/dic/2014, alle ore 19:22, Eleanor Merry <[email protected]<mailto:[email protected]>> ha scritto: Hi, Can you confirm whether the requests generated by the stress tests reach Bono? The Bono debug logs will include the SIP REGISTER messages if it is processing the register. If it does, then can you please send me the Bono and Sprout logs for a registration generated by the stress scripts. Please do use a very low number of subscribers for this, otherwise the logs are hard to parse. You can change the number of subscribers used in the stress run by setting 'count=<low number>' in /etc/clearwater/config on your stress node, and restarting clearwater-sip-stress. You can turn on debug logging by creating/editing the file /etc/clearwater/user_settings, adding log_level=5 and then restarting the component (service <component> stop - it's automatically restarted by monit). The logs are output in /var/log/<component>/*. Thanks, Ellie -----Original Message----- From: Doctor Mescaline [mailto:[email protected]] Sent: 19 December 2014 10:58 To: Eleanor Merry Cc: Salil Sharma; [email protected]<mailto:[email protected]> Subject: Re: [Clearwater] Problem with Stress testing Hi Ellie, I manually installed Clearwater on six machine. I am also unable to get some result running the stress node, but I can perform calls by using sip clients or live tests. Running the stress script I got the following error “receive timeout on message Call Load Test: 3 without label to jump to (ontimeout attribute): aborting call.” Currently there’re registration requests but I don’t know if they are successful. It seems there’re no explicit error message in the server side (bono and sprout), except that one “pjsip: tsx0x7f019c02d Timeout timer event” Thanks Mescaline Il giorno 18/dic/2014, alle ore 19:28, Eleanor Merry <[email protected]<mailto:[email protected]>> ha scritto: Hi Salil, What error message do you get from the stress script (e.g. timeout/authentication failures/...). Are the registrations in the stress script successful? Also, can you check where the registration/call fails. For example, do the Bono logs show that Bono has received the registration/call? If so, then does the Sprout? To check this, can you use the stress scripts, but with a very low number of subscribers. This will let us track down the issue, without making the logs very hard to parse. You can change the number of subscribers used in the stress run by setting 'count=<low number>' in /etc/clearwater/config on your stress node, and restarting clearwater-sip-stress. You can turn on debug logging by creating/editing the file /etc/clearwater/user_settings, adding log_level=5 and then restarting the component (service <component> stop - it's automatically restarted by monit). The logs are output in /var/log/<component>/*. Thanks, Ellie -----Original Message----- From: [email protected]<mailto:[email protected]> [mailto:[email protected]] On Behalf Of Salil Sharma Sent: 14 December 2014 21:27 To: [email protected]<mailto:[email protected]> Subject: [Clearwater] Problem with Stress testing Dear Clearwater Developers, I wanted to perform Stress test on a manually installed all-in-one node of project Clearwater, and for the test I was using the clearwater-sip-stress package but I am unable to get some result. To be precise, I never get any successful call and all the calls get failed. I tried using SIPp emulator too and for this also I used the call_load2.xml i.e. the default xml scenario which clearwater-sip-stress package uses and the same line from the script for SIP test. The bulk provisioning on the node is done correctly, i have checked about it, by manually registering a client using Zoiper and the registration does takes place. The same was even observed on Wireshark as the aio node does responds back by 200 OK. I exactly don't even know what to comment on, is it the problem with the 200 OK reply which comes late or something else. But everytime I run the test it fails as there are no successful calls generated. -- Salil Sharma * <[email protected]<mailto:[email protected]>>* _______________________________________________ Clearwater mailing list [email protected]<mailto:[email protected]> http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected]<mailto:[email protected]> http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
