Hi Ellie, Good to know what is happening with the timers and REGISTERs.
Thank you very much for finding the problem with the OPTIONS! I'll have to raise that as a client issue. Best Regards, James. On 4 March 2014 14:48, Eleanor Merry <[email protected]> wrote: > Hi James, > > > > The timer errors you are seeing are benign in this case. They don't stop > registrations from succeeding or being authenticated. (There's a fix for > this issue (https://github.com/Metaswitch/cpp-common/issues/42) and it > will be present in our next release). > > > > The re-REGISTER not being challenged is fine - Bono recognises that it's > come over an authenticated flow, and adds > "integrity-protected=ip-assoc-yes" to the authorization header, which means > Sprout won't challenge it. If the registration expires, or is explicitly > deregistered, and then a client tries to register again then they will have > to be authenticated again. > > > > The OPTIONS poll is rejected because it's coming from a different source > than the REGISTER and so is not authenticated - the port in the Contact > header is different in the REGISTER and the OPTIONS. > > > > Ellie > > > > *From:* [email protected] [mailto: > [email protected]] *On Behalf Of *James > Coleman > *Sent:* 04 March 2014 14:01 > *To:* [email protected] > *Subject:* [Clearwater] chronos timer http 405 errors when receiving > REGISTER. > > > > Hello, > > > > With latest (Another Nine and a Half Weeks) release of clearwater chat is > working well initially. > > There is something a bit funny going on though maintaining chat for more > than a few minutes. > > When problem starts there seem to be a good few errors like this in sprout > logs: > > 03-03-2014 12:15:44.985 Error httpconnection.cpp:390: > http://localhost:7253/timers failed at server 127.0.0.1 : HTTP response > code said error (22 405) : fatal > > 03-03-2014 12:15:44.985 Error httpconnection.cpp:429: cURL failure with > cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 405 > > Those 405 errors always appear when REGISTER is received. > > After the 405 error seen the response to register is always 200 OK (even > if no Auth was done). > > > > In context . . . > > When an initial REGISTER is received from clients the usual sequence > happens: > > REGISTER(Auth empty)->, <-401(with nonce), REGISTER(with response)->, > <-200 OK > > OPTIONS queries happen. > > INVITE starting chat happens. > > REGISTER is sent again from client(s). > > Sprout logs a bunch of httpconnection.cpp timers errors. > > The RESISTER sequence seems to go okay sometimes. > > But other times I observed the initial REGISTER with empty Auth getting a > 200 OK response, > > Example of messages in sprout log when this happened: > > 03-03-2014 12:15:44.980 Info authentication.cpp:406: Request integrity > protected by edge proxy > > 03-03-2014 12:15:44.985 Error httpconnection.cpp:390: > http://localhost:7253/timers failed at server 127.0.0.1 : HTTP response > code said error (22 405) : fatal > > 03-03-2014 12:15:44.985 Error httpconnection.cpp:429: cURL failure with > cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 405 > > 03-03-2014 12:15:44.985 Verbose stack.cpp:237: TX 1010 bytes Response > msg 200/REGISTER/cseq=4729 (tdta0x7fcd3c373f80) to TCP 10.124.51.133:41827 > : > > I have included a log of this heppening below. > > It can be seen subsequent to the REGISTER 200 answer to REGISTER with > empty Auth info that an OPTIONS receives a 403 forbidden. > > > > Conclusion: > > Probably at that point in sprout if error retrieving timer then > REGISTER response should be error not 200. > > But I'm not sure what is causing the timer errors. > > > > Questions: > > What is causing those httpconnection.cpp timers errors? > > Is something misbehaving and how can it be fixed? > > > > Thanks for your help already with use of clearwater! > > > > James. > > > > my reference: > > grep Error sprout/sprout_20140303_1200.txt > > > > @12:15:44 in log > > | . | | > > | 15. SIP REGISTER(empty auth values) | > > |-------------------------------->| | > > | Error httpconnection.cpp:390: http://localhost:7253/timersfailed > in logs > > | 16. SIP 200 (OK with Service-Route)<------------->| > > |<--------------------------------| | > > | . | | > > 15. REGISTER with empty auth values sent > > 16. SIP 200 ok in response to empty auth values **PROBLEM** > > > > @12:16:48 in log > > | . | | > > | 17. SIP OPTIONS | | > > |-------------------------------->| | > > | 18. SIP 403 (Forbidden) | | > > |<--------------------------------| | > > | . | | > > > > 17. OPTIONS > > 18. OPTIONS answered with 403 forbidden. > > The system doesn't regard the handset as authenticated. > > > > > > From sprout log: REGISTER with empty auth received, timer error and > REGISTER response 200 > > > > 03-03-2014 12:15:44.242 Verbose pjsip: tcplis:5054 TCP listener > 10.124.51.133:5054: got incoming TCP connection from 10.124.51.133:35374, > sock=145 > > 03-03-2014 12:15:44.242 Verbose pjsip: tcps0x7fcd0c28 TCP server transport > created > > 03-03-2014 12:15:44.242 Verbose pjsip: tcplis:5054 TCP listener > 10.124.51.133:5054: got incoming TCP connection from 10.124.51.133:37834, > sock=190 > > 03-03-2014 12:15:44.242 Verbose pjsip: tcps0x7fcd0c39 TCP server transport > created > > 03-03-2014 12:15:44.248 Verbose pjsip: tcps0x7fcd0c38 TCP connection closed > > 03-03-2014 12:15:44.248 Verbose pjsip: tcps0x7fcd0c4c TCP connection closed > > 03-03-2014 12:15:44.248 Verbose pjsip: tcps0x7fcd0c38 TCP transport > destroyed with reason 70016: End of file (PJ_EEOF) > > 03-03-2014 12:15:44.248 Verbose pjsip: tcps0x7fcd0c4c TCP transport > destroyed with reason 70016: End of file (PJ_EEOF) > > 03-03-2014 12:15:44.980 Verbose stack.cpp:221: RX 1218 bytes Request msg > REGISTER/cseq=4729 (rdata0x7fcd0c0759a8) from TCP 10.124.51.133:41827: > > --start msg-- > > > > REGISTER sip:openims.test SIP/2.0 > > Path: sip:[email protected]:5058;transport=TCP;lr;ob > > Via: SIP/2.0/TCP 10.124.51.133:41827 > ;rport;branch=z9hG4bKPjFz9BQkd4gVzM0tYcYOZexCzzG3BumYHb > > Via: SIP/2.0/TCP 192.168.127.233:49470 > ;rport=49470;received=89.100.100.100;branch=z9hG4bKPjUKSUy86luxlm-qq.J.9V1brTiqzp2wxB > > Max-Forwards: 69 > > From: <sip:+353899999999 > @openims.test>;tag=7MQ6ubQ3jb1.kESJoDEWy8bai.8s63vB > > To: <sip:[email protected]> > > Call-ID: q6QfUaaLaOacs66AJ-VaE4fekF0yCW4T > > CSeq: 4729 REGISTER > > Authorization: DIGEST username="[email protected]", > realm="openims.test", nonce="", uri="sip:openims.test", > response="",integrity-protected=ip-assoc-yes > > User-Agent: IM-client/OMA1.0 RCSAndrd/2.3.14 COMLib/3.1.0 > > Contact: <sip:[email protected]:49470 > ;ob>;q=0.5;+sip.instance="<urn:gsma:imei:35592104-359096-5>";+g.3gpp.cs-voice;+g.3gpp.iari-ref="urn%3Aurn-7%3A3gpp-application.ims.iari.gsma-is";+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.oma.cpm.msg";+g.oma.sip-im > > Expires: 600000 > > Allow: PRACK, INFO, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > > Supported: gruu > > Route: <sip:10.124.51.133:5054;transport=TCP;lr;orig> > > Content-Length: 0 > > > > > > --end msg-- > > 03-03-2014 12:15:44.980 Info authentication.cpp:406: Request integrity > protected by edge proxy > > 03-03-2014 12:15:44.985 Error httpconnection.cpp:390: > http://localhost:7253/timers failed at server 127.0.0.1 : HTTP response > code said error (22 405) : fatal > > 03-03-2014 12:15:44.985 Error httpconnection.cpp:429: cURL failure with > cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 405 > > 03-03-2014 12:15:44.985 Verbose stack.cpp:237: TX 1010 bytes Response msg > 200/REGISTER/cseq=4729 (tdta0x7fcd3c373f80) to TCP 10.124.51.133:41827: > > --start msg-- > > > > SIP/2.0 200 OK > > Service-Route: <sip:10.124.51.133:5054;transport=TCP;lr;orig> > > Via: SIP/2.0/TCP 10.124.51.133:41827 > ;rport=41827;received=10.124.51.133;branch=z9hG4bKPjFz9BQkd4gVzM0tYcYOZexCzzG3BumYHb > > Via: SIP/2.0/TCP 192.168.127.233:49470 > ;rport=49470;received=89.100.100.100;branch=z9hG4bKPjUKSUy86luxlm-qq.J.9V1brTiqzp2wxB > > Call-ID: q6QfUaaLaOacs66AJ-VaE4fekF0yCW4T > > From: <sip:+353899999999 > @openims.test>;tag=7MQ6ubQ3jb1.kESJoDEWy8bai.8s63vB > > To: <sip:+353899999999 > @openims.test>;tag=z9hG4bKPjFz9BQkd4gVzM0tYcYOZexCzzG3BumYHb > > CSeq: 4729 REGISTER > > Supported: outbound > > Contact: sip:[email protected]:49470 > ;ob;q=0.5;expires=300;+sip.instance="<urn:gsma:imei:35592104-359096-5>";+g.3gpp.cs-voice;+g.3gpp.iari-ref="urn%3Aurn-7%3A3gpp-application.ims.iari.gsma-is";+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.oma.cpm.msg";+g.oma.sip-im > > Require: outbound > > Path: sip:[email protected]:5058;transport=TCP;lr;ob > > P-Associated-URI: sip:[email protected] > > Content-Length: 0 > > > > > > --end msg-- > > 03-03-2014 12:15:44.985 Info registration_utils.cpp:138: Found 0 > Application Servers > > > > . > > . > > > > 03-03-2014 12:16:49.120 Verbose stack.cpp:221: RX 1287 bytes Request msg > OPTIONS/cseq=23252 (rdata0x7f3f000a5648) from UDP 89.100.100.100:56338: > > --start msg-- > > > > OPTIONS sip:[email protected];user=phone SIP/2.0 > > Via: SIP/2.0/UDP 192.168.127.233:56338 > ;rport;branch=z9hG4bKPjq84tpUZyMULIysDiJo.0qBe1Axv8hSnt > > Max-Forwards: 70 > > From: <sip:+353899999999 > @openims.test>;tag=Wd4vdsXM4qLmhNRE6v3fZKxc42N3BFe0 > > To: <sip:[email protected];user=phone> > > Call-ID: fvJU1oQSTgPXvf0FG1K2j3Dyt6GqUQQV > > CSeq: 23252 OPTIONS > > Route: <sip:54.199.199.199:5060;lr> > > Route: <sip:10.124.51.133:5054;transport=TCP;lr;orig> > > User-Agent: IM-client/OMA1.0 RCSAndrd/2.3.14 COMLib/3.1.0 > > Contact: <sip:[email protected]:56338 > ;ob>;+g.3gpp.iari-ref="urn%3Aurn-7%3A3gpp-application.ims.iari.joyn.intmsg,urn%3Aurn-7%3A3gpp-application.ims.iari.rcs.ftthu > > mb,urn%3Aurn-7%3A3gpp-application.ims.iari.rcse.ft,urn%3Aurn-7% > 3A3gpp-application.ims.iari.rcse.im > ";+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.oma.cpm.msg";+sip.i > > nstance="<urn:gsma:imei:35592104-359096-5>" > > Accept-Contact: > *;+g.3gpp.iari-ref="urn%3Aurn-7%3A3gpp-application.ims.iari.joyn.intmsg,urn%3Aurn-7%3A3gpp-application.ims.iari.rcs.ftthumb,urn%3Aurn-7%3A3gpp-application.im > > s.iari.rcse.ft,urn%3Aurn-7%3A3gpp-application.ims.iari.rcse.im > ";+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.oma.cpm.msg" > > P-Preferred-Identity: <sip:[email protected]> > > Content-Length: 0 > > > > > > --end msg-- > > 03-03-2014 12:16:49.120 Warning stateful_proxy.cpp:1193: Rejecting request > from untrusted source > > 03-03-2014 12:16:49.120 Verbose stack.cpp:237: TX 406 bytes Response msg > 403/OPTIONS/cseq=23252 (tdta0x7f3eec001870) to UDP 89.100.100.100:56338: > > --start msg-- > > > > SIP/2.0 403 Forbidden > > Via: SIP/2.0/UDP 192.168.127.233:56338 > ;rport=56338;received=89.100.100.100;branch=z9hG4bKPjq84tpUZyMULIysDiJo.0qBe1Axv8hSnt > > Call-ID: fvJU1oQSTgPXvf0FG1K2j3Dyt6GqUQQV > > From: <sip:[email protected] > >;tag=Wd4vdsXM4qLmhNRE6v3fZKxc42N3BFe0 > > To: <sip:[email protected] > ;user=phone>;tag=z9hG4bKPjq84tpUZyMULIysDiJo.0qBe1Axv8hSnt > > CSeq: 23252 OPTIONS > > Content-Length: 0 > > > > > > --end msg-- > > > > > [image: Image removed by sender.] > > > > [image: Image removed by > sender.]<http://www.linkedin.com/company/76647?trk=fc_badge> > > > openmindnetworks.com > -- <http://www.linkedin.com/company/76647?trk=fc_badge> openmindnetworks.com
<<inline: ~WRD000.jpg>>
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
