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:[email protected]>;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:[email protected]>;tag=7MQ6ubQ3jb1.kESJoDEWy8bai.8s63vB
To: <sip:[email protected]
>;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:[email protected]>;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--

-- 


<http://www.linkedin.com/company/76647?trk=fc_badge>

openmindnetworks.com
_______________________________________________
Clearwater mailing list
[email protected]
http://lists.projectclearwater.org/listinfo/clearwater

Reply via email to