Project

General

Profile

Bug #5550

Modify IPTV threads during streaming makes tvheadend deadlock

Added by Pablo R. almost 6 years ago. Updated over 5 years ago.

Status:
Fixed
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
2019-02-17
Due date:
% Done:

100%

Estimated time:
Found in version:
4.3-1763
Affected Versions:

Description

The process to reproduce this crash is to be playing a channel on an IPTV thread that will not be available later (example: we are using thread 6, and we limit threads to 1). At the time of closing the connection of the channel, since that thread is not configured tvheadend enters deadlock.

REASON: deadlock (src/tvh_thread.c:512)
mutex 0x556fef04f840 locked in: src/webui/webui.c:1170 (thread 6170)
mutex 0x556fef04f840   waiting in: src/http.c:296 (thread 6147)
mutex 0x556fef04f840   waiting in: src/webui/webui.c:1170 (thread 6169)
mutex 0x556fef04f840   waiting in: src/input/mpegts/mpegts_input.c:1807 (thread 5964)
mutex 0x556fef04f840   waiting in: src/satip/rtsp.c:1886 (thread 5939)

2019-02-17 11:02:34.806 [  ALERT] CRASH: Signal: 6 in PRG: tvheadend (4.3-1763~g39db47829-dirty) [6470dab3eac76dbb42a53cdfeba45bf04e7d347c                                                                                                   ] CWD: /home/trujulu
2019-02-17 11:02:34.806 [  ALERT] CRASH: Fault address 0x6f00001733 (N/A)
2019-02-17 11:02:34.806 [  ALERT] CRASH: Loaded libraries: linux-vdso.so.1 /usr/lib/x86_64-linux-gnu/libdvbcsa.so.1 /usr/lib/x86_64-linux-                                                                                                   gnu/libssl.so.1.1 /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 /lib/x86_64-linux-gnu/libz.so.1 /lib/x86_64-linux-gnu/libpcre.so.3 /usr/lib/x                                                                                                   86_64-linux-gnu/liburiparser.so.1 /usr/lib/x86_64-linux-gnu/libavahi-common.so.3 /usr/lib/x86_64-linux-gnu/libavahi-client.so.3 /lib/x86_6                                                                                                   4-linux-gnu/libdbus-1.so.3 /lib/x86_64-linux-gnu/libdl.so.2 /lib/x86_64-linux-gnu/libpthread.so.0 /lib/x86_64-linux-gnu/libm.so.6 /lib/x86                                                                                                   _64-linux-gnu/librt.so.1 /lib/x86_64-linux-gnu/libc.so.6 /lib/x86_64-linux-gnu/libsystemd.so.0 /lib64/ld-linux-x86-64.so.2 /lib/x86_64-lin                                                                                                   ux-gnu/liblzma.so.5 /usr/lib/x86_64-linux-gnu/liblz4.so.1 /lib/x86_64-linux-gnu/libgcrypt.so.20 /lib/x86_64-linux-gnu/libgpg-error.so.0 /l                                                                                                   ib/x86_64-linux-gnu/libnss_compat.so.2 /lib/x86_64-linux-gnu/libnss_nis.so.2 /lib/x86_64-linux-gnu/libnsl.so.1 /lib/x86_64-linux-gnu/libns                                                                                                   s_files.so.2 /lib/x86_64-linux-gnu/libnss_systemd.so.2
2019-02-17 11:02:34.806 [  ALERT] CRASH: Register dump [23]: 000000000000000000007f8d7888c850000000000000000800000000000002460000000000000                                                                                                   19200000000000000020000556fef04f8400000556fef04f840000000000000000200007f8d7888c85000007f8d7888caa8000000000000000000000000000000000000000                                                                                                   00000000000007f8d794c2e9700007f8d7888c85000007f8d794c2e970000000000000246002b0000000000330000000000000000000000000000000000000000000000000                                                                                                   000000000000000
2019-02-17 11:02:34.806 [  ALERT] CRASH: STACKTRACE
2019-02-17 11:02:34.848 [  ALERT] CRASH: /root/tvheadend/src/trap.c:176 0x556feeb77fdd 0x556fee9da000
2019-02-17 11:02:34.886 [  ALERT] CRASH: ??:0 0x7f8d79e2d890 0x7f8d79e1b000
2019-02-17 11:02:34.886 [  ALERT] CRASH: gsignal+0xc7  (/lib/x86_64-linux-gnu/libc.so.6)
2019-02-17 11:02:34.886 [  ALERT] CRASH: abort+0x141  (/lib/x86_64-linux-gnu/libc.so.6)
2019-02-17 11:02:34.921 [  ALERT] CRASH: /root/tvheadend/src/tvh_thread.c:492 0x556feeb3863e 0x556fee9da000
2019-02-17 11:02:34.956 [  ALERT] CRASH: /root/tvheadend/src/tvh_thread.c:512 0x556feeb38e11 0x556fee9da000
2019-02-17 11:02:34.990 [  ALERT] CRASH: /root/tvheadend/src/tvh_thread.c:91 0x556feeb38438 0x556fee9da000

