[BUG] Data race with pjmedia_stream stopping media

BC
b17 c0de
Sat, Oct 8, 2016 3:13 PM

Hi,
There are many of race conditions in pjmedia_stream that happen when
the sip event thread and the media event thread try to use the stream
at the same time. One such case is during hangup. In this case, they
both try to call pjmedia_rtcp_build_rtcp_sdes() at the same time:

sip event thread:
#0 pjmedia_rtcp_build_rtcp_sdes
pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10
#1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11
#2 pjmedia_stream_send_rtcp_bye
pjproject/pjmedia/build/../src/pjmedia/stream.c:2943:9
#3 pjsua_aud_stop_stream
pjproject/pjsip/build/../src/pjsua-lib/pjsua_aud.c:505:2
#4 stop_media_stream
pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2462:2
#5 stop_media_session
pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2514:2
#6 pjsua_media_channel_deinit
pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2538:5
#7 pjsua_call_on_state_changed
pjproject/pjsip/build/../src/pjsua-lib/pjsua_call.c:3761:2
#8 inv_set_state pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:317:2
#9 inv_handle_bye_response
pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:3407:2
#10 inv_on_state_confirmed
pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:4746:2
#11 mod_inv_on_tsx_state
pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:717:5
#12 pjsip_dlg_on_tsx_state
pjproject/pjsip/build/../src/pjsip/sip_dialog.c:2064:2
#13 mod_ua_on_tsx_state
pjproject/pjsip/build/../src/pjsip/sip_ua_layer.c:178:5
#14 tsx_set_state
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1233:2
#15 tsx_on_state_proceeding_uac
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2957:6
#16 tsx_on_state_calling
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2540:2
#17 pjsip_tsx_recv_msg
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1787:5
#18 mod_tsx_layer_on_rx_response
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:875:5
#19 pjsip_endpt_process_rx_data
pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:895:13
#20 endpt_on_rx_msg pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:1037:5
#21 pjsip_tpmgr_receive_packet
pjproject/pjsip/build/../src/pjsip/sip_transport.c:1938:2
#22 udp_on_read_complete
pjproject/pjsip/build/../src/pjsip/sip_transport_udp.c:168:3
#23 ioqueue_dispatch_read_event
pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6
#24 pj_ioqueue_poll pjproject/pjlib/build/../src/pj/ioqueue_select.c:981:7
#25 pjsip_endpt_handle_events2
pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:742:6
#26 pjsua_handle_events
pjproject/pjsip/build/../src/pjsua-lib/pjsua_core.c:1981:14
#27 worker_thread pjproject/pjsip/build/../src/pjsua-lib/pjsua_core.c:699:10
#28 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27

media event thread:
#0 pjmedia_rtcp_build_rtcp_sdes
pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10
#1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11
#2 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/stream.c:1905:11
#3 srtp_rtp_cb
pjproject/pjmedia/build/../src/pjmedia/transport_srtp.c:1005:2
#4 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/transport_udp.c:533:6
#5 ioqueue_dispatch_read_event
pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6
#6 pj_ioqueue_poll pjproject/pjlib/build/../src/pj/ioqueue_select.c:981:7
#7 worker_proc pjproject/pjmedia/build/../src/pjmedia/endpoint.c:339:2
#8 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27

Kal

Hi, There are many of race conditions in pjmedia_stream that happen when the sip event thread and the media event thread try to use the stream at the same time. One such case is during hangup. In this case, they both try to call pjmedia_rtcp_build_rtcp_sdes() at the same time: sip event thread: #0 pjmedia_rtcp_build_rtcp_sdes pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10 #1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11 #2 pjmedia_stream_send_rtcp_bye pjproject/pjmedia/build/../src/pjmedia/stream.c:2943:9 #3 pjsua_aud_stop_stream pjproject/pjsip/build/../src/pjsua-lib/pjsua_aud.c:505:2 #4 stop_media_stream pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2462:2 #5 stop_media_session pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2514:2 #6 pjsua_media_channel_deinit pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2538:5 #7 pjsua_call_on_state_changed pjproject/pjsip/build/../src/pjsua-lib/pjsua_call.c:3761:2 #8 inv_set_state pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:317:2 #9 inv_handle_bye_response pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:3407:2 #10 inv_on_state_confirmed pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:4746:2 #11 mod_inv_on_tsx_state pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:717:5 #12 pjsip_dlg_on_tsx_state pjproject/pjsip/build/../src/pjsip/sip_dialog.c:2064:2 #13 mod_ua_on_tsx_state pjproject/pjsip/build/../src/pjsip/sip_ua_layer.c:178:5 #14 tsx_set_state pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1233:2 #15 tsx_on_state_proceeding_uac pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2957:6 #16 tsx_on_state_calling pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2540:2 #17 pjsip_tsx_recv_msg pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1787:5 #18 mod_tsx_layer_on_rx_response pjproject/pjsip/build/../src/pjsip/sip_transaction.c:875:5 #19 pjsip_endpt_process_rx_data pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:895:13 #20 endpt_on_rx_msg pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:1037:5 #21 pjsip_tpmgr_receive_packet pjproject/pjsip/build/../src/pjsip/sip_transport.c:1938:2 #22 udp_on_read_complete pjproject/pjsip/build/../src/pjsip/sip_transport_udp.c:168:3 #23 ioqueue_dispatch_read_event pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6 #24 pj_ioqueue_poll pjproject/pjlib/build/../src/pj/ioqueue_select.c:981:7 #25 pjsip_endpt_handle_events2 pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:742:6 #26 pjsua_handle_events pjproject/pjsip/build/../src/pjsua-lib/pjsua_core.c:1981:14 #27 worker_thread pjproject/pjsip/build/../src/pjsua-lib/pjsua_core.c:699:10 #28 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27 media event thread: #0 pjmedia_rtcp_build_rtcp_sdes pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10 #1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11 #2 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/stream.c:1905:11 #3 srtp_rtp_cb pjproject/pjmedia/build/../src/pjmedia/transport_srtp.c:1005:2 #4 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/transport_udp.c:533:6 #5 ioqueue_dispatch_read_event pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6 #6 pj_ioqueue_poll pjproject/pjlib/build/../src/pj/ioqueue_select.c:981:7 #7 worker_proc pjproject/pjmedia/build/../src/pjmedia/endpoint.c:339:2 #8 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27 Kal
NI
Nanang Izzuddin
Fri, Oct 21, 2016 10:44 AM

