Hi, I have attached the logs from the stress run.
Thanks for your help > Il giorno 08/gen/2015, alle ore 20:16, Eleanor Merry > <[email protected]> ha scritto: > > 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] > <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:[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 > <sip:demo.clearwater;transport=TCP;lr>> > Max-Forwards: 70 > From: <sip:[email protected] > <sip:[email protected]>>;tag=28936SIPpTag001 > To: <sip:[email protected] <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:[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 <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 > <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 <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 > <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] <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:[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 > <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] > <sip:[email protected]>>;tag=28936SIPpTag001 > To: <sip:[email protected] <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:[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 > <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] > <sip:[email protected]>>;tag=28936SIPpTag001 > To: <sip:[email protected] > <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] > <sip:[email protected]>>;tag=28936SIPpTag001 > To: <sip:[email protected] > <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] > <sip:[email protected]>>;tag=1299406 > To: <sip:[email protected] > <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] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[email protected]>:5060;transport=TCP;ob EXPIRES=300 > Registration: USER_URI=sip:[email protected] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[email protected]>:5060;transport=TCP;ob EXPIRES=300 > Registration: USER_URI=sip:[email protected] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[email protected]>:53424;transport=TCP;ob EXPIRES=300 > Registration: USER_URI=sip:[email protected] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[email protected]>:53424;transport=TCP;ob EXPIRES=300 > Registration: USER_URI=sip:[email protected] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[email protected]>:53424;transport=TCP;ob EXPIRES=300 > Registration: USER_URI=sip:[email protected] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[email protected]>:53424;transport=TCP;ob EXPIRES=300 > Registration: USER_URI=sip:[email protected] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[email protected]>:53424;transport=TCP;ob EXPIRES=300 > Registration: USER_URI=sip:[email protected] > <mailto:[email protected]> > BINDING_ID=<urn:uuid:00000000-0000-0000-0000-000000000001>:1 > CONTACT_URI=sip:[email protected] > <mailto:[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:[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 > <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] > <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] > <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 > <http://lists.projectclearwater.org/listinfo/clearwater> > _______________________________________________ > Clearwater mailing list > [email protected] > <mailto:[email protected]> > http://lists.projectclearwater.org/listinfo/clearwater > <http://lists.projectclearwater.org/listinfo/clearwater> _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