History

#1

Updated by kodiaq kodiaq almost 6 years ago

+1

#2

Updated by Jaroslav Kysela almost 6 years ago

Do the backtrace for the locked thread - src/webui/webui.c:1170 .

#3

Updated by Pablo R. almost 6 years ago 

thread: REASON: deadlock (src/tvh_thread.c:512)
thread: mutex 0x55d657065840 locked in: src/webui/webui.c:1170 (thread 2195)
thread: mutex 0x55d657065840   waiting in: src/input/mpegts/mpegts_input.c:1807 (thread 2005)

(gdb) print global_lock

$1 = {mutex = pthread_mutex_t = {Type = Normal, Status = Acquired, possibly with waiters, Owner ID = 2195, Robust = No, Shared = No, Protocol = None}, magic1 = 3614061450, tid = 2195, filename = 0x55d656cabd16 "src/webui/webui.c", lineno = 1170, tstamp = 702210125, waiters = {lh_first = 0x7f26c8001980}, link = {tqe_next = 0x0, tqe_prev = 0x55d656ff1860 <thrwatch_mutexes>}, magic2 = 4181353505}

(gdb) thread find 2195

Thread 119 has target id 'Thread 0x7f270adf6700 (LWP 2195)'

(gdb) info threads 119

  Id   Target Id         Frame 
  119  Thread 0x7f270adf6700 (LWP 2195) "tvh:tcp-start" mpegts_mux_stop (mm=0x55d657907b00, force=1, reason=0) at src/input/mpegts/mpegts_mux.c:838

(gdb) thread 119

[Switching to thread 119 (Thread 0x7f270adf6700 (LWP 2195))]
#0  mpegts_mux_stop (mm=0x55d657907b00, force=1, reason=0) at src/input/mpegts/mpegts_mux.c:838
warning: Source file is more recent than executable.
838      /* Stop possible recursion */

(gdb) bt

