Opened 11 years ago
Closed 11 years ago
#4258 closed defect (fixed)
HEVC Decoder Hang in Multi-threaded Slice Type Decoding
| Reported by: | Jose Santiago | Owned by: | |
|---|---|---|---|
| Priority: | important | Component: | avcodec |
| Version: | git-master | Keywords: | hevc deadlock regression |
| Cc: | Blocked By: | ||
| Blocking: | Reproduced by developer: | yes | |
| Analyzed by developer: | no |
Description
Issue Description:
I have been using the HEVC decoder in Multi-threaded Slice Type Decoding HEVC streams in TS over UDP. I would run into very intermittent situations where the HEVC decoder would fail to return from avcodec_decode_video2(). Sometimes the issue would happen quickly (within a couple of hours) other times there would be days between failures. When I run the decoder in single threaded mode it never has an issue. So after some debugging, I found that when the decoder gets in this state all of the threads are blocked in ff_thread_await_progress2() apparently waiting for hls_slice_data_wpp() to finish. After looking at the issue for a bit, it seems that the hang can be caused by minor bitstream loss or corruption on the network stream. After a bit of work I was able to produce a somewhat minimal test case where I can reproduce the issue with the FFMPEG and the FFPLAY applications. I will attempt to attach the PCAP of the stream and the stack trace of FFMPEG and FFPLAY when they hang.
How to reproduce:
% ffmpeg_gvcodec hevc -threads 10 -thread_type slice -i udp://@239.36.13.100:4900 -f null /dev/null % ffplay_g -vcodec hevc -threads 10 -thread_type slice udp://@239.36.13.100:4900 Built from GIT master branch ad465e789721194a6bc08a0b02dbbd9b19960f41 from 20150107 .
Console Output:
ffmpeg version 2.5.git-VF Copyright (c) 2000-2015 the FFmpeg developers
built on Jan 13 2015 12:24:20 with gcc 4.5.2 (GCC)
configuration: --extra-version=VF --prefix=/mnt/centshare/ffmpeg/trunk/build/build-linux/stage --extra-cflags='-I/mnt/centshare/ffmpeg/trunk/build/../src/libavformat -I/mnt/centshare/ffmpeg/trunk/build/../src/libavcodec -I/usr/include/SDL -D_GNU_SOURCE=1 -D_REENTRANT' --extra-ldflags='-L/mnt/centshare/ffmpeg/trunk/build/build-linux/stage/lib -Wl,-rpath -Wl,/mnt/centshare/ffmpeg/trunk/build/build-linux/stage/lib -I/usr/include/SDL -D_GNU_SOURCE=1 -D_REENTRANT ' --enable-static --disable-shared --enable-avfilter --enable-pthreads --enable-zlib --enable-bzlib --enable-runtime-cpudetect --enable-hardcoded-tables
libavutil 54. 16.100 / 54. 16.100
libavcodec 56. 20.100 / 56. 20.100
libavformat 56. 18.100 / 56. 18.100
libavdevice 56. 3.100 / 56. 3.100
libavfilter 5. 6.100 / 5. 6.100
libswscale 3. 1.101 / 3. 1.101
libswresample 1. 1.100 / 1. 1.100
[hevc @ 0x9382220] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x9382220] Error parsing NAL unit #2.
[hevc @ 0x9382220] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x9382220] Error parsing NAL unit #2.
[hevc @ 0x9382220] PPS id out of range: 0
Last message repeated 1 times
...
[hevc @ 0x9382220] Error parsing NAL unit #2.
[mpegts @ 0x9363960] DTS 2559798793 < 2562088580 out of order
Input #0, mpegts, from 'udp://@239.36.13.100:4900':
Duration: N/A, start: 28466.483056, bitrate: N/A
Program 1
Metadata:
service_name : Haivision Network Video Media Server
service_provider: Haivision Network Video http://www.haivision.com
Stream #0:0[0x100]: Audio: aac (LC) ([15][0][0][0] / 0x000F), 48000 Hz, stereo, fltp, 142 kb/s
Stream #0:1[0x21]: Video: hevc (Main) ([36][0][0][0] / 0x0024), yuv420p(tv), 1280x720 [SAR 1:1 DAR 16:9], 29.97 fps, 29.97 tbr, 90k tbn, 29.97 tbc
Output #0, null, to '/dev/null':
Metadata:
encoder : Lavf56.18.100
Stream #0:0: Video: rawvideo (I420 / 0x30323449), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], q=2-31, 200 kb/s, 29.97 fps, 29.97 tbn, 29.97 tbc
Metadata:
encoder : Lavc56.20.100 rawvideo
Stream #0:1: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s
Metadata:
encoder : Lavc56.20.100 pcm_s16le
Stream mapping:
Stream #0:1 -> #0:0 (hevc (native) -> rawvideo (native))
Stream #0:0 -> #0:1 (aac (native) -> pcm_s16le (native))
Press [q] to stop, [?] for help
...
[hevc @ 0x9443860] Error parsing NAL unit #2.
[hevc @ 0x9443860] Could not find ref with POC 23
[hevc @ 0x9443860] Could not find ref with POC 22
frame= 52 fps=0.0 q=0.0 size=N/A time=00:00:03.18 bitrate=N/A
frame= 101 fps=100 q=0.0 size=N/A time=00:00:04.81 bitrate=N/A
frame= 157 fps=103 q=0.0 size=N/A time=00:00:06.68 bitrate=N/A
frame= 179 fps= 88 q=0.0 size=N/A time=00:00:07.43 bitrate=N/A
frame= 196 fps= 77 q=0.0 size=N/A time=00:00:07.96 bitrate=N/A
frame= 211 fps= 69 q=0.0 size=N/A time=00:00:08.50 bitrate=N/A
frame= 226 fps= 63 q=0.0 size=N/A time=00:00:08.99 bitrate=N/A
frame= 242 fps= 59 q=0.0 size=N/A time=00:00:09.50 bitrate=N/A
frame= 257 fps= 56 q=0.0 size=N/A time=00:00:10.03 bitrate=N/A
frame= 273 fps= 53 q=0.0 size=N/A time=00:00:10.52 bitrate=N/A
frame= 288 fps= 51 q=0.0 size=N/A time=00:00:11.06 bitrate=N/A
frame= 304 fps= 49 q=0.0 size=N/A time=00:00:11.57 bitrate=N/A
frame= 320 fps= 48 q=0.0 size=N/A time=00:00:12.08 bitrate=N/A
frame= 335 fps= 47 q=0.0 size=N/A time=00:00:12.59 bitrate=N/A
frame= 350 fps= 45 q=0.0 size=N/A time=00:00:13.13 bitrate=N/A
frame= 365 fps= 44 q=0.0 size=N/A time=00:00:13.62 bitrate=N/A
frame= 381 fps= 44 q=0.0 size=N/A time=00:00:14.17 bitrate=N/A
frame= 396 fps= 43 q=0.0 size=N/A time=00:00:14.64 bitrate=N/A
frame= 412 fps= 42 q=0.0 size=N/A time=00:00:15.17 bitrate=N/A
frame= 427 fps= 42 q=0.0 size=N/A time=00:00:15.66 bitrate=N/A
frame= 443 fps= 41 q=0.0 size=N/A time=00:00:16.18 bitrate=N/A
frame= 458 fps= 40 q=0.0 size=N/A time=00:00:16.69 bitrate=N/A
frame= 473 fps= 40 q=0.0 size=N/A time=00:00:17.24 bitrate=N/A
frame= 487 fps= 39 q=0.0 size=N/A time=00:00:17.71 bitrate=N/A
frame= 505 fps= 39 q=0.0 size=N/A time=00:00:18.29 bitrate=N/A
frame= 519 fps= 39 q=0.0 size=N/A time=00:00:18.74 bitrate=N/A
frame= 534 fps= 39 q=0.0 size=N/A time=00:00:19.27 bitrate=N/A
frame= 548 fps= 38 q=0.0 size=N/A time=00:00:19.74 bitrate=N/A
frame= 564 fps= 38 q=0.0 size=N/A time=00:00:20.27 bitrate=N/A
frame= 579 fps= 38 q=0.0 size=N/A time=00:00:20.74 bitrate=N/A
frame= 593 fps= 37 q=0.0 size=N/A time=00:00:21.21 bitrate=N/A
frame= 608 fps= 37 q=0.0 size=N/A time=00:00:21.72 bitrate=N/A
frame= 625 fps= 37 q=0.0 size=N/A time=00:00:22.32 bitrate=N/A
frame= 642 fps= 37 q=0.0 size=N/A time=00:00:22.85 bitrate=N/A
frame= 657 fps= 37 q=0.0 size=N/A time=00:00:23.37 bitrate=N/A
frame= 672 fps= 36 q=0.0 size=N/A time=00:00:23.90 bitrate=N/A
frame= 687 fps= 36 q=0.0 size=N/A time=00:00:24.39 bitrate=N/A
frame= 702 fps= 36 q=0.0 size=N/A time=00:00:24.88 bitrate=N/A
frame= 717 fps= 36 q=0.0 size=N/A time=00:00:25.39 bitrate=N/A
frame= 733 fps= 36 q=0.0 size=N/A time=00:00:25.93 bitrate=N/A
frame= 748 fps= 36 q=0.0 size=N/A time=00:00:26.40 bitrate=N/A
frame= 763 fps= 35 q=0.0 size=N/A time=00:00:26.91 bitrate=N/A
[mpegts @ 0x9363960] DTS 2559798793 < 2562088580 out of order
[hevc @ 0x9443860] Could not find ref with POC 23
[hevc @ 0x9443860] Could not find ref with POC 22
frame= 773 fps= 35 q=0.0 size=N/A time=00:00:27.27 bitrate=N/A
frame= 788 fps= 35 q=0.0 size=N/A time=00:00:27.78 bitrate=N/A
frame= 804 fps= 35 q=0.0 size=N/A time=00:00:28.32 bitrate=N/A
frame= 818 fps= 35 q=0.0 size=N/A time=00:00:28.78 bitrate=N/A
frame= 834 fps= 35 q=0.0 size=N/A time=00:00:29.32 bitrate=N/A
frame= 849 fps= 35 q=0.0 size=N/A time=00:00:29.83 bitrate=N/A
frame= 865 fps= 34 q=0.0 size=N/A time=00:00:30.34 bitrate=N/A
frame= 881 fps= 34 q=0.0 size=N/A time=00:00:30.88 bitrate=N/A
frame= 896 fps= 34 q=0.0 size=N/A time=00:00:31.37 bitrate=N/A
frame= 911 fps= 34 q=0.0 size=N/A time=00:00:31.90 bitrate=N/A
frame= 927 fps= 34 q=0.0 size=N/A time=00:00:32.37 bitrate=N/A
frame= 941 fps= 34 q=0.0 size=N/A time=00:00:32.88 bitrate=N/A
frame= 957 fps= 34 q=0.0 size=N/A time=00:00:33.41 bitrate=N/A
frame= 972 fps= 34 q=0.0 size=N/A time=00:00:33.93 bitrate=N/A
frame= 987 fps= 34 q=0.0 size=N/A time=00:00:34.42 bitrate=N/A
frame= 1003 fps= 34 q=0.0 size=N/A time=00:00:34.93 bitrate=N/A
frame= 1018 fps= 34 q=0.0 size=N/A time=00:00:35.46 bitrate=N/A
frame= 1034 fps= 34 q=0.0 size=N/A time=00:00:35.95 bitrate=N/A
frame= 1049 fps= 34 q=0.0 size=N/A time=00:00:36.46 bitrate=N/A
frame= 1065 fps= 34 q=0.0 size=N/A time=00:00:36.98 bitrate=N/A
frame= 1079 fps= 33 q=0.0 size=N/A time=00:00:37.47 bitrate=N/A
frame= 1094 fps= 33 q=0.0 size=N/A time=00:00:37.98 bitrate=N/A
frame= 1109 fps= 33 q=0.0 size=N/A time=00:00:38.49 bitrate=N/A
frame= 1124 fps= 33 q=0.0 size=N/A time=00:00:38.96 bitrate=N/A
frame= 1140 fps= 33 q=0.0 size=N/A time=00:00:39.47 bitrate=N/A
frame= 1154 fps= 33 q=0.0 size=N/A time=00:00:40.01 bitrate=N/A
frame= 1170 fps= 33 q=0.0 size=N/A time=00:00:40.52 bitrate=N/A
frame= 1185 fps= 33 q=0.0 size=N/A time=00:00:41.03 bitrate=N/A
frame= 1201 fps= 33 q=0.0 size=N/A time=00:00:41.54 bitrate=N/A
frame= 1216 fps= 33 q=0.0 size=N/A time=00:00:42.03 bitrate=N/A
frame= 1231 fps= 33 q=0.0 size=N/A time=00:00:42.54 bitrate=N/A
frame= 1246 fps= 33 q=0.0 size=N/A time=00:00:43.04 bitrate=N/A
frame= 1261 fps= 33 q=0.0 size=N/A time=00:00:43.55 bitrate=N/A
frame= 1276 fps= 33 q=0.0 size=N/A time=00:00:44.04 bitrate=N/A
frame= 1289 fps= 33 q=0.0 size=N/A time=00:00:44.49 bitrate=N/A
frame= 1306 fps= 33 q=0.0 size=N/A time=00:00:45.06 bitrate=N/A
frame= 1320 fps= 33 q=0.0 size=N/A time=00:00:45.53 bitrate=N/A
frame= 1337 fps= 33 q=0.0 size=N/A time=00:00:46.06 bitrate=N/A
frame= 1352 fps= 33 q=0.0 size=N/A time=00:00:46.56 bitrate=N/A
frame= 1366 fps= 33 q=0.0 size=N/A time=00:00:47.07 bitrate=N/A
frame= 1382 fps= 33 q=0.0 size=N/A time=00:00:47.62 bitrate=N/A
frame= 1398 fps= 33 q=0.0 size=N/A time=00:00:48.13 bitrate=N/A
frame= 1413 fps= 33 q=0.0 size=N/A time=00:00:48.67 bitrate=N/A
frame= 1428 fps= 33 q=0.0 size=N/A time=00:00:49.16 bitrate=N/A
frame= 1444 fps= 32 q=0.0 size=N/A time=00:00:49.67 bitrate=N/A
frame= 1459 fps= 32 q=0.0 size=N/A time=00:00:50.16 bitrate=N/A
frame= 1474 fps= 32 q=0.0 size=N/A time=00:00:50.67 bitrate=N/A
frame= 1489 fps= 32 q=0.0 size=N/A time=00:00:51.18 bitrate=N/A
frame= 1504 fps= 32 q=0.0 size=N/A time=00:00:51.68 bitrate=N/A
frame= 1519 fps= 32 q=0.0 size=N/A time=00:00:52.21 bitrate=N/A
frame= 1530 fps= 32 q=0.0 size=N/A time=00:00:52.57 bitrate=N/A
[mpegts @ 0x9363960] DTS 2559798793 < 2562088580 out of order
[hevc @ 0x9443860] Could not find ref with POC 23
[hevc @ 0x9443860] Could not find ref with POC 22
frame= 1546 fps= 32 q=0.0 size=N/A time=00:00:53.10 bitrate=N/A
frame= 1561 fps= 32 q=0.0 size=N/A time=00:00:53.60 bitrate=N/A
frame= 1577 fps= 32 q=0.0 size=N/A time=00:00:54.15 bitrate=N/A
frame= 1591 fps= 32 q=0.0 size=N/A time=00:00:54.62 bitrate=N/A
frame= 1608 fps= 32 q=0.0 size=N/A time=00:00:55.13 bitrate=N/A
frame= 1623 fps= 32 q=0.0 size=N/A time=00:00:55.64 bitrate=N/A
frame= 1638 fps= 32 q=0.0 size=N/A time=00:00:56.18 bitrate=N/A
frame= 1652 fps= 32 q=0.0 size=N/A time=00:00:56.65 bitrate=N/A
frame= 1669 fps= 32 q=0.0 size=N/A time=00:00:57.16 bitrate=N/A
frame= 1683 fps= 32 q=0.0 size=N/A time=00:00:57.67 bitrate=N/A
frame= 1699 fps= 32 q=0.0 size=N/A time=00:00:58.20 bitrate=N/A
frame= 1714 fps= 32 q=0.0 size=N/A time=00:00:58.67 bitrate=N/A
frame= 1729 fps= 32 q=0.0 size=N/A time=00:00:59.21 bitrate=N/A
frame= 1744 fps= 32 q=0.0 size=N/A time=00:00:59.68 bitrate=N/A
frame= 1759 fps= 32 q=0.0 size=N/A time=00:01:00.21 bitrate=N/A
frame= 1774 fps= 32 q=0.0 size=N/A time=00:01:00.70 bitrate=N/A
frame= 1789 fps= 32 q=0.0 size=N/A time=00:01:01.21 bitrate=N/A
frame= 1804 fps= 32 q=0.0 size=N/A time=00:01:01.72 bitrate=N/A
frame= 1820 fps= 32 q=0.0 size=N/A time=00:01:02.21 bitrate=N/A
frame= 1835 fps= 32 q=0.0 size=N/A time=00:01:02.75 bitrate=N/A
frame= 1849 fps= 32 q=0.0 size=N/A time=00:01:03.22 bitrate=N/A
frame= 1865 fps= 32 q=0.0 size=N/A time=00:01:03.73 bitrate=N/A
frame= 1881 fps= 32 q=0.0 size=N/A time=00:01:04.26 bitrate=N/A
frame= 1895 fps= 32 q=0.0 size=N/A time=00:01:04.75 bitrate=N/A
frame= 1911 fps= 32 q=0.0 size=N/A time=00:01:05.29 bitrate=N/A
frame= 1928 fps= 32 q=0.0 size=N/A time=00:01:05.80 bitrate=N/A
frame= 1944 fps= 32 q=0.0 size=N/A time=00:01:06.33 bitrate=N/A
frame= 1959 fps= 32 q=0.0 size=N/A time=00:01:06.84 bitrate=N/A
frame= 1975 fps= 32 q=0.0 size=N/A time=00:01:07.38 bitrate=N/A
frame= 1991 fps= 32 q=0.0 size=N/A time=00:01:07.91 bitrate=N/A
frame= 2006 fps= 32 q=0.0 size=N/A time=00:01:08.40 bitrate=N/A
frame= 2019 fps= 32 q=0.0 size=N/A time=00:01:08.87 bitrate=N/A
frame= 2036 fps= 32 q=0.0 size=N/A time=00:01:09.45 bitrate=N/A
frame= 2050 fps= 32 q=0.0 size=N/A time=00:01:09.87 bitrate=N/A
frame= 2065 fps= 32 q=0.0 size=N/A time=00:01:10.41 bitrate=N/A
frame= 2080 fps= 32 q=0.0 size=N/A time=00:01:10.92 bitrate=N/A
frame= 2097 fps= 32 q=0.0 size=N/A time=00:01:11.49 bitrate=N/A
frame= 2111 fps= 32 q=0.0 size=N/A time=00:01:11.92 bitrate=N/A
frame= 2125 fps= 32 q=0.0 size=N/A time=00:01:12.43 bitrate=N/A
frame= 2141 fps= 32 q=0.0 size=N/A time=00:01:12.99 bitrate=N/A
frame= 2157 fps= 31 q=0.0 size=N/A time=00:01:13.52 bitrate=N/A
frame= 2172 fps= 31 q=0.0 size=N/A time=00:01:14.01 bitrate=N/A
frame= 2187 fps= 31 q=0.0 size=N/A time=00:01:14.52 bitrate=N/A
frame= 2203 fps= 31 q=0.0 size=N/A time=00:01:15.01 bitrate=N/A
frame= 2218 fps= 31 q=0.0 size=N/A time=00:01:15.50 bitrate=N/A
frame= 2233 fps= 31 q=0.0 size=N/A time=00:01:16.04 bitrate=N/A
frame= 2248 fps= 31 q=0.0 size=N/A time=00:01:16.55 bitrate=N/A
frame= 2263 fps= 31 q=0.0 size=N/A time=00:01:17.06 bitrate=N/A
frame= 2278 fps= 31 q=0.0 size=N/A time=00:01:17.57 bitrate=N/A
frame= 2293 fps= 31 q=0.0 size=N/A time=00:01:18.06 bitrate=N/A
[mpegts @ 0x9363960] DTS 2559798793 < 2562088580 out of order
[hevc @ 0x9443860] Could not find ref with POC 23
[hevc @ 0x9443860] Could not find ref with POC 22
frame= 2309 fps= 31 q=0.0 size=N/A time=00:01:18.60 bitrate=N/A
frame= 2324 fps= 31 q=0.0 size=N/A time=00:01:19.09 bitrate=N/A
frame= 2340 fps= 31 q=0.0 size=N/A time=00:01:19.64 bitrate=N/A
frame= 2354 fps= 31 q=0.0 size=N/A time=00:01:20.11 bitrate=N/A
frame= 2371 fps= 31 q=0.0 size=N/A time=00:01:20.62 bitrate=N/A
frame= 2386 fps= 31 q=0.0 size=N/A time=00:01:21.14 bitrate=N/A
frame= 2401 fps= 31 q=0.0 size=N/A time=00:01:21.67 bitrate=N/A
frame= 2416 fps= 31 q=0.0 size=N/A time=00:01:22.14 bitrate=N/A
frame= 2432 fps= 31 q=0.0 size=N/A time=00:01:22.65 bitrate=N/A
frame= 2446 fps= 31 q=0.0 size=N/A time=00:01:23.16 bitrate=N/A
frame= 2462 fps= 31 q=0.0 size=N/A time=00:01:23.70 bitrate=N/A
frame= 2477 fps= 31 q=0.0 size=N/A time=00:01:24.17 bitrate=N/A
frame= 2492 fps= 31 q=0.0 size=N/A time=00:01:24.70 bitrate=N/A
frame= 2507 fps= 31 q=0.0 size=N/A time=00:01:25.17 bitrate=N/A
frame= 2522 fps= 31 q=0.0 size=N/A time=00:01:25.70 bitrate=N/A
frame= 2537 fps= 31 q=0.0 size=N/A time=00:01:26.19 bitrate=N/A
frame= 2553 fps= 31 q=0.0 size=N/A time=00:01:26.73 bitrate=N/A
frame= 2568 fps= 31 q=0.0 size=N/A time=00:01:27.24 bitrate=N/A
frame= 2583 fps= 31 q=0.0 size=N/A time=00:01:27.73 bitrate=N/A
frame= 2599 fps= 31 q=0.0 size=N/A time=00:01:28.24 bitrate=N/A
frame= 2613 fps= 31 q=0.0 size=N/A time=00:01:28.73 bitrate=N/A
frame= 2628 fps= 31 q=0.0 size=N/A time=00:01:29.22 bitrate=N/A
frame= 2644 fps= 31 q=0.0 size=N/A time=00:01:29.76 bitrate=N/A
frame= 2658 fps= 31 q=0.0 size=N/A time=00:01:30.25 bitrate=N/A
frame= 2674 fps= 31 q=0.0 size=N/A time=00:01:30.78 bitrate=N/A
frame= 2691 fps= 31 q=0.0 size=N/A time=00:01:31.29 bitrate=N/A
frame= 2707 fps= 31 q=0.0 size=N/A time=00:01:31.82 bitrate=N/A
frame= 2722 fps= 31 q=0.0 size=N/A time=00:01:32.34 bitrate=N/A
frame= 2738 fps= 31 q=0.0 size=N/A time=00:01:32.87 bitrate=N/A
frame= 2753 fps= 31 q=0.0 size=N/A time=00:01:33.40 bitrate=N/A
frame= 2768 fps= 31 q=0.0 size=N/A time=00:01:33.89 bitrate=N/A
frame= 2780 fps= 31 q=0.0 size=N/A time=00:01:34.32 bitrate=N/A
frame= 2799 fps= 31 q=0.0 size=N/A time=00:01:34.92 bitrate=N/A
frame= 2813 fps= 31 q=0.0 size=N/A time=00:01:35.37 bitrate=N/A
frame= 2828 fps= 31 q=0.0 size=N/A time=00:01:35.90 bitrate=N/A
frame= 2843 fps= 31 q=0.0 size=N/A time=00:01:36.41 bitrate=N/A
frame= 2860 fps= 31 q=0.0 size=N/A time=00:01:36.99 bitrate=N/A
frame= 2874 fps= 31 q=0.0 size=N/A time=00:01:37.41 bitrate=N/A
frame= 2888 fps= 31 q=0.0 size=N/A time=00:01:37.93 bitrate=N/A
frame= 2904 fps= 31 q=0.0 size=N/A time=00:01:38.46 bitrate=N/A
frame= 2920 fps= 31 q=0.0 size=N/A time=00:01:39.01 bitrate=N/A
frame= 2935 fps= 31 q=0.0 size=N/A time=00:01:39.50 bitrate=N/A
frame= 2950 fps= 31 q=0.0 size=N/A time=00:01:40.02 bitrate=N/A
frame= 2966 fps= 31 q=0.0 size=N/A time=00:01:40.51 bitrate=N/A
frame= 2981 fps= 31 q=0.0 size=N/A time=00:01:41.00 bitrate=N/A
frame= 2996 fps= 31 q=0.0 size=N/A time=00:01:41.53 bitrate=N/A
frame= 3011 fps= 31 q=0.0 size=N/A time=00:01:42.04 bitrate=N/A
frame= 3026 fps= 31 q=0.0 size=N/A time=00:01:42.56 bitrate=N/A
frame= 3041 fps= 31 q=0.0 size=N/A time=00:01:43.07 bitrate=N/A
frame= 3056 fps= 31 q=0.0 size=N/A time=00:01:43.56 bitrate=N/A
[mpegts @ 0x9363960] DTS 2559798793 < 2562088580 out of order
[hevc @ 0x9443860] Could not find ref with POC 23
[hevc @ 0x9443860] Could not find ref with POC 22
frame= 3072 fps= 31 q=0.0 size=N/A time=00:01:44.09 bitrate=N/A
frame= 3087 fps= 31 q=0.0 size=N/A time=00:01:44.58 bitrate=N/A
frame= 3103 fps= 31 q=0.0 size=N/A time=00:01:45.14 bitrate=N/A
frame= 3117 fps= 31 q=0.0 size=N/A time=00:01:45.61 bitrate=N/A
frame= 3134 fps= 31 q=0.0 size=N/A time=00:01:46.12 bitrate=N/A
frame= 3149 fps= 31 q=0.0 size=N/A time=00:01:46.63 bitrate=N/A
frame= 3164 fps= 31 q=0.0 size=N/A time=00:01:47.16 bitrate=N/A
frame= 3178 fps= 31 q=0.0 size=N/A time=00:01:47.61 bitrate=N/A
frame= 3195 fps= 31 q=0.0 size=N/A time=00:01:48.14 bitrate=N/A
frame= 3209 fps= 31 q=0.0 size=N/A time=00:01:48.66 bitrate=N/A
frame= 3225 fps= 31 q=0.0 size=N/A time=00:01:49.19 bitrate=N/A
frame= 3240 fps= 31 q=0.0 size=N/A time=00:01:49.66 bitrate=N/A
frame= 3255 fps= 31 q=0.0 size=N/A time=00:01:50.19 bitrate=N/A
frame= 3270 fps= 31 q=0.0 size=N/A time=00:01:50.66 bitrate=N/A
frame= 3285 fps= 31 q=0.0 size=N/A time=00:01:51.20 bitrate=N/A
frame= 3300 fps= 31 q=0.0 size=N/A time=00:01:51.69 bitrate=N/A
frame= 3315 fps= 31 q=0.0 size=N/A time=00:01:52.20 bitrate=N/A
frame= 3330 fps= 31 q=0.0 size=N/A time=00:01:52.71 bitrate=N/A
frame= 3346 fps= 31 q=0.0 size=N/A time=00:01:53.20 bitrate=N/A
frame= 3361 fps= 31 q=0.0 size=N/A time=00:01:53.73 bitrate=N/A
frame= 3375 fps= 31 q=0.0 size=N/A time=00:01:54.20 bitrate=N/A
frame= 3391 fps= 31 q=0.0 size=N/A time=00:01:54.72 bitrate=N/A
frame= 3407 fps= 31 q=0.0 size=N/A time=00:01:55.25 bitrate=N/A
frame= 3421 fps= 31 q=0.0 size=N/A time=00:01:55.74 bitrate=N/A
frame= 3437 fps= 31 q=0.0 size=N/A time=00:01:56.27 bitrate=N/A
frame= 3454 fps= 31 q=0.0 size=N/A time=00:01:56.78 bitrate=N/A
frame= 3470 fps= 31 q=0.0 size=N/A time=00:01:57.32 bitrate=N/A
frame= 3485 fps= 31 q=0.0 size=N/A time=00:01:57.83 bitrate=N/A
frame= 3501 fps= 31 q=0.0 size=N/A time=00:01:58.36 bitrate=N/A
frame= 3516 fps= 31 q=0.0 size=N/A time=00:01:58.90 bitrate=N/A
frame= 3531 fps= 31 q=0.0 size=N/A time=00:01:59.39 bitrate=N/A
frame= 3543 fps= 31 q=0.0 size=N/A time=00:01:59.81 bitrate=N/A
frame= 3562 fps= 31 q=0.0 size=N/A time=00:02:00.41 bitrate=N/A
frame= 3576 fps= 31 q=0.0 size=N/A time=00:02:00.86 bitrate=N/A
frame= 3591 fps= 31 q=0.0 size=N/A time=00:02:01.39 bitrate=N/A
frame= 3606 fps= 31 q=0.0 size=N/A time=00:02:01.90 bitrate=N/A
frame= 3623 fps= 31 q=0.0 size=N/A time=00:02:02.48 bitrate=N/A
frame= 3637 fps= 31 q=0.0 size=N/A time=00:02:02.91 bitrate=N/A
frame= 3651 fps= 31 q=0.0 size=N/A time=00:02:03.42 bitrate=N/A
frame= 3667 fps= 31 q=0.0 size=N/A time=00:02:03.97 bitrate=N/A
frame= 3683 fps= 31 q=0.0 size=N/A time=00:02:04.51 bitrate=N/A
frame= 3698 fps= 31 q=0.0 size=N/A time=00:02:05.00 bitrate=N/A
frame= 3713 fps= 31 q=0.0 size=N/A time=00:02:05.51 bitrate=N/A
frame= 3729 fps= 31 q=0.0 size=N/A time=00:02:06.00 bitrate=N/A
frame= 3744 fps= 31 q=0.0 size=N/A time=00:02:06.49 bitrate=N/A
frame= 3759 fps= 31 q=0.0 size=N/A time=00:02:07.02 bitrate=N/A
frame= 3774 fps= 31 q=0.0 size=N/A time=00:02:07.54 bitrate=N/A
frame= 3789 fps= 31 q=0.0 size=N/A time=00:02:08.05 bitrate=N/A
frame= 3804 fps= 31 q=0.0 size=N/A time=00:02:08.56 bitrate=N/A
frame= 3819 fps= 31 q=0.0 size=N/A time=00:02:09.05 bitrate=N/A
[udp @ 0x93632c0] Circular buffer overrun. To avoid, increase fifo_size URL option. To survive in such case, use overrun_nonfatal option
Attachments (4)
Change History (15)
by , 11 years ago
| Attachment: | ffmpeg-hang-stack-trace.txt added |
|---|
comment:1 by , 11 years ago
I have uploaded a PCAP that can be used to reproduce the issue to ftp://upload.ffmpeg.org/incoming/ffmpeg-issue-4258.pcap . If you stream the PCAP in a loop, the decoder will eventually hang. It may hang right away, it may take 15-20 minutes to hang. Seems like a race condition of some kind. If you need me to change the IP addresses and/or the MAC addresses in the PCAP let me know. It is a single TS over UDP.
To reproduce the issue:
1) Use tcpreplay to stream the PCAP in a loop :
$ while true ; do \ sudo tcpreplay --preload-pcap -i eth0 ffmpeg-issue-4258.pcap ; \ done
2) Tune into the stream and start decoding it:
$ ffmpeg_g -vcodec hevc -threads 10 -thread_type slice -i udp://@239.36.13.100:4900 -f null /dev/null
comment:2 by , 11 years ago
| Keywords: | deadlock added |
|---|---|
| Priority: | normal → important |
Is this still reproducible?
Is it not possible to produce an input file that has the same effect?
comment:4 by , 11 years ago
This issue is fixed and can be closed. The decoder no longer deadlocks on this stream.
comment:6 by , 11 years ago
No idea. I recently retested when asked to do so, and the problem is resolved now. But no idea when it was fixed or how.
comment:7 by , 11 years ago
This issue is still happening. Minor bitstream corruption can cause the HEVC Decoder running Multi-Threaded slice type to deadlock. Observed on Linux using Pthreads.
The decoder deadlocks inside the call to avcodec_decode_video2() which never returns. All of the decoder threads are blocked in ff_thread_await_progress2().
It has been very hard to catch, but I have a mechanism to reproduce it now every time. On my system is will deadlock anywhere within 20 minutes to 5 or 6 hours. To reproduce the issue stream the TS file located at http://162.97.176.4/ffmpeg-issue-4258-test-case.ts (NOTE file is approx 300MB) via FFMPEG in a loop to UDP localhost and decode the stream in a second instance of FFMPEG. For instance:
$ while true ; do \
ffmpeg -re -i ./ffmpeg-issue-4258-test-case.ts \
-codec copy -f mpegts udp://127.0.0.1:12345 \
;done
Then decode the stream via:
$ ffmpeg_g -vcodec hevc -threads 12 -thread_type slice \ -i udp://:12345 -f null /dev/null
Here is a recent run where it deadlocked after almost 2 hours:
$ ./ffmpeg_g -vcodec hevc -threads 12 -thread_type slice \
-i udp://:12345 -f null /dev/null 2>&1 | tee run.log
ffmpeg version 2.8.git-VF Copyright (c) 2000-2015 the FFmpeg developers
built with gcc 5.2.0 (GCC)
configuration: --extra-version=VF --prefix=/mnt/centshare/ffmpeg/trunk/build/build-linux/stage --extra-cflags='-I/mnt/centshare/ffmpeg/trunk/build/../src/libavformat -I/mnt/centshare/ffmpeg/trunk/build/../src/libavcodec -I/usr/include/SDL -D_GNU_SOURCE=1 -D_REENTRANT -ggdb' --extra-ldflags='-L/mnt/centshare/ffmpeg/trunk/build/build-linux/stage/lib -Wl,-rpath -Wl,/mnt/centshare/ffmpeg/trunk/build/build-linux/stage/lib -I/usr/include/SDL -D_GNU_SOURCE=1 -D_REENTRANT -L/usr/lib -lSDL -lpthread' --enable-static --enable-avfilter --enable-pthreads --enable-zlib --enable-bzlib --enable-runtime-cpudetect --enable-hardcoded-tables
libavutil 55. 1.100 / 55. 1.100
libavcodec 57. 1.100 / 57. 1.100
libavformat 57. 0.100 / 57. 0.100
libavdevice 57. 0.100 / 57. 0.100
libavfilter 6. 1.100 / 6. 1.100
libswscale 4. 0.100 / 4. 0.100
libswresample 2. 0.100 / 2. 0.100
Input #0, mpegts, from 'udp://:12345':
Duration: N/A, start: 1.400000, bitrate: N/A
Program 1
Metadata:
service_name : Service01
service_provider: FFmpeg
Stream #0:0[0x100]: Video: hevc (Main) ([36][0][0][0] / 0x0024), yuv420p(tv), 960x1080 [SAR 2:1 DAR 16:9], 29.97 fps, 29.97 tbr, 90k tbn, 29.97 tbc
Stream #0:1[0x101]: Audio: aac (LC) ([15][0][0][0] / 0x000F), 48000 Hz, stereo, fltp, 123 kb/s
Output #0, null, to '/dev/null':
Metadata:
encoder : Lavf57.0.100
Stream #0:0: Video: rawvideo (I420 / 0x30323449), yuv420p, 960x1080 [SAR 2:1 DAR 16:9], q=2-31, 200 kb/s, 29.97 fps, 29.97 tbn, 29.97 tbc
Metadata:
encoder : Lavc57.1.100 rawvideo
Stream #0:1: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s
Metadata:
encoder : Lavc57.1.100 pcm_s16le
Stream mapping:
Stream #0:0 -> #0:0 (hevc (native) -> rawvideo (native))
Stream #0:1 -> #0:1 (aac (native) -> pcm_s16le (native))
Press [q] to stop, [?] for help
frame= 107 fps=0.0 q=-0.0 size=N/A time=00:00:03.87 bitrate=N/A
frame= 180 fps=178 q=-0.0 size=N/A time=00:00:06.30 bitrate=N/A
frame= 195 fps=128 q=-0.0 size=N/A time=00:00:06.80 bitrate=N/A
frame= 213 fps=103 q=-0.0 size=N/A time=00:00:07.40 bitrate=N/A
frame= 229 fps= 88 q=-0.0 size=N/A time=00:00:07.94 bitrate=N/A
...
<SNIP>
...
frame=193019 fps= 30 q=-0.0 size=N/A time=01:47:22.26 bitrate=N/A
frame=193034 fps= 30 q=-0.0 size=N/A time=01:47:22.76 bitrate=N/A
frame=193053 fps= 30 q=-0.0 size=N/A time=01:47:23.40 bitrate=N/A
frame=193068 fps= 30 q=-0.0 size=N/A time=01:47:23.90 bitrate=N/A
[udp @ 0x37d2de0] Circular buffer overrun. To avoid, increase fifo_size URL option. To survive in such case, use overrun_nonfatal option
comment:8 by , 11 years ago
I have a second method to reproduce the issue very quickly. Usually less than a minute. This method involves streaming a sufficiently corrupted stream to FFMPEG to make it deadlock much faster in the same way. Note, the file itself is not really corrupt. It is a network packet capture of an HEVC transport stream that i feed to FFMPEG as input. FFMPEG is fooled enough to detect it as an HEVC file and then stream it to the decoder. The file is located at http://162.97.176.4/ffmpeg-issue-4258-test-case2-short-garbage.dat . This file is much smaller <20MB. You can perform the same test as above with this file:
$ while true ; do \
ffmpeg -re -i ./ffmpeg-issue-4258-test-case2-short-garbage.dat \
-codec copy -f mpegts udp://127.0.0.1:12345 \
; done
Then decode the stream via:
$ ffmpeg_g -vcodec hevc -threads 12 -thread_type slice \ -i udp://:12345 -f null /dev/null
by , 11 years ago
| Attachment: | ffmpeg-issue-4258-test-case2-short-garbage_cut.dat added |
|---|
comment:9 by , 11 years ago
| Reproduced by developer: | set |
|---|---|
| Status: | new → open |
comment:10 by , 11 years ago
| Keywords: | regression added |
|---|
Regression since 0c8aba3842a718eb9139fc88b7b60dc79e127bd7
(gdb) r -thread_type slice -threads 2 -i ffmpeg-issue-4258-test-case2-short-garbage_cut.dat -f null -
Starting program: ffmpeg_g -thread_type slice -threads 2 -i ffmpeg-issue-4258-test-case2-short-garbage_cut.dat -f null -
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
ffmpeg version N-75185-gf58e011 Copyright (c) 2000-2015 the FFmpeg developers
built with gcc 4.7 (SUSE Linux)
configuration: --enable-gpl
libavutil 55. 2.100 / 55. 2.100
libavcodec 57. 1.100 / 57. 1.100
libavformat 57. 0.100 / 57. 0.100
libavdevice 57. 0.100 / 57. 0.100
libavfilter 6. 1.100 / 6. 1.100
libswscale 4. 0.100 / 4. 0.100
libswresample 2. 0.100 / 2. 0.100
libpostproc 54. 0.100 / 54. 0.100
[hevc @ 0x1c62380] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x1c62380] Error parsing NAL unit #2.
[hevc @ 0x1c62380] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x1c62380] Error parsing NAL unit #2.
[hevc @ 0x1c62380] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x1c62380] Error parsing NAL unit #2.
[hevc @ 0x1c62380] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x1c62380] Error parsing NAL unit #2.
[hevc @ 0x1c62380] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x1c62380] Error parsing NAL unit #2.
[hevc @ 0x1c62380] PPS id out of range: 0
Last message repeated 1 times
[hevc @ 0x1c62380] Error parsing NAL unit #2.
Input #0, mpegts, from 'ffmpeg-issue-4258-test-case2-short-garbage_cut.dat':
Duration: 00:00:16.18, start: 28442.208811, bitrate: 1265 kb/s
Program 1
Metadata:
service_name : Haivision Network Video Media Server
service_provider: Haivision Network Video http://www.haivision.com
Stream #0:0[0x100]: Audio: aac (LC) ([15][0][0][0] / 0x000F), 48000 Hz, stereo, fltp, 124 kb/s
Stream #0:1[0x21]: Video: hevc (Main) ([36][0][0][0] / 0x0024), yuv420p(tv), 1280x720 [SAR 1:1 DAR 16:9], 29.97 fps, 29.97 tbr, 90k tbn, 29.97 tbc
[New Thread 0x7ffff14f0700 (LWP 24078)]
[New Thread 0x7ffff0cef700 (LWP 24079)]
[New Thread 0x7ffff04ee700 (LWP 24080)]
[New Thread 0x7fffefced700 (LWP 24081)]
[New Thread 0x7fffef4ec700 (LWP 24082)]
[New Thread 0x7fffeeceb700 (LWP 24083)]
[New Thread 0x7fffee4ea700 (LWP 24084)]
[New Thread 0x7fffedce9700 (LWP 24085)]
[New Thread 0x7fffed4e8700 (LWP 24086)]
[New Thread 0x7fffecce7700 (LWP 24087)]
[New Thread 0x7fffec4e6700 (LWP 24088)]
[New Thread 0x7fffebce5700 (LWP 24089)]
[New Thread 0x7fffeb4e4700 (LWP 24090)]
[New Thread 0x7fffeace3700 (LWP 24091)]
[New Thread 0x7fffea4e2700 (LWP 24092)]
[New Thread 0x7fffe9ce1700 (LWP 24093)]
[New Thread 0x7fffe94e0700 (LWP 24094)]
[New Thread 0x7fffe8cdf700 (LWP 24095)]
[New Thread 0x7fffe84de700 (LWP 24096)]
[New Thread 0x7fffe7cdd700 (LWP 24097)]
Output #0, null, to 'pipe:':
Metadata:
encoder : Lavf57.0.100
Stream #0:0: Video: rawvideo (I420 / 0x30323449), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], q=2-31, 200 kb/s, 29.97 fps, 29.97 tbn, 29.97 tbc
Metadata:
encoder : Lavc57.1.100 rawvideo
Stream #0:1: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s
Metadata:
encoder : Lavc57.1.100 pcm_s16le
Stream mapping:
Stream #0:1 -> #0:0 (hevc (native) -> rawvideo (native))
Stream #0:0 -> #0:1 (aac (native) -> pcm_s16le (native))
Press [q] to stop, [?] for help
[hevc @ 0x1c65520] Could not find ref with POC 23
[hevc @ 0x1c65520] Could not find ref with POC 22
[null @ 0x1c659c0] Encoder did not produce proper pts, making some up.
[hevc @ 0x1c65520] The cu_qp_delta 47 is outside the valid range [-26, 25].
Program received signal SIGINT, Interrupt.
0x00007ffff62728f4 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
(gdb) bt
#0 0x00007ffff62728f4 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x0000000000a4b803 in thread_park_workers (thread_count=2, c=0x1e20f00)
at libavcodec/pthread_slice.c:142
#2 thread_execute (avctx=<optimized out>, func=<optimized out>, arg=<optimized out>,
ret=<optimized out>, job_count=<optimized out>, job_size=<optimized out>)
at libavcodec/pthread_slice.c:174
#3 0x00000000008b978b in hls_slice_data_wpp (nal=<optimized out>, s=0x1c9fc00)
at libavcodec/hevc.c:2510
#4 decode_nal_unit (nal=<optimized out>, s=0x1c9fc00) at libavcodec/hevc.c:2734
#5 decode_nal_units (s=s@entry=0x1c9fc00, buf=<optimized out>, length=<optimized out>)
at libavcodec/hevc.c:2793
#6 0x00000000008b9927 in hevc_decode_frame (avctx=0x1c65520, data=0x1dff6e0,
got_output=0x7fffffffd7cc, avpkt=0x7fffffffd530) at libavcodec/hevc.c:2897
#7 0x0000000000b35d38 in avcodec_decode_video2 (avctx=0x1c65520,
picture=picture@entry=0x1dff6e0, got_picture_ptr=got_picture_ptr@entry=0x7fffffffd7cc,
avpkt=avpkt@entry=0x7fffffffda80) at libavcodec/utils.c:2096
#8 0x000000000048fffd in decode_video (ist=ist@entry=0x1c65240,
pkt=pkt@entry=0x7fffffffda80, got_output=got_output@entry=0x7fffffffd7cc)
at ffmpeg.c:2070
#9 0x00000000004931c1 in process_input_packet (pkt=0x7fffffffda30, ist=0x1c65240)
at ffmpeg.c:2327
#10 process_input (file_index=234234) at ffmpeg.c:3834
#11 transcode_step () at ffmpeg.c:3922
#12 transcode () at ffmpeg.c:3975
#13 0x0000000000475cfb in main (argc=<optimized out>, argv=0x7fffffffdcc8) at ffmpeg.c:4158
comment:11 by , 11 years ago
| Resolution: | → fixed |
|---|---|
| Status: | open → closed |
Fixed in 74e4948235bc8f8946eeca20525258bbf383f75d.
Note:
See TracTickets
for help on using tickets.
Stack Trace for the FFMPEG Hang