OpenSIPS / opensips

OpenSIPS is a GPL implementation of a multi-functionality SIP Server that targets to deliver a high-level technical solution (performance, security and quality) to be used in professional SIP server platforms.
https://opensips.org
Other
1.28k stars 580 forks source link

b2b_init_request Crash #3109

Closed inderjeetsharma closed 1 year ago

inderjeetsharma commented 1 year ago

opensips 3.4.0-beta (x86_64/linux)

I'm encountering a segmentation fault error when attempting to initialize a B2b invite with top hiding.

if (is_method("INVITE")) { xlog("INVIETEEEEEEEEEEEEE\n"); $du="sip:172.17.0.2:5060"; xlog("$fU $tU $ci $rm Relaying Request to $ru"); xlog("$fU $tU $ci $rm Calling function b2b_init"); b2b_init_request("top hiding");

do_accounting("log");

            xlog("B2BUA\n");
            exit;
    }

Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:b2b_entities:b2b_prescript_f: start - method = INVITE Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:b2b_entities:b2b_prescript_f: host:port [telephony5.abc.com][5060] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:grep_sock_info_ext: checking if host==us: 21==10 && [telephony5.abc.com] == [172.17.0.4] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:grep_sock_info_ext: checking if port 5060 matches port 5060 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:check_self: host != me Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:b2b_entities:b2b_prescript_f: RURI does not point to me Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:maxfwd:is_maxfwd_present: value = 69 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:sipmsgops:has_totag: no totag Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: flags=78 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:tm:t_lookup_request: start searching: hash=17119, isACK=0 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:tm:matching_3261: RFC3261 transaction matching failed Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:tm:t_lookup_request: no transaction found Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: flags=200 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:rr:find_first_route: No Route headers found Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:rr:loose_route: There is no Route HF Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: INVIETEEEEEEEEEEEEE Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_to_param: tag=6d16ec19 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_to_param: end of header reached, state=11 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:_parse_to: end of header reached, state=29 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:_parse_to: display={}, ruri={sip:1001@telephony5.abc.com:5060;transport=UDP} Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: 1001 1002 UUuYuGea2br4IYZ-vDmQgQ.. INVITE Relaying Request to sip:1002@telephony5.abc.com:5060;transport=UDP Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: 1001 1002 UUuYuGea2br4IYZ-vDmQgQ.. INVITE Calling function b2b_init Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: flags=ffffffffffffffff Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_msg: SIP Request: Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_msg: method: Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_msg: uri: sip:1002@telephony5.abc.com:5060;transport=UDP Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_msg: version: <SIP/2.0> Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: flags=ffffffffffffffff Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_via_param: found param type 232, = ; state=16 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_via: end of header reached, state=5 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: via found, flags=ffffffffffffffff Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: this is the first via Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_via_param: found param type 232, = ; state=16 Jun 6 13:51:31 telephony5 kernel: [10912218.864678] opensips[41002150]: segfault at 8 ip 00005643d546d570 sp 00007ffc1ba22eb0 error 4 in opensips[5643d53fd000+1c1000] Jun 6 13:51:31 telephony5 kernel: [10912218.872334] Code: 48 83 c4 48 5b 41 5c 41 5d 5d c3 55 48 89 e5 41 57 41 56 41 55 41 54 53 48 81 ec c8 00 00 00 48 89 7d b8 89 75 b4 48 8b 45 b8 <8b> 40 08 48 98 48 83 c0 29 b9 64 01 00 00 48 8d 15 fb cf 17 00 48 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_via: end of header reached, state=5 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: via found, flags=ffffffffffffffff Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: parse_headers: this is the second via Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:_parse_to: end of header reached, state=10 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:_parse_to: display={}, ruri={sip:1002@telephony5.abc.com:5060;transport=UDP} Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:get_hdr_field: [52]; uri=[sip:1002@telephony5.abc.com:5060;transport=UDP] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:get_hdr_field: to body [sip:1002@telephony5.abc.com:5060;transport=UDP#015#012] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:get_hdr_field: cseq : <1> Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:get_hdr_field: content_length=245 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:get_hdr_field: found end of header Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: flags=ffffffffffffffff Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: flags=ffffffffffffffff Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_to_param: tag=6d16ec19 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_to_param: end of header reached, state=11 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:_parse_to: end of header reached, state=29 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:_parse_to: display={}, ruri={sip:1001@telephony5.abc.com:5060;transport=UDP} Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:b2b_logic:udh_to_uri: user:host:port [1002][telephony5.abc.com][5060] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:parse_headers: flags=ffffffffffffffff Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:b2b_logic:b2bl_insert_new: hash index [1010]: Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:b2b_logic:b2bl_insert_new: id [0] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: CRITICAL:core:sig_usr: segfault in process pid: 86209, id: 7 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:restore_segv_handler: restoring SIGSEGV handler... Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86209]: DBG:core:restore_segv_handler: successfully restored system SIGSEGV handler Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:core:handle_sigs: OpenSIPS exit status = 11 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:handle_sigs: child process 86209 exited by a signal 11 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:handle_sigs: core was not generated Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:handle_sigs: terminating due to SIGCHLD Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:core:shutdown_opensips: Asking process 1 [MI FIFO] to terminate Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:core:shutdown_opensips: Asking process 4 [SIP receiver udp:172.17.0.4:5060] to terminate Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:core:shutdown_opensips: Asking process 5 [SIP receiver udp:172.17.0.4:5060] to terminate Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:core:shutdown_opensips: Asking process 6 [SIP receiver udp:172.17.0.4:5060] to terminate Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:core:shutdown_opensips: Asking process 8 [Timer handler] to terminate Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86205]: INFO:core:sig_usr: signal 15 received Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86206]: DBG:core:rpc_process_terminate: Process 4 exiting with code 0... Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86203]: DBG:core:rpc_process_terminate: Process 1 exiting with code 0... Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86207]: DBG:core:rpc_process_terminate: Process 5 exiting with code 0... Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86208]: DBG:core:rpc_process_terminate: Process 6 exiting with code 0... Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86204]: INFO:core:sig_usr: signal 15 received Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:shutdown_opensips: process 3(86205) [timer] terminated, still waiting for 6 more Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:shutdown_opensips: process 1(86203) [MI FIFO] terminated, still waiting for 5 more Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:shutdown_opensips: process 4(86206) [SIP receiver udp:172.17.0.4:5060] terminated, still waiting for 4 more Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:shutdown_opensips: process 6(86208) [SIP receiver udp:172.17.0.4:5060] terminated, still waiting for 3 more Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86210]: DBG:core:rpc_process_terminate: Process 8 exiting with code 0... Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:shutdown_opensips: process 5(86207) [SIP receiver udp:172.17.0.4:5060] terminated, still waiting for 2 more Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:shutdown_opensips: process 2(86204) [time_keeper] terminated, still waiting for 1 more Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:shutdown_opensips: process 8(86210) [Timer handler] terminated, still waiting for 0 more Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: INFO:core:cleanup: cleanup Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:b2b_logic:b2bl_delete: Delete record [0x7f1e3a986ca0]->[1010.0], hash_index=[1010], local_index=[0] Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:tm:tm_shutdown: tm_shutdown : start Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:tm:unlink_timer_lists: emptying DELETE list for set 0 Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:tm:tm_shutdown: emptying hash table Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:tm:tm_shutdown: releasing timers Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:tm:tm_shutdown: removing semaphores Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:tm:tm_shutdown: destroying callback lists Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:tm:tm_shutdown: tm_shutdown : done Jun 6 13:51:31 telephony5 opensips[86184]: Thank you for running opensips Jun 6 13:51:31 telephony5 /usr/local/sbin/opensips[86202]: DBG:core:shm_mem_destroy: destroying the shared memory lock

OS/environment information

rvlad-patrascu commented 1 year ago

Hi @inderjeetsharma ,

Can you please post a bt full backtrace from the core dump?

github-actions[bot] commented 1 year ago

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

github-actions[bot] commented 1 year ago

Marking as closed due to lack of progress for more than 30 days. If this issue is still relevant, please re-open it with additional details.

razvancrainea commented 1 year ago

If this still reproduces with the latest sources, please re-open the ticket and attach the requested core dump.

Best regards, Răzvan