Opened 4 months ago

Last modified 4 months ago

#7673 new defect

Fails to play long (30+ hours) hls playlist

Reported by: Jasdf923 Owned by:
Priority: normal Component: avformat
Version: git-master Keywords: hls
Cc: Blocked By:
Blocking: Reproduced by developer: no
Analyzed by developer: no

Description

Summary of the bug:
ffmpeg (ffplay) fails to play a long hls playlist. Trying to seek to somewhere after roughly after 27 hours does not work.

How to reproduce:
First, generate a long playlist. I am using the following command. It creates a lot of files totalling about 750MiB, so run it in a new directory.

ffmpeg -t 165600 -f lavfi -i color=c=black:s=2x2 -c:v libx264 -tune stillimage -pix_fmt yuv420p -hls_time 10 -hls_playlist_type vod playlist.m3u8

This is 46 hours of blank video split into 10 second segments.

ffmpeg -v 9 -loglevel 99 -i playlist.m3u8
ffmpeg version n4.1 Copyright (c) 2000-2018 the FFmpeg developers
  built with gcc 8.2.1 (GCC) 20180831
  configuration: --prefix=/usr --disable-debug --disable-static --disable-stripping --enable-fontconfig --enable-gmp --enable-gnutls --enable-gpl --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libdrm --enable-libfreetype --enable-libfribidi --enable-libgsm --enable-libiec61883 --enable-libjack --enable-libmodplug --enable-libmp3lame --enable-libopencore_amrnb --enable-libopencore_amrwb --enable-libopenjpeg --enable-libopus --enable-libpulse --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libv4l2 --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxcb --enable-libxml2 --enable-libxvid --enable-nvdec --enable-nvenc --enable-omx --enable-shared --enable-version3
  libavutil      56. 22.100 / 56. 22.100
  libavcodec     58. 35.100 / 58. 35.100
  libavformat    58. 20.100 / 58. 20.100
  libavdevice    58.  5.100 / 58.  5.100
  libavfilter     7. 40.101 /  7. 40.101
  libswscale      5.  3.100 /  5.  3.100
  libswresample   3.  3.100 /  3.  3.100
  libpostproc    55.  3.100 / 55.  3.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument '9'.
Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '99'.
Reading option '-i' ... matched as input url with argument 'playlist.m3u8'.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument 9.
Successfully parsed a group of options.
Parsing a group of options: input url playlist.m3u8.
Successfully parsed a group of options.
Opening an input file: playlist.m3u8.
[NULL @ 0x5610dd18edc0] Opening 'playlist.m3u8' for reading
[file @ 0x5610dd18f8c0] Setting default whitelist 'file,crypto'
Probing hls,applehttp score:100 size:2048
[hls,applehttp @ 0x5610dd18edc0] Format hls,applehttp probed with size=2048 and score=100
[hls,applehttp @ 0x5610dd18edc0] new_program: id=0x0000
[hls,applehttp @ 0x5610dd18edc0] HLS request for url 'playlist0.ts', offset 0, playlist 0
[hls,applehttp @ 0x5610dd18edc0] Opening 'playlist0.ts' for reading
Probing mpeg score:25 size:2048
Probing mpegts score:50 size:2048
Format mpegts probed with size=2048 and score=50
score: 44, dvhs_score: -2, fec_score: -2
[mpegts @ 0x5610dd4a6880] Filter: pid=0x11 type=1
[mpegts @ 0x5610dd4a6880] Filter: pid=0x0 type=1
[mpegts @ 0x5610dd4a6880] SDT:
[mpegts @ 0x5610dd4a6880] tag: 0x48 len=18
[mpegts @ 0x5610dd4a6880] new_program: id=0x0001
[mpegts @ 0x5610dd4a6880] PAT:
[mpegts @ 0x5610dd4a6880] sid=0x1 pid=0x1000
[mpegts @ 0x5610dd4a6880] new_program: id=0x0001
[mpegts @ 0x5610dd4a6880] Filter: pid=0x1000 type=1
[mpegts @ 0x5610dd4a6880] PMT: len 21
[mpegts @ 0x5610dd4a6880] sid=0x1 sec_num=0/0 version=0 tid=2
[mpegts @ 0x5610dd4a6880] pcr_pid=0x100
[mpegts @ 0x5610dd4a6880] Filter: pid=0x100 type=0
[mpegts @ 0x5610dd4a6880] stream=0 stream_type=1b pid=100 prog_reg_desc=
[mpegts @ 0x5610dd4a6880] tuning done
[hls,applehttp @ 0x5610dd18edc0] Before avformat_find_stream_info() pos: 585164 bytes read:585164 seeks:0 nb_streams:1
[mpegts @ 0x5610dd4a6880] Skipping after seek
[mpegts @ 0x5610dd4a6880] SDT:
[mpegts @ 0x5610dd4a6880] tag: 0x48 len=18
[mpegts @ 0x5610dd4a6880] new_program: id=0x0001
[mpegts @ 0x5610dd4a6880] PAT:
[mpegts @ 0x5610dd4a6880] sid=0x1 pid=0x1000
[mpegts @ 0x5610dd4a6880] new_program: id=0x0001
[mpegts @ 0x5610dd4a6880] PMT: len 21
[mpegts @ 0x5610dd4a6880] sid=0x1 sec_num=0/0 version=0 tid=2
[mpegts @ 0x5610dd4a6880] pcr_pid=0x100
[mpegts @ 0x5610dd4a6880] pid=100 pes_code=0x1e0
    Last message repeated 2 times
