[asterisk-bugs] [JIRA] (ASTERISK-29907) res_pjsip, 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:59:49 CDT 2022
[ https://issues.asterisk.org/jira/browse/ASTERISK-29907?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=259524#comment-259524 ]
N A commented on ASTERISK-29907:
--------------------------------
Working backwards from the infinite video updates, interestingly, res_pjsip_sdp_rtp itself doesn't seem to generate infinite updates. It only generates a single update, which then gets processed forever in perpetuity.
As such, I don't actually think this is app_confbridge related anymore - this seems to be purely a PJSIP related bug since the issue is caused there and can be isolated there:
{noformat}
[2022-06-17 23:56:16] -- PJSIP/tsip-00000003 is ringing
[2022-06-17 23:56:16] NOTICE[1244]: res_pjsip_sdp_rtp.c:2321 video_info_incoming_request: Queuing a video update
[2022-06-17 23:56:16] -- Local/1 at vidtest-00000005;2 requested media update control 18, passing it to PJSIP/tsip-00000003
[2022-06-17 23:56:17] -- <CBAnn/vidtest-00000006;1> Playing '/var/lib/asterisk/sounds/en/silence/1.ulaw' (language 'en')
[2022-06-17 23:56:19] > 0x55e9e385d2c0 -- Strict RTP learning after remote address set to: 192.168.10.102:4016
[2022-06-17 23:56:19] > 0x55e9e385ff00 -- Strict RTP learning after remote address set to: 192.168.10.102:4018
[2022-06-17 23:56:19] > 0x55e9e385d2c0 -- Strict RTP qualifying stream type: audio
[2022-06-17 23:56:19] -- PJSIP/tsip-00000003 answered Local/1 at vidtest-00000005;2
[2022-06-17 23:56:19] -- Executing [1 at vidtest:4] ConfBridge("Local/1 at vidtest-00000005;2", "vidtest2,oebridge") in new stack
[2022-06-17 23:56:19] -- Executing [1 at vidtest:5] ConfBridge("PJSIP/tsip-00000003", "vidtest2,oebridge") in new stack
[2022-06-17 23:56:19] -- Channel CBAnn/vidtest2-00000007;2 joined 'softmix' base-bridge <7137a988-4708-4589-ae7f-37f3c4b3ae5e>
[2022-06-17 23:56:19] -- Channel Local/1 at vidtest-00000005;2 joined 'softmix' base-bridge <7137a988-4708-4589-ae7f-37f3c4b3ae5e>
[2022-06-17 23:56:19] -- Channel PJSIP/tsip-00000003 joined 'softmix' base-bridge <7137a988-4708-4589-ae7f-37f3c4b3ae5e>
[2022-06-17 23:56:19] -- <CBAnn/vidtest2-00000007;1> Playing '/var/lib/asterisk/sounds/en/silence/1.ulaw' (language 'en')
[2022-06-17 23:56:19] > 0x55e9e385ff00 -- Strict RTP qualifying stream type: video
[2022-06-17 23:56:19] > Video source in bridge 'vidtest2' (7137a988-4708-4589-ae7f-37f3c4b3ae5e) is now 'PJSIP/tsip-00000003' (1655510176.24)
[2022-06-17 23:56:19] > Video source in bridge 'vidtest' (e93c4427-23f6-4551-912f-7f0ce5aae357) is now 'Local/1 at vidtest-00000005;1' (1655510176.20)
[2022-06-17 23:56:19] NOTICE[1787]: res_pjsip_sdp_rtp.c:2321 video_info_incoming_request: Queuing a video update
[2022-06-17 23:56:20] WARNING[1243]: taskprocessor.c:1160 taskprocessor_push: The 'pjsip/outsess/tsip-00000122' task processor queue reached 500 scheduled tasks.
[2022-06-17 23:56:20] WARNING[3674][C-00000005]: taskprocessor.c:1160 taskprocessor_push: The 'pjsip/distributor-00000083' task processor queue reached 500 scheduled tasks.
[2022-06-17 23:56:20] -- <CBAnn/vidtest2-00000007;1> Playing '/var/lib/asterisk/sounds/en/silence/1.ulaw' (language 'en')
[2022-06-17 23:56:20] > Video source in bridge 'vidtest2' (7137a988-4708-4589-ae7f-37f3c4b3ae5e) is now 'Local/1 at vidtest-00000005;2' (1655510176.21)
[2022-06-17 23:56:21] > Video source in bridge 'vidtest' (e93c4427-23f6-4551-912f-7f0ce5aae357) is now 'PJSIP/ATAxMicroSIP1-00000002' (1655510176.19)
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
[2022-06-17 23:56:23] ERROR[1244]: chan_pjsip.c:1458 transmit_info_with_vidupdate: Session already DISCONNECTED [reason=200 (OK)]
{noformat}
> res_pjsip, 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-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