[OpenSIPS-Users] Request Timeout on INVITE After Idle Registration

Bogdan-Andrei Iancu bogdan at opensips.org
Tue Jan 19 12:18:39 CET 2016


According to the logs, the INVITE is sent out :

Jan 13 06:12:08 server1 opensips: Jan 13 06:12:08 [17457] 
DBG:core:_shm_resize: resize(0) called
Jan 13 06:12:08 server1 opensips: Jan 13 06:12:08 [17457] 
DBG:core:mk_proxy: doing DNS lookup...
Jan 13 06:12:08 server1 opensips: Jan 13 06:12:08 [17457] 
DBG:tm:set_timer: relative timeout is 500000
Jan 13 06:12:08 server1 opensips: Jan 13 06:12:08 [17457] 
DBG:tm:insert_timer_unsafe: [4]: 0x7f8518e24938 (7092500000)
Jan 13 06:12:08 server1 opensips: Jan 13 06:12:08 [17457] 
DBG:tm:insert_timer_unsafe: [0]: 0x7f8518e24968 (7097)
Jan 13 06:12:08 server1 opensips: Jan 13 06:12:08 [17457] 
DBG:tm:t_relay_to: new transaction fwd'ed


there, are several retransmissions:

Jan 13 06:12:09 server1 opensips: Jan 13 06:12:09 [17458] 
DBG:tm:retransmission_handler: retransmission_handler : request 
resending (t=0x7f8518e24718, INVITE si ... )
Jan 13 06:12:10 server1 opensips: Jan 13 06:12:10 [17467] 
DBG:tm:retransmission_handler: retransmission_handler : request 
resending (t=0x7f8518e24718, INVITE si ... )
Jan 13 06:12:12 server1 opensips: Jan 13 06:12:12 [17458] 
DBG:tm:retransmission_handler: retransmission_handler : request 
resending (t=0x7f8518e24718, INVITE si ... )

and finally, on timeout, it is canceled (toward UAS) and 408 reply 
generated:

Jan 13 06:12:14 server1 opensips: Jan 13 06:12:14 [17457] 
DBG:tm:final_response_handler: Cancel sent out, sending 408 (0x7f8518e24718)
Jan 13 06:12:14 server1 opensips: Jan 13 06:12:14 [17457] 
DBG:tm:t_should_relay_response: T_code=100, new_code=408
Jan 13 06:12:14 server1 opensips: Jan 13 06:12:14 [17457] 
DBG:tm:t_pick_branch: picked branch 0, code 408 (prio=800)
Jan 13 06:12:14 server1 opensips: Jan 13 06:12:14 [17457] 
DBG:tm:relay_reply: sent buf=0x7f851f8e9518: SIP/2.0 4..., 
shmem=0x7f8518e6f618: SIP/2.0 4

I see even a ACC log is created:

Jan 13 06:12:14 server1 opensips: ACC: call missed: 
timestamp=1452665534;method=INVITE;from_tag=z9hG4bK17850112;to_tag=;call_id=369319113465 at 10.121.239.28;code=408;reason=Request 
Timeout


So, everything looks good here.

Regards,

Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
http://www.opensips-solutions.com

