Opened 3 years ago

Closed 2 years ago

#4258 closed defect (fixed)

HEVC Decoder Hang in Multi-threaded Slice Type Decoding

Reported by: jlsantiago0 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)

ffmpeg-hang-stack-trace.txt (21.2 KB) - added by jlsantiago0 3 years ago.
Stack Trace for the FFMPEG Hang
ffplay-hang-stack-trace.txt (30.4 KB) - added by jlsantiago0 3 years ago.
Stack Trace for the FFPLAY Hang
backtrace-30009.txt (28.1 KB) - added by jlsantiago0 2 years ago.
Backtrace of the deadlock
ffmpeg-issue-4258-test-case2-short-garbage_cut.dat (2.4 MB) - added by cehoyos 2 years ago.

Change History (15)

Changed 3 years ago by jlsantiago0

Stack Trace for the FFMPEG Hang

Changed 3 years ago by jlsantiago0

Stack Trace for the FFPLAY Hang

comment:1 Changed 3 years ago by jlsantiago0

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
Last edited 3 years ago by jlsantiago0 (previous) (diff)

comment:2 Changed 2 years ago by cehoyos

  • Keywords deadlock added
  • Priority changed from normal to important

Is this still reproducible?
Is it not possible to produce an input file that has the same effect?

comment:3 Changed 2 years ago by jlsantiago0

Not sure. I will test this week with the latest development code.

comment:4 Changed 2 years ago by jlsantiago0

This issue is fixed and can be closed. The decoder no longer deadlocks on this stream.

comment:5 Changed 2 years ago by cehoyos

Which change fixed the issue?

comment:6 Changed 2 years ago by jlsantiago0

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.

Last edited 2 years ago by jlsantiago0 (previous) (diff)

comment:7 Changed 2 years ago by jlsantiago0

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
Last edited 2 years ago by jlsantiago0 (previous) (diff)

Changed 2 years ago by jlsantiago0

Backtrace of the deadlock

comment:8 Changed 2 years ago by jlsantiago0

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

comment:9 Changed 2 years ago by cehoyos

  • Reproduced by developer set
  • Status changed from new to open

comment:10 Changed 2 years ago by cehoyos

  • 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 Changed 2 years ago by rbultje

  • Resolution set to fixed
  • Status changed from open to closed
Note: See TracTickets for help on using tickets.