Hi Kal,

The sample case is a valid scenario, but it seems to be harmless as the
read-raced data is virtually a constant/read-only data (i.e:
stream->rtcp.rtcp_sr_pkt.common). However, as you mentioned that there are
many, but unfortunately we haven't got a chance to dig deeper for now, I'd
just create a ticket: https://trac.pjsip.org/repos/ticket/1973.

Thanks you for the report.

BR,
nanang

On Sat, Oct 8, 2016 at 10:13 PM, b17 c0de b17c0de@gmail.com wrote:

Hi,
There are many of race conditions in pjmedia_stream that happen when
the sip event thread and the media event thread try to use the stream
at the same time. One such case is during hangup. In this case, they
both try to call pjmedia_rtcp_build_rtcp_sdes() at the same time:

sip event thread:
#0 pjmedia_rtcp_build_rtcp_sdes
pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10
#1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11
#2 pjmedia_stream_send_rtcp_bye
pjproject/pjmedia/build/../src/pjmedia/stream.c:2943:9
#3 pjsua_aud_stop_stream
pjproject/pjsip/build/../src/pjsua-lib/pjsua_aud.c:505:2
#4 stop_media_stream
pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2462:2
#5 stop_media_session
pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2514:2
#6 pjsua_media_channel_deinit
pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2538:5
#7 pjsua_call_on_state_changed
pjproject/pjsip/build/../src/pjsua-lib/pjsua_call.c:3761:2
#8 inv_set_state pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:317:2
#9 inv_handle_bye_response
pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:3407:2
#10 inv_on_state_confirmed
pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:4746:2
#11 mod_inv_on_tsx_state
pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:717:5
#12 pjsip_dlg_on_tsx_state
pjproject/pjsip/build/../src/pjsip/sip_dialog.c:2064:2
#13 mod_ua_on_tsx_state
pjproject/pjsip/build/../src/pjsip/sip_ua_layer.c:178:5
#14 tsx_set_state
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1233:2
#15 tsx_on_state_proceeding_uac
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2957:6
#16 tsx_on_state_calling
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2540:2
#17 pjsip_tsx_recv_msg
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1787:5
#18 mod_tsx_layer_on_rx_response
pjproject/pjsip/build/../src/pjsip/sip_transaction.c:875:5
#19 pjsip_endpt_process_rx_data
pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:895:13
#20 endpt_on_rx_msg pjproject/pjsip/build/../src/
pjsip/sip_endpoint.c:1037:5
#21 pjsip_tpmgr_receive_packet
pjproject/pjsip/build/../src/pjsip/sip_transport.c:1938:2
#22 udp_on_read_complete
pjproject/pjsip/build/../src/pjsip/sip_transport_udp.c:168:3
#23 ioqueue_dispatch_read_event
pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6
#24 pj_ioqueue_poll pjproject/pjlib/build/../src/
pj/ioqueue_select.c:981:7
#25 pjsip_endpt_handle_events2
pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:742:6
#26 pjsua_handle_events
pjproject/pjsip/build/../src/pjsua-lib/pjsua_core.c:1981:14
#27 worker_thread pjproject/pjsip/build/../src/
pjsua-lib/pjsua_core.c:699:10
#28 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27

media event thread:
#0 pjmedia_rtcp_build_rtcp_sdes
pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10
#1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11
#2 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/stream.c:1905:11
#3 srtp_rtp_cb
pjproject/pjmedia/build/../src/pjmedia/transport_srtp.c:1005:2
#4 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/transport_udp.c:
533:6
#5 ioqueue_dispatch_read_event
pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6
#6 pj_ioqueue_poll pjproject/pjlib/build/../src/
pj/ioqueue_select.c:981:7
#7 worker_proc pjproject/pjmedia/build/../src/pjmedia/endpoint.c:339:2
#8 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27