On 13.01.2016 08:19, Nabeel wrote:
> Hi Bogdan,
>
> I changed log_stderror=yes and log_facility=LOG_DAEMON. Now I see some 
> more in the log.  Do you see anything obviously wrong?
>
> http://pastebin.com/MzJW1P1S
>
> On 12 January 2016 at 09:10, Bogdan-Andrei Iancu <bogdan at opensips.org 
> <mailto:bogdan at opensips.org>> wrote:
>
>     Hi Nabeel,
>
>     Be sure you are looking into the right log file - maybe the debug
>     level is redirected by your syslog to another log file... Debug
>     level 4 is the most verbose one in opensips.
>
>     Regards,
>
>     Bogdan-Andrei Iancu
>     OpenSIPS Founder and Developer
>     http://www.opensips-solutions.com
>
>     On 08.01.2016 21:04, Nabeel wrote:
>>
>>     Hi Bogdan,
>>
>>     I have the following near the top of my config file:
>>
>>     ###### Global Parameters #########
>>
>>     debug=4
>>     log_stderror=no
>>     log_facility=LOG_LOCAL1
>>
>>     The log I posted earlier is from opensips running with these
>>     configurations.
>>
>>     On 8 Jan 2016 3:49 pm, "Bogdan-Andrei Iancu" <bogdan at opensips.org
>>     <mailto:bogdan at opensips.org>> wrote:
>>
>>         Hi Nabeel,
>>
>>         have you tried running opensips is debug mode (level 4) to
>>         see what it is doing with the request ?
>>
>>         Regards,
>>
>>         Bogdan-Andrei Iancu
>>         OpenSIPS Founder and Developer
>>         http://www.opensips-solutions.com
>>
>>         On 07.01.2016 11:37, Nabeel wrote:
>>>
>>>         Hi Bogdan,
>>>
>>>         I used the tshark command as explained here on page 14:
>>>         http://opensips.org/pub/events/2015-05-12_OpenSIPS-Summit_Amsterdam/Lorenzo_
>>>         <http://opensips.org/pub/events/2015-05-12_OpenSIPS-Summit_Amsterdam/Lorenzo_Mangani-OpenSIPS_Summit2015-SIPCapture.pdf>Mangani-OpenSIPS
>>>         <http://opensips.org/pub/events/2015-05-12_OpenSIPS-Summit_Amsterdam/Lorenzo_Mangani-OpenSIPS_Summit2015-SIPCapture.pdf>_
>>>         <http://opensips.org/pub/events/2015-05-12_OpenSIPS-Summit_Amsterdam/Lorenzo_Mangani-OpenSIPS_Summit2015-SIPCapture.pdf>Summit2015-SIPCapture.pdf
>>>         <http://opensips.org/pub/events/2015-05-12_OpenSIPS-Summit_Amsterdam/Lorenzo_Mangani-OpenSIPS_Summit2015-SIPCapture.pdf>
>>>
>>>         tshark -o "ssl.desegment_ssl_records: TRUE"  -o
>>>         "ssl.desegment_ssl_application_data: TRUE"  -o
>>>         "ssl.keys_list:
>>>         162.249.6.110,5061,sip,/install/tls/domain.com-key.pem" -i
>>>         eth0  -f "tcp port 5061"
>>>
>>>         I'm using a command line version of Linux without a graphic
>>>         UI, so I could not "configure Wireshark to decide TLS" as
>>>         mentioned in that document, however I did pass the private
>>>         key in the command as shown above.
>>>
>>>         Does tshark require configuring to decode TLS, other than
>>>         passing the private key in the command?
>>>
>>>         Hi Nabeel,
>>>
>>>         Indeed, the 408 seems generated by OpenSIPS (after 5
>>>         seconds). Such reply is generated only if the the request
>>>         was actually sent out (if no request sent, there is no
>>>         timeout). But the network capture does not show anything :(
>>>         ... maybe wrong capturing ?
>>>
>>>         So you see anything in the logs ? have you tried to run with
>>>         debug level 4 ?
>>>
>>>         Regards,
>>>         Bogdan-Andrei Iancu
>>>         OpenSIPS Founder and Developer
>>>         http://www.opensips-solutions.com
>>>         On 06.01.2016 23:07, Nabeel wrote:
>>>>         I managed to capture the SIP traffic with Wireshark.  It
>>>>         seems that the party generating the 408 reply is OpenSIPS,
>>>>         not the callee. OpenSIPS does not seem to forward the call
>>>>         to the callee at all.
>>>>
>>>>         Below are traces showing a successful call and a call with
>>>>         Request Timeout.
>>>>         The server IP is 162.249.6.110, the caller IP is
>>>>         92.40.249.9, and the callee IP is 188.29.165.24.
>>>>
>>>>         Trace for a successful call:
>>>>
>>>>         http://pastebin.com/2xn0bkEU
>>>>
>>>>         Trace for a call with Request Timeout:
>>>>
>>>>         http://pastebin.com/WR7BA6pj
>>>>
>>>>         Please advise what may be causing this.
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>
>>
>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20160119/825957d6/attachment-0001.htm>


More information about the Users mailing list