[AVBSFContext @ 0x5610dd4bf340] nal_unit_type: 9(AUD), nal_ref_idc: 0
[AVBSFContext @ 0x5610dd4bf340] nal_unit_type: 7(SPS), nal_ref_idc: 3
[AVBSFContext @ 0x5610dd4bf340] nal_unit_type: 8(PPS), nal_ref_idc: 3
[AVBSFContext @ 0x5610dd4bf340] nal_unit_type: 6(SEI), nal_ref_idc: 0
[AVBSFContext @ 0x5610dd4bf340] nal_unit_type: 5(IDR), nal_ref_idc: 3
[h264 @ 0x5610dd4bd300] nal_unit_type: 9(AUD), nal_ref_idc: 0
[h264 @ 0x5610dd4bd300] nal_unit_type: 7(SPS), nal_ref_idc: 3
[h264 @ 0x5610dd4bd300] nal_unit_type: 8(PPS), nal_ref_idc: 3
[h264 @ 0x5610dd4bd300] nal_unit_type: 6(SEI), nal_ref_idc: 0
[h264 @ 0x5610dd4bd300] nal_unit_type: 5(IDR), nal_ref_idc: 3
[h264 @ 0x5610dd4bd300] Format yuv420p chosen by get_format().
[h264 @ 0x5610dd4bd300] Reinit context to 16x16, pix_fmt: yuv420p
[h264 @ 0x5610dd4bd300] no picture
[mpegts @ 0x5610dd4a6880] pid=100 pes_code=0x1e0
    Last message repeated 126 times
[hls,applehttp @ 0x5610dd18edc0] max_analyze_duration 5000000 reached at 5000000 microseconds st:0
[hls,applehttp @ 0x5610dd18edc0] Setting avg frame rate based on r frame rate
[hls,applehttp @ 0x5610dd18edc0] stream 0: start_time: 1.480 duration: -102481911520608.625
[hls,applehttp @ 0x5610dd18edc0] format: start_time: 1.480 duration: 165600.000 bitrate=0 kb/s
[hls,applehttp @ 0x5610dd18edc0] After avformat_find_stream_info() pos: 585164 bytes read:585164 seeks:0 frames:127
Input #0, hls,applehttp, from 'playlist.m3u8':
  Duration: 46:00:00.00, start: 1.480000, bitrate: 0 kb/s
  Program 0
    Metadata:
      variant_bitrate : 0
    Stream #0:0, 127, 1/90000: Video: h264 (High), 1 reference frame ([27][0][0][0] / 0x001B), yuv420p(left), 2x2 (16x16) [SAR 1:1 DAR 1:1], 0/1, 25 fps, 25 tbr, 90k tbn, 50 tbc
    Metadata:
      variant_bitrate : 0
Successfully opened the file.
At least one output file must be specified
[AVIOContext @ 0x5610dd4b8040] Statistics: 32768 bytes read, 0 seeks
[AVIOContext @ 0x5610dd197d40] Statistics: 585164 bytes read, 0 seeks