#0  mpegts_mux_stop (mm=0x55d657907b00, force=1, reason=0) at src/input/mpegts/mpegts_mux.c:838
#1  0x000055d656c13597 in mpegts_input_stop_all (mi=0x7f2698008a90) at src/input/mpegts/mpegts_input.c:2135
#2  0x000055d656c5e043 in iptv_input_thread_manage (count=1, force=0) at src/input/mpegts/iptv/iptv.c:1237
#3  0x000055d656c19559 in mpegts_mux_stop (mm=0x55d657907b00, force=<optimized out>, reason=0) at src/input/mpegts/mpegts_mux.c:879
#4  0x000055d656c1d9fd in mpegts_service_stop (t=0x55d657902080) at src/input/mpegts/mpegts_service.c:440
#5  0x000055d656b76525 in service_stop (t=t@entry=0x55d657902080) at src/service.c:259
#6  0x000055d656b73ccc in subscription_unlink_service0 (s=s@entry=0x7f26c4008220, reason=reason@entry=0, resched=resched@entry=0) at src/subscriptions.c:164
#7  0x000055d656b73fd7 in subscription_unlink_service (s=s@entry=0x7f26c4008220, reason=reason@entry=0) at src/subscriptions.c:171
#8  0x000055d656b76601 in service_remove_subscriber (t=t@entry=0x55d657902080, s=s@entry=0x7f26c4008220, reason=reason@entry=0) at src/service.c:301
#9  0x000055d656b74340 in subscription_unsubscribe (s=s@entry=0x7f26c4008220, flags=flags@entry=2) at src/subscriptions.c:736
#10 0x000055d656becccc in http_stream_service (hc=hc@entry=0x7f270adf59b0, service=<optimized out>, weight=weight@entry=0) at src/webui/webui.c:1171
#11 0x000055d656becfed in http_stream (hc=0x7f270adf59b0, remain=<optimized out>, opaque=<optimized out>) at src/webui/webui.c:1380
#12 0x000055d656b5b5d5 in http_exec (hc=hc@entry=0x7f270adf59b0, hp=hp@entry=0x7f270adf5670, remain=0x7f26c40014ac "service") at src/http.c:1241
#13 0x000055d656b5c87a in http_cmd_get (hc=hc@entry=0x7f270adf59b0) at src/http.c:1316
#14 0x000055d656b5cab5 in http_process_request (hc=0x7f270adf59b0, spill=<optimized out>) at src/http.c:1398
#15 0x000055d656b5bc59 in process_request (hc=hc@entry=0x7f270adf59b0, spill=spill@entry=0x7f270adf5930) at src/http.c:1533
#16 0x000055d656b5ce3b in http_serve_requests (hc=hc@entry=0x7f270adf59b0) at src/http.c:2018
#17 0x000055d656b5d159 in http_serve (fd=103, opaque=0x7f273c002390, peer=0x7f273c0023a8, self=0x7f273c002428) at src/http.c:2069
#18 0x000055d656b53460 in tcp_server_start (aux=0x7f273c002360) at src/tcp.c:724
#19 0x000055d656b4e438 in thread_wrapper (p=0x7f273c002670) at src/tvh_thread.c:91
#20 0x00007f276aae26db in start_thread (arg=0x7f270adf6700) at pthread_create.c:463
#21 0x00007f276a26588f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Detaching from program: /usr/bin/tvheadend, process 1980
#4

Updated by Pablo R. almost 6 years ago

Same deadlock for 'mux' instead of 'service':

REASON: deadlock (src/tvh_thread.c:512)
mutex 0x555555bc9840 locked in: src/webui/webui.c:1249 (thread 15806)
mutex 0x555555bc9840   waiting in: src/input/mpegts/mpegts_input.c:1807 (thread 15795)
mutex 0x555555bc9840   waiting in: src/main.c:703 (thread 15694)
mutex 0x7fffe002dbc0 other in: src/httpc.c:1194 (thread 15698)

(gdb) bt full

#0  0x00007ffff5b33bb7 in epoll_wait (epfd=97, events=0x7fffec001220, maxevents=1, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
        resultvar = 18446744073709551612
        sc_cancel_oldtype = 0
        sc_ret = <optimized out>
#1  0x00005555556f374d in tvhpoll_wait (tp=0x7fffec00b7e0, evs=evs@entry=0x7fff2a7d2b80, num=num@entry=1, ms=ms@entry=-1) at src/tvhpoll.c:336
        nfds = 0
        i = <optimized out>
#2  0x00005555557c4061 in iptv_input_thread (aux=0x7fffec002770) at src/input/mpegts/iptv/iptv.c:528
        pool = 0x7fffec002770
        nfds = <optimized out>
        r = <optimized out>
        n = <optimized out>
        im = <optimized out>
        mi = <optimized out>
        ev = {fd = 0, events = 0, ptr = 0x0}
#3  0x00005555556b2448 in thread_wrapper (p=0x7fffec00a010) at src/tvh_thread.c:91
        ts = <optimized out>
        set = {__val = {16388, 0 <repeats 15 times>}}
        r = <optimized out>
#4  0x00007ffff63b06db in start_thread (arg=0x7fff2a7d3700) at pthread_create.c:463
        pd = 0x7fff2a7d3700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140733906237184, 6790504611084590911, 140733906234688, 0, 140737152851984, 140733908332416, -6790615642940022977, -6790483202057347265}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
