Hello! I have pjsip-2.9 based application. I compile pjproject with video and ffmpeg video codecs. I implemented on_call_media_event callback using pjsua_call_get_info function.
The problem occurs then i switch video on/off quickly( through pjsua_call_set_vid_strm with PJSUA_CALL_VID_STRM_CHANGE_DIR). It may cause deadlock between PJSUA_LOCK and event manager mutex.
My trace:
Thread 1 (Thread 0x7fb2d05cb700 (LWP 2016)):
#0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1 0x00007fb3102bfc06 in __GI___pthread_mutex_lock (mutex=0x66991b5cf6b8) at ../nptl/pthread_mutex_lock.c:115
#2 0x00007fb2f3440edb in pj_mutex_lock (mutex=0x66991b5cf6b8) at ../src/pj/os_core_unix.c:1281
#3 0x00007fb2f339e546 in pjmedia_event_subscribe (mgr=0x66991b5cedc8, mgr@entry=0x0, cb=cb@entry=0x7fb2f33b9690 <vidstream_event_cb>, user_data=user_data@entry=0x66991af85c18, epub=0x7fb28804c928) at ../src/pjmedia/event.c:255
#4 0x00007fb2f33baaa4 in pjmedia_vid_port_create (pool=0x66991af85b70, prm=prm@entry=0x7fb2d05c4aa0, p_vid_port=p_vid_port@entry=0x7fb2f39ae820 <pjsua_var+2355296>) at ../src/pjmedia/vid_port.c:606
#5 0x00007fb2f3353eb5 in create_vid_win (type=type@entry=PJSUA_WND_TYPE_PREVIEW, fmt=0x7fb28842cc50, rend_id=4, cap_id=0, show=show@entry=0, wnd_flags=<optimized out>, wnd=0x0, id=0x7fb2d05c54fc) at ../src/pjsua-lib/pjsua_vid.c:742
#6 0x00007fb2f335457b in setup_vid_capture (call_med=call_med@entry=0x7fb2f3781f90 <pjsua_var+75728>) at ../src/pjsua-lib/pjsua_vid.c:940
#7 0x00007fb2f3354b21 in pjsua_vid_channel_update (call_med=call_med@entry=0x7fb2f3781f90 <pjsua_var+75728>, tmp_pool=0x66991e94b340, si=si@entry=0x7fb2d05c5fc0, local_sdp=local_sdp@entry=0x66991ec52be8, remote_sdp=remote_sdp@entry=0x7fb288421dc8) at ../src/pjsua-lib/pjsua_vid.c:1195
#8 0x00007fb2f3346e1a in pjsua_media_channel_update (call_id=<optimized out>, local_sdp=0x66991ec52be8, remote_sdp=0x7fb288421dc8) at ../src/pjsua-lib/pjsua_media.c:3501
#9 0x00007fb2f3338a21 in pjsua_call_on_media_update (inv=0x66991e36b448, status=<optimized out>) at ../src/pjsua-lib/pjsua_call.c:4482
#10 0x00007fb2f3355e57 in inv_negotiate_sdp (inv=0x66991e36b448) at ../src/pjsip-ua/sip_inv.c:1953
#11 0x00007fb2f3356c30 in inv_check_sdp_in_incoming_msg (inv=inv@entry=0x66991e36b448, tsx=tsx@entry=0x66991be7ec68, rdata=0x7fb288001988) at ../src/pjsip-ua/sip_inv.c:2180
#12 0x00007fb2f335aa19 in inv_on_state_confirmed (inv=0x66991e36b448, e=0x7fb2d05c7750) at ../src/pjsip-ua/sip_inv.c:5163
#13 0x00007fb2f3356187 in mod_inv_on_tsx_state (tsx=0x66991be7ec68, e=0x7fb2d05c7750) at ../src/pjsip-ua/sip_inv.c:720
#14 0x00007fb2f3389f4d in pjsip_dlg_on_tsx_state (dlg=0x66991e94b3e8, tsx=0x66991be7ec68, e=0x7fb2d05c7750) at ../src/pjsip/sip_dialog.c:2069
#15 0x00007fb2f3384795 in tsx_set_state (tsx=tsx@entry=0x66991be7ec68, state=state@entry=PJSIP_TSX_STATE_TERMINATED, event_src_type=event_src_type@entry=PJSIP_EVENT_RX_MSG, event_src=0x7fb288001988, flag=flag@entry=0) at ../src/pjsip/sip_transaction.c:1272
#16 0x00007fb2f3386349 in tsx_on_state_proceeding_uac (tsx=0x66991be7ec68, event=0x7fb2d05c7840) at ../src/pjsip/sip_transaction.c:2989
#17 0x00007fb2f33864de in tsx_on_state_calling (tsx=0x66991be7ec68, event=0x7fb2d05c7840) at ../src/pjsip/sip_transaction.c:2599
#18 0x00007fb2f338776f in pjsip_tsx_recv_msg (tsx=tsx@entry=0x66991be7ec68, rdata=rdata@entry=0x7fb288001988) at ../src/pjsip/sip_transaction.c:1832
#19 0x00007fb2f3387835 in mod_tsx_layer_on_rx_response (rdata=0x7fb288001988) at ../src/pjsip/sip_transaction.c:893
#20 0x00007fb2f337539e in pjsip_endpt_process_rx_data (endpt=0x66991b531dc8, rdata=0x7fb288001988, p=<optimized out>, p_handled=0x7fb2d05c796c) at ../src/pjsip/sip_endpoint.c:938
#21 0x00007fb2f3375526 in endpt_on_rx_msg (endpt=0x66991b531dc8, status=<optimized out>, rdata=0x7fb288001988) at ../src/pjsip/sip_endpoint.c:1080
#22 0x00007fb2f337b5ff in pjsip_tpmgr_receive_packet (mgr=<optimized out>, rdata=rdata@entry=0x7fb288001988) at ../src/pjsip/sip_transport.c:2130
#23 0x00007fb2f337d906 in udp_on_read_complete (key=0x66991b540e18, op_key=<optimized out>, bytes_read=<optimized out>) at ../src/pjsip/sip_transport_udp.c:188
#24 0x00007fb2f343e8df in ioqueue_dispatch_read_event (ioqueue=0x66991b53d958, h=0x66991b540e18) at ../src/pj/ioqueue_common_abs.c:605
#25 0x00007fb2f343fec6 in pj_ioqueue_poll (ioqueue=0x66991b53d958, timeout=timeout@entry=0x7fb2d05cae70) at ../src/pj/ioqueue_select.c:1069
#26 0x00007fb2f33750a7 in pjsip_endpt_handle_events2 (endpt=0x66991b531dc8, max_timeout=max_timeout@entry=0x7fb2d05caed0, p_count=p_count@entry=0x7fb2d05caecc) at ../src/pjsip/sip_endpoint.c:745
#27 0x00007fb2f333b905 in pjsua_handle_events (msec_timeout=msec_timeout@entry=10) at ../src/pjsua-lib/pjsua_core.c:2156
#28 0x00007fb2f333b94a in worker_thread (arg=<optimized out>) at ../src/pjsua-lib/pjsua_core.c:786
#29 0x00007fb2f34410f6 in thread_main (param=0x66991b5cf2e8) at ../src/pj/os_core_unix.c:541
#30 0x00007fb3102bd494 in start_thread (arg=0x7fb2d05cb700) at pthread_create.c:333
#31 0x00007fb3105bbacf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 1 (Thread 0x7fb2d05cb700 (LWP 2016)):
#0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1 0x00007fb3102bfc06 in __GI___pthread_mutex_lock (mutex=0x66991b5cf6b8) at ../nptl/pthread_mutex_lock.c:115
#2 0x00007fb2f3440edb in pj_mutex_lock (mutex=0x66991b5cf6b8) at ../src/pj/os_core_unix.c:1281
#3 0x00007fb2f339e546 in pjmedia_event_subscribe (mgr=0x66991b5cedc8, mgr@entry=0x0, cb=cb@entry=0x7fb2f33b9690 <vidstream_event_cb>, user_data=user_data@entry=0x66991af85c18, epub=0x7fb28804c928) at ../src/pjmedia/event.c:255
#4 0x00007fb2f33baaa4 in pjmedia_vid_port_create (pool=0x66991af85b70, prm=prm@entry=0x7fb2d05c4aa0, p_vid_port=p_vid_port@entry=0x7fb2f39ae820 <pjsua_var+2355296>) at ../src/pjmedia/vid_port.c:606
#5 0x00007fb2f3353eb5 in create_vid_win (type=type@entry=PJSUA_WND_TYPE_PREVIEW, fmt=0x7fb28842cc50, rend_id=4, cap_id=0, show=show@entry=0, wnd_flags=<optimized out>, wnd=0x0, id=0x7fb2d05c54fc) at ../src/pjsua-lib/pjsua_vid.c:742
#6 0x00007fb2f335457b in setup_vid_capture (call_med=call_med@entry=0x7fb2f3781f90 <pjsua_var+75728>) at ../src/pjsua-lib/pjsua_vid.c:940
#7 0x00007fb2f3354b21 in pjsua_vid_channel_update (call_med=call_med@entry=0x7fb2f3781f90 <pjsua_var+75728>, tmp_pool=0x66991e94b340, si=si@entry=0x7fb2d05c5fc0, local_sdp=local_sdp@entry=0x66991ec52be8, remote_sdp=remote_sdp@entry=0x7fb288421dc8) at ../src/pjsua-lib/pjsua_vid.c:1195
#8 0x00007fb2f3346e1a in pjsua_media_channel_update (call_id=<optimized out>, local_sdp=0x66991ec52be8, remote_sdp=0x7fb288421dc8) at ../src/pjsua-lib/pjsua_media.c:3501
#9 0x00007fb2f3338a21 in pjsua_call_on_media_update (inv=0x66991e36b448, status=<optimized out>) at ../src/pjsua-lib/pjsua_call.c:4482
#10 0x00007fb2f3355e57 in inv_negotiate_sdp (inv=0x66991e36b448) at ../src/pjsip-ua/sip_inv.c:1953
#11 0x00007fb2f3356c30 in inv_check_sdp_in_incoming_msg (inv=inv@entry=0x66991e36b448, tsx=tsx@entry=0x66991be7ec68, rdata=0x7fb288001988) at ../src/pjsip-ua/sip_inv.c:2180
#12 0x00007fb2f335aa19 in inv_on_state_confirmed (inv=0x66991e36b448, e=0x7fb2d05c7750) at ../src/pjsip-ua/sip_inv.c:5163
#13 0x00007fb2f3356187 in mod_inv_on_tsx_state (tsx=0x66991be7ec68, e=0x7fb2d05c7750) at ../src/pjsip-ua/sip_inv.c:720
#14 0x00007fb2f3389f4d in pjsip_dlg_on_tsx_state (dlg=0x66991e94b3e8, tsx=0x66991be7ec68, e=0x7fb2d05c7750) at ../src/pjsip/sip_dialog.c:2069
#15 0x00007fb2f3384795 in tsx_set_state (tsx=tsx@entry=0x66991be7ec68, state=state@entry=PJSIP_TSX_STATE_TERMINATED, event_src_type=event_src_type@entry=PJSIP_EVENT_RX_MSG, event_src=0x7fb288001988, flag=flag@entry=0) at ../src/pjsip/sip_transaction.c:1272
#16 0x00007fb2f3386349 in tsx_on_state_proceeding_uac (tsx=0x66991be7ec68, event=0x7fb2d05c7840) at ../src/pjsip/sip_transaction.c:2989
#17 0x00007fb2f33864de in tsx_on_state_calling (tsx=0x66991be7ec68, event=0x7fb2d05c7840) at ../src/pjsip/sip_transaction.c:2599
#18 0x00007fb2f338776f in pjsip_tsx_recv_msg (tsx=tsx@entry=0x66991be7ec68, rdata=rdata@entry=0x7fb288001988) at ../src/pjsip/sip_transaction.c:1832
#19 0x00007fb2f3387835 in mod_tsx_layer_on_rx_response (rdata=0x7fb288001988) at ../src/pjsip/sip_transaction.c:893
#20 0x00007fb2f337539e in pjsip_endpt_process_rx_data (endpt=0x66991b531dc8, rdata=0x7fb288001988, p=<optimized out>, p_handled=0x7fb2d05c796c) at ../src/pjsip/sip_endpoint.c:938
#21 0x00007fb2f3375526 in endpt_on_rx_msg (endpt=0x66991b531dc8, status=<optimized out>, rdata=0x7fb288001988) at ../src/pjsip/sip_endpoint.c:1080
#22 0x00007fb2f337b5ff in pjsip_tpmgr_receive_packet (mgr=<optimized out>, rdata=rdata@entry=0x7fb288001988) at ../src/pjsip/sip_transport.c:2130
#23 0x00007fb2f337d906 in udp_on_read_complete (key=0x66991b540e18, op_key=<optimized out>, bytes_read=<optimized out>) at ../src/pjsip/sip_transport_udp.c:188
#24 0x00007fb2f343e8df in ioqueue_dispatch_read_event (ioqueue=0x66991b53d958, h=0x66991b540e18) at ../src/pj/ioqueue_common_abs.c:605
#25 0x00007fb2f343fec6 in pj_ioqueue_poll (ioqueue=0x66991b53d958, timeout=timeout@entry=0x7fb2d05cae70) at ../src/pj/ioqueue_select.c:1069
#26 0x00007fb2f33750a7 in pjsip_endpt_handle_events2 (endpt=0x66991b531dc8, max_timeout=max_timeout@entry=0x7fb2d05caed0, p_count=p_count@entry=0x7fb2d05caecc) at ../src/pjsip/sip_endpoint.c:745
#27 0x00007fb2f333b905 in pjsua_handle_events (msec_timeout=msec_timeout@entry=10) at ../src/pjsua-lib/pjsua_core.c:2156
#28 0x00007fb2f333b94a in worker_thread (arg=<optimized out>) at ../src/pjsua-lib/pjsua_core.c:786
#29 0x00007fb2f34410f6 in thread_main (param=0x66991b5cf2e8) at ../src/pj/os_core_unix.c:541
#30 0x00007fb3102bd494 in start_thread (arg=0x7fb2d05cb700) at pthread_create.c:333
#31 0x00007fb3105bbacf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 2 (Thread 0x7fb2a1fc5700 (LWP 2052)):
#0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1 0x00007fb3102bfc06 in __GI___pthread_mutex_lock (mutex=0x66991b52f5b8) at ../nptl/pthread_mutex_lock.c:115
#2 0x00007fb2f3440edb in pj_mutex_lock (mutex=0x66991b52f5b8) at ../src/pj/os_core_unix.c:1281
#3 0x00007fb2f3334624 in PJSUA_LOCK () at ../include/pjsua-lib/pjsua_internal.h:591
#4 pjsua_call_get_info (call_id=3, info=info@entry=0x7fb2a1fc4160) at ../src/pjsua-lib/pjsua_call.c:2148
#5 0x00007fb2f330dfb1 in Call::onMediaEvent (this=0x66991e3ba200, mi=<optimized out>, event=<optimized out>) at call.cpp:526
#6 0x00007fb2f3342816 in call_media_on_event (event=0x7fb2f36f1720 <ev_queue>, user_data=0x7fb2f3781f90 <pjsua_var+75728>) at ../src/pjsua-lib/pjsua_media.c:1562
#7 0x00007fb2f339e0b6 in event_mgr_distribute_events (mgr=mgr@entry=0x66991b5cedc8, ev_queue=0x7fb2f36f1720 <ev_queue>, next_sub=next_sub@entry=0x66991b5cf2e0, rls_lock=rls_lock@entry=0) at ../src/pjmedia/event.c:113
#8 0x00007fb2f339e8a7 in pjmedia_event_publish (mgr=0x66991b5cedc8, mgr@entry=0x0, epub=epub@entry=0x7fb288425840, event=event@entry=0x7fb2884256b0, flag=flag@entry=PJMEDIA_EVENT_PUBLISH_DEFAULT) at ../src/pjmedia/event.c:364
#9 0x00007fb2f33bc0f9 in get_frame (port=0x7fb288425840, frame=0x7fb2a1fc4e00) at ../src/pjmedia/vid_stream.c:1409
#10 0x00007fb2f33be5a9 in on_clock_tick (now=0x66991b5c9f10, user_data=0x66991b5c9d78) at ../src/pjmedia/vid_conf.c:735
#11 0x00007fb2f3396e63 in clock_thread (arg=0x66991b5c9ef0) at ../src/pjmedia/clock_thread.c:378
#12 0x00007fb2f34410f6 in thread_main (param=0x66991b5ca198) at ../src/pj/os_core_unix.c:541
#13 0x00007fb3102bd494 in start_thread (arg=0x7fb2a1fc5700) at pthread_create.c:333
#14 0x00007fb3105bbacf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
#0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1 0x00007fb3102bfc06 in __GI___pthread_mutex_lock (mutex=0x66991b52f5b8) at ../nptl/pthread_mutex_lock.c:115
#2 0x00007fb2f3440edb in pj_mutex_lock (mutex=0x66991b52f5b8) at ../src/pj/os_core_unix.c:1281
#3 0x00007fb2f3334624 in PJSUA_LOCK () at ../include/pjsua-lib/pjsua_internal.h:591
#4 pjsua_call_get_info (call_id=3, info=info@entry=0x7fb2a1fc4160) at ../src/pjsua-lib/pjsua_call.c:2148
#5 0x00007fb2f330dfb1 in Call::onMediaEvent (this=0x66991e3ba200, mi=<optimized out>, event=<optimized out>) at call.cpp:526
#6 0x00007fb2f3342816 in call_media_on_event (event=0x7fb2f36f1720 <ev_queue>, user_data=0x7fb2f3781f90 <pjsua_var+75728>) at ../src/pjsua-lib/pjsua_media.c:1562
#7 0x00007fb2f339e0b6 in event_mgr_distribute_events (mgr=mgr@entry=0x66991b5cedc8, ev_queue=0x7fb2f36f1720 <ev_queue>, next_sub=next_sub@entry=0x66991b5cf2e0, rls_lock=rls_lock@entry=0) at ../src/pjmedia/event.c:113
#8 0x00007fb2f339e8a7 in pjmedia_event_publish (mgr=0x66991b5cedc8, mgr@entry=0x0, epub=epub@entry=0x7fb288425840, event=event@entry=0x7fb2884256b0, flag=flag@entry=PJMEDIA_EVENT_PUBLISH_DEFAULT) at ../src/pjmedia/event.c:364
#9 0x00007fb2f33bc0f9 in get_frame (port=0x7fb288425840, frame=0x7fb2a1fc4e00) at ../src/pjmedia/vid_stream.c:1409
#10 0x00007fb2f33be5a9 in on_clock_tick (now=0x66991b5c9f10, user_data=0x66991b5c9d78) at ../src/pjmedia/vid_conf.c:735
#11 0x00007fb2f3396e63 in clock_thread (arg=0x66991b5c9ef0) at ../src/pjmedia/clock_thread.c:378
#12 0x00007fb2f34410f6 in thread_main (param=0x66991b5ca198) at ../src/pj/os_core_unix.c:541
#13 0x00007fb3102bd494 in start_thread (arg=0x7fb2a1fc5700) at pthread_create.c:333
#14 0x00007fb3105bbacf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
I've found that thread 1 had acquired PJSUA_LOCK at setup_vid_capture and had tried to acquire event manager mutex in pjmedia_event_subscribe.
Thread 2 had acquired event manager mutex in pjmedia_event_publish and had tried to acquire PJSUA_LOCK at pjsua_call_get_info. It"s seems to be wrong lock order in thead 1. Is any suggestions how to avoid it?
_______________________________________________ Visit our blog: http://blog.pjsip.org pjsip mailing list pjsip@xxxxxxxxxxxxxxx http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