Kal


Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@lists.pjsip.org
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org

Hi Kal, The sample case is a valid scenario, but it seems to be harmless as the read-raced data is virtually a constant/read-only data (i.e: stream->rtcp.rtcp_sr_pkt.common). However, as you mentioned that there are many, but unfortunately we haven't got a chance to dig deeper for now, I'd just create a ticket: https://trac.pjsip.org/repos/ticket/1973. Thanks you for the report. BR, nanang On Sat, Oct 8, 2016 at 10:13 PM, b17 c0de <b17c0de@gmail.com> wrote: > Hi, > There are many of race conditions in pjmedia_stream that happen when > the sip event thread and the media event thread try to use the stream > at the same time. One such case is during hangup. In this case, they > both try to call pjmedia_rtcp_build_rtcp_sdes() at the same time: > > sip event thread: > #0 pjmedia_rtcp_build_rtcp_sdes > pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10 > #1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11 > #2 pjmedia_stream_send_rtcp_bye > pjproject/pjmedia/build/../src/pjmedia/stream.c:2943:9 > #3 pjsua_aud_stop_stream > pjproject/pjsip/build/../src/pjsua-lib/pjsua_aud.c:505:2 > #4 stop_media_stream > pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2462:2 > #5 stop_media_session > pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2514:2 > #6 pjsua_media_channel_deinit > pjproject/pjsip/build/../src/pjsua-lib/pjsua_media.c:2538:5 > #7 pjsua_call_on_state_changed > pjproject/pjsip/build/../src/pjsua-lib/pjsua_call.c:3761:2 > #8 inv_set_state pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:317:2 > #9 inv_handle_bye_response > pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:3407:2 > #10 inv_on_state_confirmed > pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:4746:2 > #11 mod_inv_on_tsx_state > pjproject/pjsip/build/../src/pjsip-ua/sip_inv.c:717:5 > #12 pjsip_dlg_on_tsx_state > pjproject/pjsip/build/../src/pjsip/sip_dialog.c:2064:2 > #13 mod_ua_on_tsx_state > pjproject/pjsip/build/../src/pjsip/sip_ua_layer.c:178:5 > #14 tsx_set_state > pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1233:2 > #15 tsx_on_state_proceeding_uac > pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2957:6 > #16 tsx_on_state_calling > pjproject/pjsip/build/../src/pjsip/sip_transaction.c:2540:2 > #17 pjsip_tsx_recv_msg > pjproject/pjsip/build/../src/pjsip/sip_transaction.c:1787:5 > #18 mod_tsx_layer_on_rx_response > pjproject/pjsip/build/../src/pjsip/sip_transaction.c:875:5 > #19 pjsip_endpt_process_rx_data > pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:895:13 > #20 endpt_on_rx_msg pjproject/pjsip/build/../src/ > pjsip/sip_endpoint.c:1037:5 > #21 pjsip_tpmgr_receive_packet > pjproject/pjsip/build/../src/pjsip/sip_transport.c:1938:2 > #22 udp_on_read_complete > pjproject/pjsip/build/../src/pjsip/sip_transport_udp.c:168:3 > #23 ioqueue_dispatch_read_event > pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6 > #24 pj_ioqueue_poll pjproject/pjlib/build/../src/ > pj/ioqueue_select.c:981:7 > #25 pjsip_endpt_handle_events2 > pjproject/pjsip/build/../src/pjsip/sip_endpoint.c:742:6 > #26 pjsua_handle_events > pjproject/pjsip/build/../src/pjsua-lib/pjsua_core.c:1981:14 > #27 worker_thread pjproject/pjsip/build/../src/ > pjsua-lib/pjsua_core.c:699:10 > #28 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27 > > media event thread: > #0 pjmedia_rtcp_build_rtcp_sdes > pjproject/pjmedia/build/../src/pjmedia/rtcp.c:1014:10 > #1 send_rtcp pjproject/pjmedia/build/../src/pjmedia/stream.c:991:11 > #2 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/stream.c:1905:11 > #3 srtp_rtp_cb > pjproject/pjmedia/build/../src/pjmedia/transport_srtp.c:1005:2 > #4 on_rx_rtp pjproject/pjmedia/build/../src/pjmedia/transport_udp.c: > 533:6 > #5 ioqueue_dispatch_read_event > pjproject/pjlib/build/../src/pj/ioqueue_common_abs.c:605:6 > #6 pj_ioqueue_poll pjproject/pjlib/build/../src/ > pj/ioqueue_select.c:981:7 > #7 worker_proc pjproject/pjmedia/build/../src/pjmedia/endpoint.c:339:2 > #8 thread_main pjproject/pjlib/build/../src/pj/os_core_unix.c:541:27 > > Kal > > _______________________________________________ > Visit our blog: http://blog.pjsip.org > > pjsip mailing list > pjsip@lists.pjsip.org > http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org >