#5  0x00007ffff5b3388f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.

(gdb) print global_lock

$1 = {mutex = pthread_mutex_t = {Type = Normal, Status = Acquired, possibly with waiters, Owner ID = 15806, Robust = No, Shared = No, Protocol = None}, magic1 = 3614061450, tid = 15806, filename = 0x55555580fff6 "src/webui/webui.c", lineno = 1249, tstamp = 338440109, waiters = {lh_first = 0x555555e0a8a0}, link = {tqe_next = 0x0, tqe_prev = 0x555555b55860 <thrwatch_mutexes>}, magic2 = 4181353505}

(gdb) thread find 15806

Thread 119 has target id 'Thread 0x7fff289c4700 (LWP 15806)'

(gdb) info threads 119

  Id   Target Id         Frame 
  119  Thread 0x7fff289c4700 (LWP 15806) "tvh:tcp-start" 0x00007ffff63b1d2d in __GI___pthread_timedjoin_ex (threadid=140733906237184, thread_return=thread_return@entry=0x0, abstime=abstime@entry=0x0, block=block@entry=true) at pthread_join_common.c:89

(gdb) thread 119

[Switching to thread 119 (Thread 0x7fff289c4700 (LWP 15806))]
#0  0x00007ffff63b1d2d in __GI___pthread_timedjoin_ex (threadid=140733906237184, thread_return=thread_return@entry=0x0, abstime=abstime@entry=0x0, block=block@entry=true) at pthread_join_common.c:89
89    pthread_join_common.c: No such file or directory.

(gdb) bt

#0  0x00007ffff63b1d2d in __GI___pthread_timedjoin_ex (threadid=140733906237184, thread_return=thread_return@entry=0x0, abstime=abstime@entry=0x0, block=block@entry=true) at pthread_join_common.c:89
#1  0x00007ffff63b1b5c in __pthread_join (threadid=<optimized out>, thread_return=thread_return@entry=0x0) at pthread_join.c:24
#2  0x00005555557c2300 in iptv_input_thread_manage (count=1, force=0) at src/input/mpegts/iptv/iptv.c:1235
#3  0x000055555577d569 in mpegts_mux_stop (mm=0x555555c17cb0, force=<optimized out>, reason=0) at src/input/mpegts/mpegts_mux.c:879
#4  0x0000555555781a0d in mpegts_service_stop (t=0x7fff5c008330) at src/input/mpegts/mpegts_service.c:440
#5  0x00005555556da535 in service_stop (t=t@entry=0x7fff5c008330) at src/service.c:259
#6  0x00005555556d7cdc in subscription_unlink_service0 (s=s@entry=0x7fff5c0088c0, reason=reason@entry=0, resched=resched@entry=0) at src/subscriptions.c:164
#7  0x00005555556d7fe7 in subscription_unlink_service (s=s@entry=0x7fff5c0088c0, reason=reason@entry=0) at src/subscriptions.c:171
#8  0x00005555556da611 in service_remove_subscriber (t=t@entry=0x7fff5c008330, s=s@entry=0x7fff5c0088c0, reason=reason@entry=0) at src/service.c:301
#9  0x00005555556d8350 in subscription_unsubscribe (s=s@entry=0x7fff5c0088c0, flags=flags@entry=2) at src/subscriptions.c:736
#10 0x000055555574ff0b in http_stream_mux (hc=hc@entry=0x7fff289c39b0, mm=<optimized out>, weight=weight@entry=0) at src/webui/webui.c:1251
#11 0x0000555555750f15 in http_stream (hc=0x7fff289c39b0, remain=<optimized out>, opaque=<optimized out>) at src/webui/webui.c:1383
#12 0x00005555556bf5e5 in http_exec (hc=hc@entry=0x7fff289c39b0, hp=hp@entry=0x7fff289c3670, remain=0x7fff5c00162c "mux") at src/http.c:1241
#13 0x00005555556c088a in http_cmd_get (hc=hc@entry=0x7fff289c39b0) at src/http.c:1316
#14 0x00005555556c0ac5 in http_process_request (hc=0x7fff289c39b0, spill=<optimized out>) at src/http.c:1398
#15 0x00005555556bfc69 in process_request (hc=hc@entry=0x7fff289c39b0, spill=spill@entry=0x7fff289c3930) at src/http.c:1533
#16 0x00005555556c0e4b in http_serve_requests (hc=hc@entry=0x7fff289c39b0) at src/http.c:2018
#17 0x00005555556c1169 in http_serve (fd=103, opaque=0x7fffd000dbc0, peer=0x7fffd000dbd8, self=0x7fffd000dc58) at src/http.c:2069
#18 0x00005555556b7470 in tcp_server_start (aux=0x7fffd000db90) at src/tcp.c:724
#19 0x00005555556b2448 in thread_wrapper (p=0x7fffd000dd20) at src/tvh_thread.c:91
#20 0x00007ffff63b06db in start_thread (arg=0x7fff289c4700) at pthread_create.c:463
#21 0x00007ffff5b3388f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
#5