Note that the log above was created with release version 4.1 but I have reproduced the same problem using the development version.

The error can be reproduced with:

ffplay playlist.m3u8

Then seek to somewhere later than 30 hours. Earlier than 25 hours works fine but I am do not know exactly at which time between 25 and 30 hours the problem starts to occur.
I use the right mouse button to seek in ffplay.
Here is an example log output

Seek to 31% (14:22:30) of total duration (46:00:00)       B f=0/0
[hls,applehttp @ 0x7fc81c000b80] Opening 'playlist5175.ts' for reading
[hls,applehttp @ 0x7fc81c000b80] Opening 'playlist5176.ts' for reading
Seek to 75% (34:34:18) of total duration (46:00:00)       0B f=0/0
[hls,applehttp @ 0x7fc81c000b80] Opening 'playlist12445.ts' for reading
[hls,applehttp @ 0x7fc81c000b80] Opening 'playlist12446.ts' for reading
[hls,applehttp @ 0x7fc81c000b80] Opening 'playlist12447.ts' for reading
...

The first seek works fine and the file plays correctly, after the second seek the console is filled with the above messages, showing all the individual segments in quick succession. The file no longer plays at all.
I can also reproduce this with the mpv media player which uses ffmpeg internally. This makes seeking a bit easier and it shows the same log messages.

mpv --no-config --msg-level=all=debug playlist.m3u8

Change History (2)

comment:1 Changed 4 months ago by cehoyos

  • Component changed from undetermined to avformat
  • Keywords m3u m3u8 playlist removed

There is a timestamp reset, I don't know if the behaviour can be changed.

$ ffplay -ss 26:30:30 playlist.m3u8
ffplay version N-92961-g90ab9a5 Copyright (c) 2003-2019 the FFmpeg developers
  built with gcc 6.4.0 (GCC)
  configuration: --enable-gpl --enable-libxml2 --enable-gnutls --enable-gmp --enable-version3 --enable-libx264
  libavutil      56. 25.100 / 56. 25.100
  libavcodec     58. 43.101 / 58. 43.101
  libavformat    58. 25.100 / 58. 25.100
  libavdevice    58.  6.101 / 58.  6.101
  libavfilter     7. 47.100 /  7. 47.100
  libswscale      5.  4.100 /  5.  4.100
  libswresample   3.  4.100 /  3.  4.100
  libpostproc    55.  4.100 / 55.  4.100
[hls,applehttp @ 0x7f9934000940] Opening 'playlist0.ts' for reading
Input #0, hls,applehttp, from 'playlist.m3u8':
  Duration: 46:00:00.00, start: 1.480000, bitrate: 0 kb/s
  Program 0
    Metadata:
      variant_bitrate : 0
    Stream #0:0: Video: h264 (High) ([27][0][0][0] / 0x001B), yuv420p, 2x2 [SAR 1:1 DAR 1:1], 25 fps, 25 tbr, 90k tbn, 50 tbc
    Metadata:
      variant_bitrate : 0
[hls,applehttp @ 0x7f9934000940] Opening 'playlist9543.ts' for reading
[hls,applehttp @ 0x7f9934000940] Opening 'playlist9544.ts' for reading
[mpegts @ 0x7f993419d8c0] Invalid timestamps stream=0, pts=208, dts=8589916800, size=25
[mpegts @ 0x7f993419d8c0] Invalid timestamps stream=0, pts=14608, dts=8589931200, size=25
   1.23 M-V: -0.000 fd=   0 aq=    0KB vq=    3KB sq=    0B f=1/2

(Pressed q after around three seconds.)

comment:2 Changed 4 months ago by tbucher

@cehoyos I did not consult the source code, so this a shot in the dark, but improper handling of timestamp rollover https://www.w3.org/TR/mse-byte-stream-format-mp2t/#mpeg2ts-discontinuities in TS stream jumped to mind first, however, when testing with fmp4 by adding -hls_segment_type fmp4 to the original command line, the issue occured as well.

Could HLS demuxer apply the same timestamp handling to fmp4, too, and thus both segment formats are somehow broken?

Note: See TracTickets for help on using tickets.