[asterisk-bugs] [JIRA] (ASTERISK-29907) app_confbridge: Video call through ConfBridge with normal endpoints causes infinite loop/crash
N A (JIRA)
noreply at issues.asterisk.org
Fri Jun 17 18:34:49 CDT 2022
[ https://issues.asterisk.org/jira/browse/ASTERISK-29907?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=259522#comment-259522 ]
N A commented on ASTERISK-29907:
--------------------------------
Several new backtraces attached, and a restatement/clarification of the issue here.
Conditions to reproduce: 2 ConfBridges with video need to be connected. Doesn't happen with just a single ConfBridge.
This happens both with and without DEBUG_THREADS/BETTER_BACKTRACES.
Result: As soon as the call is answered and thus we get bidirectional video, Asterisk taskprocessor immediately explodes as such:
{noformat}
[2022-06-17 23:17:20] WARNING[25286][C-00000002]: taskprocessor.c:1160 taskprocessor_push: The 'pjsip/outsess/tsip-00000124' task processor queue reached 500 scheduled tasks.
[2022-06-17 23:17:20] WARNING[25269][C-00000002]: taskprocessor.c:1160 taskprocessor_push: The 'pjsip/distributor-0000006b' task processor queue reached 500 scheduled tasks.
{noformat}
Both CPU and memory start climbing to 100% and, within a few seconds, we're at the point of no return and Asterisk is going to crash.
In this case, it gets killed by the system due to "out of memory" as shown in dmesg.
If we have a few seconds before crashing, lots of extremely long queue warnings, deadlocks, other nasty stuff, etc.
Minimally reproducible example:
extensions.conf:
{noformat}
exten => test2,1,Originate(Local/1 at vidtest,exten,vidtest,2,1,,C(slin|h264))
same => n,Goto(vidtest,2,1)
[vidtest]
exten => 1,1,Answer
same => n,Dial(PJSIP/tsip,,G(split))
same => n,Hangup
same => n(split),ConfBridge(vidtest2,oebridge)
same => n,ConfBridge(vidtest2,oebridge)
exten => 2,1,ConfBridge(vidtest,oebridge)
{noformat}
confbridge.conf:
{noformat}
[oebridge]
type=bridge
sound_join=/var/lib/asterisk/sounds/en/silence/1
sound_leave=/var/lib/asterisk/sounds/en/silence/1
video_mode=follow_talker
{noformat}
The backtraces and core show locks do indicate a deadlock, though whether this is a cause or as a result, not entirely sure. The deadlock does seem to be in the same place each time, though:
core show locks:
{noformat}
=======================================================================
=== 18.9.0
=== Currently Held Locks
=======================================================================
===
=== <pending> <lock#> (<file>): <lock type> <line num> <function> <lock name> <lock addr> (times locked)
===
=== Thread ID: 0x7fab514fe700 LWP:20224 (worker_start started at [ 1111] threadpool.c worker_thread_start())
=== ---> Lock #0 (sorcery.c): RDLOCK 1869 ast_sorcery_retrieve_by_id &(&object_type->wizards)->lock 0x55f82b51c008 (1)
asterisk __ast_rwlock_rdlock()
asterisk ast_sorcery_retrieve_by_id()
[0x7fab53d2549f] res_pjsip_nat.so res_pjsip_nat.c:419 process_nat()
[0x7fab53d259c5] res_pjsip_nat.so res_pjsip_nat.c:480 nat_on_tx_message()
[0x7fab7b0a1966] libasteriskpj.so.2 sip_endpoint.c:1116 endpt_on_tx_msg()
[0x7fab7b0a94de] libasteriskpj.so.2 sip_transport.c:931 pjsip_transport_send()
[0x7fab7b0a4a9d] libasteriskpj.so.2 sip_util.c:1277 stateless_send_transport_cb()
[0x7fab7b0a4db6] libasteriskpj.so.2 sip_util.c:1379 stateless_send_resolver_callback()
[0x7fab53db1fb6] res_pjsip.so pjsip_resolver.c:529 sip_resolve()
[0x7fab7b0a6aa7] libasteriskpj.so.2 sip_resolve.c:208 pjsip_resolve()
[0x7fab7b0a1b70] libasteriskpj.so.2 sip_endpoint.c:1202 pjsip_endpt_resolve()
[0x7fab7b0a4edb] libasteriskpj.so.2 sip_util.c:1422 pjsip_endpt_send_request_stateless()
[0x7fab7b0c0dde] libasteriskpj.so.2 sip_transaction.c:2222 tsx_send_msg()
[0x7fab7b0c157a] libasteriskpj.so.2 sip_transaction.c:2456 tsx_on_state_null()
[0x7fab7b0c00f7] libasteriskpj.so.2 sip_transaction.c:1794 pjsip_tsx_send_msg()
[0x7fab7b0c6318] libasteriskpj.so.2 sip_dialog.c:1348 pjsip_dlg_send_request()
[0x7fab7b079238] libasteriskpj.so.2 sip_inv.c:3264 pjsip_inv_send_msg()
[0x7fab53cb510d] res_pjsip_session.so res_pjsip_session.c:2840 ast_sip_session_send_request_with_cb()
[0x7fab53cb5140] res_pjsip_session.so res_pjsip_session.c:2846 ast_sip_session_send_request()
[0x7fab539e9ca9] chan_pjsip.so chan_pjsip.c:1474 transmit_info_with_vidupdate()
asterisk ast_taskprocessor_execute()
asterisk <unknown>()
asterisk ast_taskprocessor_execute()
asterisk <unknown>()
asterisk <unknown>()
asterisk <unknown>()
asterisk <unknown>()
[0x7fab7a8d3fa3] libpthread.so.0 pthread_create.c:487 start_thread()
[0x7fab7a367eff] libc.so.6 clone.S:97 clone()
=== -------------------------------------------------------------------
===
=== Thread ID: 0x7fab4f22f700 LWP:20733 (pbx_thread started at [ 4736] pbx.c ast_pbx_start())
=== ---> Lock #0 (channel.c): MUTEX 3540 __ast_read chan 0x7fab5433a2f0 (1)
asterisk __ast_pthread_mutex_lock()
asterisk __ao2_lock()
asterisk <unknown>()
asterisk ast_read_stream()
asterisk <unknown>()
asterisk <unknown>()
asterisk bridge_channel_internal_join()
asterisk ast_bridge_join()
[0x7fab53faf571] app_confbridge.so app_confbridge.c:2904 confbridge_exec()
asterisk pbx_exec()
asterisk <unknown>()
asterisk ast_spawn_extension()
asterisk <unknown>()
asterisk <unknown>()
asterisk <unknown>()
[0x7fab7a8d3fa3] libpthread.so.0 pthread_create.c:487 start_thread()
[0x7fab7a367eff] libc.so.6 clone.S:97 clone()
=== ---> Lock #1 (rtp_engine.c): MUTEX 582 ast_rtp_instance_read instance 0x7fab5439a5b0 (1)
asterisk __ast_pthread_mutex_lock()
asterisk __ao2_lock()
asterisk ast_rtp_instance_read()
[0x7fab5393253d] res_pjsip_sdp_rtp.so res_pjsip_sdp_rtp.c:2038 media_session_rtp_read_callback()
[0x7fab539e7dc4] chan_pjsip.so chan_pjsip.c:855 chan_pjsip_read_stream()
asterisk <unknown>()
asterisk ast_read_stream()
asterisk <unknown>()
asterisk <unknown>()
asterisk bridge_channel_internal_join()
asterisk ast_bridge_join()
[0x7fab53faf571] app_confbridge.so app_confbridge.c:2904 confbridge_exec()
asterisk pbx_exec()
asterisk <unknown>()
asterisk ast_spawn_extension()
asterisk <unknown>()
asterisk <unknown>()
asterisk <unknown>()
[0x7fab7a8d3fa3] libpthread.so.0 pthread_create.c:487 start_thread()
[0x7fab7a367eff] libc.so.6 clone.S:97 clone()
=== -------------------------------------------------------------------
===
=== Thread ID: 0x7fab73d8e700 LWP:20756 (pbx_thread started at [ 4736] pbx.c ast_pbx_start())
=== ---> Lock #0 (bridge_channel.c): MUTEX 235 ast_bridge_channel_lock_bridge bridge 0x7fab747a7770 (1)
asterisk __ast_pthread_mutex_lock()
asterisk __ao2_lock()
asterisk <unknown>()
asterisk ast_bridge_channel_lock_bridge()
asterisk <unknown>()
asterisk <unknown>()
asterisk <unknown>()
asterisk bridge_channel_internal_join()
asterisk ast_bridge_join()
[0x7fab53faf571] app_confbridge.so app_confbridge.c:2904 confbridge_exec()
asterisk pbx_exec()
asterisk <unknown>()
asterisk ast_spawn_extension()
asterisk <unknown>()
asterisk <unknown>()
asterisk <unknown>()
[0x7fab7a8d3fa3] libpthread.so.0 pthread_create.c:487 start_thread()
[0x7fab7a367eff] libc.so.6 clone.S:97 clone()
{noformat}
> app_confbridge: Video call through ConfBridge with normal endpoints causes infinite loop/crash
> ----------------------------------------------------------------------------------------------
>
> Key: ASTERISK-29907
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-29907
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Applications/app_confbridge
> Affects Versions: 18.9.0
> Environment: Debian 10
> Reporter: N A
> Assignee: Unassigned
> Attachments: core-asterisk-running-2022-06-17T23-06-44Z-full.txt, core-asterisk-running-2022-06-17T23-24-08Z-full.txt, deadlock.txt, hangup_quickly.txt
>
>
> Something seems to be very wrong with the bridging logic for handing video calls.
> When making a direct call between two endpoints, including going through local channels, all seems well.
> However, when a call is made and originated into a ConfBridge with video, Asterisk enters an infinite loop processing video updates (or something) and crashes within 5-10 seconds. Sometimes if it takes longer to crash, you'll start seeing "Extremely long queue length queueing to..." messages before it actually crashes.
> Softphone used for testing is MicroSIP on both ends.
> Call is made between two PJSIP endpoints on the same system.
> Issue replicates 100% of the time, even with just two endpoints involved on an otherwise idle system. Infinite loop of media updates, followed by a crash.
> No issues when not using ConfBridge. No issues when failing to specify the h264 codec in Originate, which causes video call to fail and use audio only. No issues when using audio only, no video.
> It almost *seems* like somehow the conf bridge is not handling something right and is causing something to bounce around and go back and forth forever.
> Culprit seems to be hundreds/thousands of these bouncing around: Content-Type: application/media_control+xml
> Debug attached, providing an example of the infinite loop: https://paste.interlinked.us/xsr1mtgc6r.txt
> Additionally, here is a SIP debug from the perspective of the called line during all of this (different call but same thing): https://paste.interlinked.us/hky3ws7o3w.txt
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list