Updated by Pablo R. over 5 years ago

Any ideas? Perhaps kicking retransmissions whose threads are not available is a solution (at the time of reduce threads).

#6

Updated by Jaroslav Kysela over 5 years ago

Retest with latest.

#7

Updated by Pablo R. over 5 years ago

It seems to continue.

thread: REASON: deadlock (src/tvh_thread.c:512)
thread: mutex 0x55b4dd061a20 locked in: src/webui/webui.c:1170 (thread 9277)
thread: mutex 0x55b4dd061a20   waiting in: src/main.c:703 (thread 9004)

Thread 104 "tvh:iptv" received signal SIGQUIT, Quit.
[Switching to Thread 0x7f14527f3700 (LWP 9261)]
0x00007f151dceabb7 in epoll_wait (epfd=98, events=0x7f1460008d10, maxevents=1, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
30      ../sysdeps/unix/sysv/linux/epoll_wait.c: No such file or directory.
(gdb) bt
#0  0x00007f151dceabb7 in epoll_wait (epfd=98, events=0x7f1460008d10, maxevents=1, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1  0x000055b4db964bcd in tvhpoll_wait (tp=0x7f1460008c70, evs=evs@entry=0x7f14527f2980, num=num@entry=1, ms=ms@entry=-1) at src/tvhpoll.c:336
#2  0x000055b4dba3676b in iptv_input_thread (aux=0x7f1460008c30) at src/input/mpegts/iptv/iptv.c:529
#3  0x000055b4db9238c8 in thread_wrapper (p=0x7f1460008280) at src/tvh_thread.c:91
#4  0x00007f151eb1a6db in start_thread (arg=0x7f14527f3700) at pthread_create.c:463
#5  0x00007f151dcea88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
#8

Updated by Jaroslav Kysela over 5 years ago

  • Status changed from New to Fixed
  • % Done changed from 0 to 100

Applied in changeset commit:tvheadend|65c63116c23df8ea72ba6caa63fb70c94d3b106e.

#9

Updated by Pablo R. over 5 years ago

Tested again, I close one stream, the other continues working but tvh webui stops working (freezes)

GDB stops openning or closing threads, it does not show any code stop either.

#10

Updated by Pablo R. over 5 years ago 

REASON: deadlock (src/tvh_thread.c:512)
mutex 0x55785ddd4a20 locked in: src/webui/webui.c:1170 (thread 4870)
mutex 0x55785ddd4a20   waiting in: src/http.c:296 (thread 4854)
mutex 0x55785ddd4a20   waiting in: src/main.c:703 (thread 4763)
mutex 0x55785ddd4a20   waiting in: src/input/mpegts/mpegts_input.c:1807 (thread 4864)
2019-02-27 18:15:09.124 [  ALERT] CRASH: Signal: 6 in PRG: /usr/bin/tvheadend (4.3-1770~g65c63116c) [e5955c5e882d0f6f91a0be0f79c570381f9598e8] CWD: /root/tvheadend
2019-02-27 18:15:09.124 [  ALERT] CRASH: Fault address 0x6f00001294 (N/A)
2019-02-27 18:15:09.124 [  ALERT] CRASH: Loaded libraries: linux-vdso.so.1 /usr/lib/x86_64-linux-gnu/libdvbcsa.so.1 /usr/lib/x86_64-linux-gnu/libssl.so.1.1 /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 /lib/x86_64-linux-gnu/libz.so.1 /usr/lib/x86_64-linux-gnu/libpcre2-8.so.0 /usr/lib/x86_64-linux-gnu/liburiparser.so.1 /usr/lib/x86_64-linux-gnu/libavahi-common.so.3 /usr/lib/x86_64-linux-gnu/libavahi-client.so.3 /lib/x86_64-linux-gnu/libdbus-1.so.3 /lib/x86_64-linux-gnu/libdl.so.2 /lib/x86_64-linux-gnu/libpthread.so.0 /lib/x86_64-linux-gnu/libm.so.6 /lib/x86_64-linux-gnu/librt.so.1 /lib/x86_64-linux-gnu/libmvec.so.1 /usr/lib/x86_64-linux-gnu/libstdc++.so.6 /lib/x86_64-linux-gnu/libc.so.6 /lib/x86_64-linux-gnu/libsystemd.so.0 /lib64/ld-linux-x86-64.so.2 /lib/x86_64-linux-gnu/libgcc_s.so.1 /lib/x86_64-linux-gnu/liblzma.so.5 /usr/lib/x86_64-linux-gnu/liblz4.so.1 /lib/x86_64-linux-gnu/libgcrypt.so.20 /lib/x86_64-linux-gnu/libgpg-error.so.0 /lib/x86_64-linux-gnu/libnss_compat.so.2 /lib/x86_64-linux-gnu/libnss_nis.so.2 /lib/x86_64-linux-gnu/libnsl.so.1
2019-02-27 18:15:09.124 [  ALERT] CRASH: Register dump [23]: 000000000000000000007f3fae9e46500000000000000008000000000000024600000000000001430000000000000002000055785ddd4a20000055785ddd4a20000000000000000200007f3fae9e465000007f3fae9e48a800000000000000000000000000000000000000000000000000007f3faf832e9700007f3fae9e465000007f3faf832e970000000000000246002b0000000000330000000000000000000000000000000000000000000000000000000000000000
2019-02-27 18:15:09.124 [  ALERT] CRASH: STACKTRACE
2019-02-27 18:15:09.251 [  ALERT] CRASH: /project/repo/checkout/src/trap.c:176 0x55785c6d646d 0x55785c4c1000
2019-02-27 18:15:09.389 [  ALERT] CRASH: ??:0 0x7f3fb0750890 0x7f3fb073e000
2019-02-27 18:15:09.389 [  ALERT] CRASH: gsignal+0xc7  (/lib/x86_64-linux-gnu/libc.so.6)
2019-02-27 18:15:09.389 [  ALERT] CRASH: abort+0x141  (/lib/x86_64-linux-gnu/libc.so.6)
2019-02-27 18:15:09.517 [  ALERT] CRASH: /project/repo/checkout/src/tvh_thread.c:492 0x55785c696ace 0x55785c4c1000
2019-02-27 18:15:09.660 [  ALERT] CRASH: /project/repo/checkout/src/tvh_thread.c:512 0x55785c6972a1 0x55785c4c1000
2019-02-27 18:15:09.807 [  ALERT] CRASH: /project/repo/checkout/src/tvh_thread.c:91 0x55785c6968c8 0x55785c4c1000
Aborted (core dumped)
#11

Updated by Jaroslav Kysela over 5 years ago

Do the backtrace in the locked thread - 'mutex 0x55785ddd4a20 locked in: src/webui/webui.c:1170 (thread 4870)' .

#12

Updated by Jaroslav Kysela over 5 years ago

Fixed in v4.3-1771-gd2405f298 .

#13

Updated by Pablo R. over 5 years ago

It seems that it no longer crashes. (/)

It seems that it does strange things when opening and closing channels once the threads have been modified but at least it is more stable now
(ex. thread 1 not used and so).

Also available in: Atom PDF