[OpenSIPS-Devel] Crash in OpenSIPS 2.1.4 (tm?)
Maxim Sobolev
sobomax at sippysoft.com
Mon Mar 6 11:59:05 EST 2017
The code leading to a crash is following:
/* lock reply processing to determine how to proceed reliably */
LOCK_REPLIES( t );
We also see a lot of messages like this before the crash:
Mar 6 16:41:17 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365200 ms (now 15365390 ms), it may overlap..
Mar 6 16:41:17 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365390 ms (now 15365490 ms), it may overlap..
Mar 6 16:41:17 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365490 ms (now 15365590 ms), it may overlap..
Mar 6 16:41:17 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365590 ms (now 15365680 ms), it may overlap..
Mar 6 16:41:17 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365680 ms (now 15365780 ms), it may overlap..
Mar 6 16:41:17 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365780 ms (now 15365870 ms), it may overlap..
Mar 6 16:41:17 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365870 ms (now 15365970 ms), it may overlap..
Mar 6 16:41:18 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15365970 ms (now 15366070 ms), it may overlap..
Mar 6 16:41:18 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:timer_ticker: timer task <ul-timer> already scheduled for
15363310 ms (now 15366070 ms), it may overlap..
Mar 6 16:41:18 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:timer_ticker: timer task <dlg-timer> already scheduled for
15363310 ms (now 15366070 ms), it may overlap..
Mar 6 16:41:18 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:timer_ticker: timer task <tm-timer> already scheduled for
15362340 ms (now 15366070 ms), it may overlap..
Mar 6 16:41:18 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:timer_ticker: timer task <blcore-expire> already scheduled for
15363310 ms (now 15366070 ms), it may overlap..
Mar 6 16:41:18 jenv_1 /usr/local/sbin/opensips[27453]:
WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for
15366070 ms (now 15366160 ms), it may overlap..
On Mon, Mar 6, 2017 at 8:51 AM, Maxim Sobolev <sobomax at sippysoft.com> wrote:
> Hi folks,
>
> We have observed the following crash in the OpenSIPS:
>
> $ sudo gdb712 /usr/local/sbin/opensips ~/opensips.27455.core
> GNU gdb (GDB) 7.12 [GDB v7.12 for FreeBSD]
> Core was generated by `opensips'.
> Program terminated with signal SIGABRT, Aborted.
> #0 0x0000000800ccf39a in thr_kill () from /lib/libc.so.7
> [Current thread is 1 (LWP 100588)]
> (gdb) bt
> #0 0x0000000800ccf39a in thr_kill () from /lib/libc.so.7
> #1 0x0000000800ccf386 in raise () from /lib/libc.so.7
> #2 0x0000000800ccf309 in abort () from /lib/libc.so.7
> #3 0x00000008009fe95a in ?? () from /lib/libthr.so.3
> #4 0x00000008009fa046 in ?? () from /lib/libthr.so.3
> #5 0x0000000801a148e1 in _lock (s=0x805003800) at lock.h:100
> #6 0x0000000801a14e84 in final_response_handler (fr_tl=0x805002078) at
> timer.c:389
> #7 0x0000000801a1664a in timer_routine (ticks=15362, set=0x0) at
> timer.c:1066
> #8 0x00000000004544dd in handle_timer_job () at timer.c:567
> #9 0x0000000000519920 in handle_io (fm=0x80142e670, idx=1, event_type=1)
> at net/net_udp.c:265
> #10 0x00000000005187ca in io_wait_loop_kqueue (h=0x8b6300 <_worker_io>,
> t=1, repeat=0) at net/../io_wait_loop.h:281
> #11 0x0000000000519bed in udp_rcv_loop (si=0x80141ff98) at
> net/net_udp.c:308
> #12 0x000000000051a5c0 in udp_start_processes (chd_rank=0x7d56c8
> <chd_rank>, startup_done=0x0) at net/net_udp.c:448
> #13 0x00000000004318a5 in main_loop () at main.c:731
> #14 0x0000000000433c79 in main (argc=9, argv=0x7fffffffe950) at main.c:1271
>
> The opensips configuration is:
>
> if (method == "INVITE") {
> if (!t_newtran()) {
> sl_reply_error();
> exit;
> };
> };
> # Do strict routing if pre-loaded route headers present
> if (loose_route() && !(method == "INVITE")) {
> t_relay();
> exit;
> };
> if ((!lookup("location") && method == "INVITE" && uri == myself)
> || uri == myself) {
> sl_send_reply("404", "Not Found");
> exit;
> };
> if (method == "INVITE") {
> record_route();
> };
> if (!t_relay()) {
> sl_reply_error();
> };
>
> SIP exchange leading to this is below. It's basically case of the call
> that has been cancelled on the side A but INVITE got no provisional reply
> on side B.
>
> -Max
>
> 6 Mar 16:40:42.156/GLOBAL/opensips[27445]: RECEIVED message from
> 1.2.3.4:5067:
> INVITE sip:kenny_teSt-onnet1 at 1.2.3.4:5060 SIP/2.0
> Via: SIP/2.0/UDP 1.2.3.4:5067;branch=z9hG4bK7f6a37ed46c2b41312b994c
> 78f9953d5;rport
> Max-Forwards: 70
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 INVITE
> Contact: Anonymous <sip:kEnny_teSt-onnet1 at 1.2.3.4:5067>
> Expires: 300
> User-Agent: Sippy Softswitch v5.0-dev.166
> cisco-GUID: 795718100-3120542206-472987301-3288912555
> h323-conf-id: 795718100-3120542206-472987301-3288912555
> Content-Length: 532
> Content-Type: application/sdp
>
> v=0
> o=- 3697803640 3697803640 IN IP4 192.168.0.110
> s=pjmedia
> b=AS:84
> t=0 0
> a=X-nat:0
> m=audio 4010 RTP/AVP 8 0 18 3 120 97 119 117 110 101
> c=IN IP4 192.168.0.110
> b=TIAS:64000
> a=rtcp:4011 IN IP4 192.168.0.110
> a=sendrecv
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:3 GSM/8000
> a=rtpmap:120 AMR/8000
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:119 speex/32000
> a=rtpmap:117 speex/16000
> a=rtpmap:110 speex/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
>
>
> 6 Mar 16:40:42.156/GLOBAL/opensips[27445]: SENDING message to 1.2.3.4:5067
> :
> SIP/2.0 100 Giving a try
> Via: SIP/2.0/UDP 1.2.3.4:5067;received=1.2.3.4;branch=
> z9hG4bK7f6a37ed46c2b41312b994c78f9953d5;rport=5067
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 INVITE
> Server: Sippy Softswitch v5.0-dev.166
> Content-Length: 0
>
>
> 6 Mar 16:40:42.157/GLOBAL/opensips[27445]: SENDING message to
> 192.168.0.110:60131:
> INVITE sip:kenny_teSt-onnet1 at 192.168.0.110:60131;ob SIP/2.0
> Record-Route: <sip:1.2.3.4;lr;ftag=eac8d4a10d1042c839d945086b0656d2>
> Via: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bKb971.8a172365.0
> Via: SIP/2.0/UDP 1.2.3.4:5067;received=1.2.3.4;branch=
> z9hG4bK7f6a37ed46c2b41312b994c78f9953d5;rport=5067
> Max-Forwards: 69
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 INVITE
> Contact: Anonymous <sip:kEnny_teSt-onnet1 at 1.2.3.4:5067>
> Expires: 300
> User-Agent: Sippy Softswitch v5.0-dev.166
> cisco-GUID: 795718100-3120542206-472987301-3288912555
> h323-conf-id: 795718100-3120542206-472987301-3288912555
> Content-Length: 532
> Content-Type: application/sdp
>
> v=0
> o=- 3697803640 3697803640 IN IP4 192.168.0.110
> s=pjmedia
> b=AS:84
> t=0 0
> a=X-nat:0
> m=audio 4010 RTP/AVP 8 0 18 3 120 97 119 117 110 101
> c=IN IP4 192.168.0.110
> b=TIAS:64000
> a=rtcp:4011 IN IP4 192.168.0.110
> a=sendrecv
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:3 GSM/8000
> a=rtpmap:120 AMR/8000
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:119 speex/32000
> a=rtpmap:117 speex/16000
> a=rtpmap:110 speex/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
>
>
> 6 Mar 16:40:42.664/GLOBAL/opensips[27445]: SENDING message to
> 192.168.0.110:60131:
> INVITE sip:kenny_teSt-onnet1 at 192.168.0.110:60131;ob SIP/2.0
> Record-Route: <sip:1.2.3.4;lr;ftag=eac8d4a10d1042c839d945086b0656d2>
> Via: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bKb971.8a172365.0
> Via: SIP/2.0/UDP 1.2.3.4:5067;received=1.2.3.4;branch=
> z9hG4bK7f6a37ed46c2b41312b994c78f9953d5;rport=5067
> Max-Forwards: 69
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 INVITE
> Contact: Anonymous <sip:kEnny_teSt-onnet1 at 1.2.3.4:5067>
> Expires: 300
> User-Agent: Sippy Softswitch v5.0-dev.166
> cisco-GUID: 795718100-3120542206-472987301-3288912555
> h323-conf-id: 795718100-3120542206-472987301-3288912555
> Content-Length: 532
> Content-Type: application/sdp
>
> v=0
> o=- 3697803640 3697803640 IN IP4 192.168.0.110
> s=pjmedia
> b=AS:84
> t=0 0
> a=X-nat:0
> m=audio 4010 RTP/AVP 8 0 18 3 120 97 119 117 110 101
> c=IN IP4 192.168.0.110
> b=TIAS:64000
> a=rtcp:4011 IN IP4 192.168.0.110
> a=sendrecv
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:3 GSM/8000
> a=rtpmap:120 AMR/8000
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:119 speex/32000
> a=rtpmap:117 speex/16000
> a=rtpmap:110 speex/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
>
> 6 Mar 16:40:52.139/GLOBAL/opensips[27445]: RECEIVED message from
> 1.2.3.4:5067:
> CANCEL sip:kenny_teSt-onnet1 at 1.2.3.4:5060 SIP/2.0
> Via: SIP/2.0/UDP 1.2.3.4:5067;rport;branch=z9hG4bK7f6a37ed46c2b41312b994c
> 78f9953d5
> Max-Forwards: 70
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 CANCEL
> User-Agent: Sippy Softswitch v5.0-dev.166
> Content-Length: 0
>
>
> 6 Mar 16:40:52.140/GLOBAL/opensips[27445]: SENDING message to 1.2.3.4:5067
> :
> SIP/2.0 200 canceling
> Via: SIP/2.0/UDP 1.2.3.4:5067;received=1.2.3.4;rport=5067;branch=
> z9hG4bK7f6a37ed46c2b41312b994c78f9953d5
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>;tag=51bbe412150d8b6167b2d0523a6431
> c1-c48a
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 CANCEL
> Server: Sippy Softswitch v5.0-dev.166
> Content-Length: 0
>
> 6 Mar 16:41:02.900/GLOBAL/opensips[27445]: SENDING message to
> 192.168.0.110:60131:
> INVITE sip:kenny_teSt-onnet1 at 192.168.0.110:60131;ob SIP/2.0
> Record-Route: <sip:1.2.3.4;lr;ftag=eac8d4a10d1042c839d945086b0656d2>
> Via: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bKb971.8a172365.0
> Via: SIP/2.0/UDP 1.2.3.4:5067;received=1.2.3.4;branch=
> z9hG4bK7f6a37ed46c2b41312b994c78f9953d5;rport=5067
> Max-Forwards: 69
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 INVITE
> Contact: Anonymous <sip:kEnny_teSt-onnet1 at 1.2.3.4:5067>
> Expires: 300
> User-Agent: Sippy Softswitch v5.0-dev.166
> cisco-GUID: 795718100-3120542206-472987301-3288912555
> h323-conf-id: 795718100-3120542206-472987301-3288912555
> Content-Length: 532
> Content-Type: application/sdp
>
> v=0
> o=- 3697803640 3697803640 IN IP4 192.168.0.110
> s=pjmedia
> b=AS:84
> t=0 0
> a=X-nat:0
> m=audio 4010 RTP/AVP 8 0 18 3 120 97 119 117 110 101
> c=IN IP4 192.168.0.110
> b=TIAS:64000
> a=rtcp:4011 IN IP4 192.168.0.110
> a=sendrecv
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:3 GSM/8000
> a=rtpmap:120 AMR/8000
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:119 speex/32000
> a=rtpmap:117 speex/16000
> a=rtpmap:110 speex/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
>
> 6 Mar 16:41:07.188/GLOBAL/opensips[27445]: SENDING message to
> 192.168.0.110:60131:
> INVITE sip:kenny_teSt-onnet1 at 192.168.0.110:60131;ob SIP/2.0
> Record-Route: <sip:1.2.3.4;lr;ftag=eac8d4a10d1042c839d945086b0656d2>
> Via: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bKb971.8a172365.0
> Via: SIP/2.0/UDP 1.2.3.4:5067;received=1.2.3.4;branch=
> z9hG4bK7f6a37ed46c2b41312b994c78f9953d5;rport=5067
> Max-Forwards: 69
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 INVITE
> Contact: Anonymous <sip:kEnny_teSt-onnet1 at 1.2.3.4:5067>
> Expires: 300
> User-Agent: Sippy Softswitch v5.0-dev.166
> cisco-GUID: 795718100-3120542206-472987301-3288912555
> h323-conf-id: 795718100-3120542206-472987301-3288912555
> Content-Length: 532
> Content-Type: application/sdp
>
> v=0
> o=- 3697803640 3697803640 IN IP4 192.168.0.110
> s=pjmedia
> b=AS:84
> t=0 0
> a=X-nat:0
> m=audio 4010 RTP/AVP 8 0 18 3 120 97 119 117 110 101
> c=IN IP4 192.168.0.110
> b=TIAS:64000
> a=rtcp:4011 IN IP4 192.168.0.110
> a=sendrecv
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:3 GSM/8000
> a=rtpmap:120 AMR/8000
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:119 speex/32000
> a=rtpmap:117 speex/16000
> a=rtpmap:110 speex/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
>
> 6 Mar 16:41:11.480/GLOBAL/opensips[27445]: SENDING message to
> 192.168.0.110:60131:
> INVITE sip:kenny_teSt-onnet1 at 192.168.0.110:60131;ob SIP/2.0
> Record-Route: <sip:1.2.3.4;lr;ftag=eac8d4a10d1042c839d945086b0656d2>
> Via: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bKb971.8a172365.0
> Via: SIP/2.0/UDP 1.2.3.4:5067;received=1.2.3.4;branch=
> z9hG4bK7f6a37ed46c2b41312b994c78f9953d5;rport=5067
> Max-Forwards: 69
> From: <sip:kEnny_teSt-onnet1 at 1.2.3.4>;tag=eac8d4a10d1042c839d945086b0656d2
> To: <sip:kenny_teSt-onnet1 at 1.2.3.4>
> Call-ID: ef28002a1d6d40b79314ef6af21ed1e5-onnet_1-b2b_1
> CSeq: 200 INVITE
> Contact: Anonymous <sip:kEnny_teSt-onnet1 at 1.2.3.4:5067>
> Expires: 300
> User-Agent: Sippy Softswitch v5.0-dev.166
> cisco-GUID: 795718100-3120542206-472987301-3288912555
> h323-conf-id: 795718100-3120542206-472987301-3288912555
> Content-Length: 532
> Content-Type: application/sdp
>
> v=0
> o=- 3697803640 3697803640 IN IP4 192.168.0.110
> s=pjmedia
> b=AS:84
> t=0 0
> a=X-nat:0
> m=audio 4010 RTP/AVP 8 0 18 3 120 97 119 117 110 101
> c=IN IP4 192.168.0.110
> b=TIAS:64000
> a=rtcp:4011 IN IP4 192.168.0.110
> a=sendrecv
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:3 GSM/8000
> a=rtpmap:120 AMR/8000
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:119 speex/32000
> a=rtpmap:117 speex/16000
> a=rtpmap:110 speex/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
>
>
--
Maksym Sobolyev
Sippy Software, Inc.
Internet Telephony (VoIP) Experts
Tel (Canada): +1-778-783-0474
Tel (Toll-Free): +1-855-747-7779
Fax: +1-866-857-6942
Web: http://www.sippysoft.com
MSN: sales at sippysoft.com
Skype: SippySoft
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/devel/attachments/20170306/0029e1ea/attachment-0001.html>
More information about the Devel
mailing list