#5800 closed defect (fixed)
ffmpeg-git: Slow Start Transcode vs ffmpeg-2.8.7: Fast Start Transcode
Reported by: | barhom | Owned by: | |
---|---|---|---|
Priority: | important | Component: | avformat |
Version: | git-master | Keywords: | regression probe |
Cc: | Blocked By: | ||
Blocking: | Reproduced by developer: | yes | |
Analyzed by developer: | no |
Description
The Problem:
In ffmpeg 2.8.7 we have noticed that there are a couple of videos that start up really quickly whilst when we tried 3.0.2, 3.1.2 and git the startup time for the transcode is incredibly slow.
Try the command below to understand the issue in ffmpeg 2.8.7 and >3.0.2 or git.
This command:
ffmpeg -analyzeduration 1000000 -i http://www.netsat.se/channel.ts \ -map 0:0 -map 0:1 -c:v libx264 -preset superfast -g 25 -b:v 900k \ -maxrate 900k -bufsize 2000k -filter:v yadif -c:a libfdk_aac -b:a 64k \ -f mpegts -metadata chan_id=300 -metadata timeshift=0 \ "udp://239.240.127.64:3301?buffer_size=1316&pkt_size=1316" -loglevel 48
In FFmpeg-git this transcode-command starts in about 5 seconds.
In FFmpeg-2.8.7 this transcode-command starts in about 1 second.
Logs:
ffmpeg-git (5s start time because of all the "probing stream 1 pp:")
ffmpeg -analyzeduration 1000000 -i http://www.netsat.se/channel.ts -map 0:0 -map 0:1 -c:v libx264 -preset superfast -g 25 -b:v 900k -maxrate 900k -bufsize 2000k -filter:v yadif -c:a libfdk_aac -b:a 64k -f mpegts -metadata chan_id=300 -metadata timeshift=0 "udp://239.240.127.64:3301?buffer_size=1316&pkt_size=1316" -loglevel 48 ffmpeg version N-80789-gc5566f0 Copyright (c) 2000-2016 the FFmpeg developers built with gcc 4.9.2 (Debian 4.9.2-10) configuration: --prefix=/home/company/company_packages/ffmpeg_build --pkg-config-flags=--static --extra-cflags=-I/home/company/company_packages/ffmpeg_build/include --extra-ldflags=-L/home/company/company_packages/ffmpeg_build/lib --bindir=/home/company/company_packages/bin --enable-gpl --enable-libass --enable-libfdk-aac --enable-libfreetype --enable-libmp3lame --enable-libtheora --enable-libvorbis --enable-libx264 --enable-libx265 --enable-nonfree --enable-libzvbi libavutil 55. 27.100 / 55. 27.100 libavcodec 57. 48.101 / 57. 48.101 libavformat 57. 40.101 / 57. 40.101 libavdevice 57. 0.102 / 57. 0.102 libavfilter 6. 46.102 / 6. 46.102 libswscale 4. 1.100 / 4. 1.100 libswresample 2. 1.100 / 2. 1.100 libpostproc 54. 0.100 / 54. 0.100 Splitting the commandline. Reading option '-analyzeduration' ... matched as AVOption 'analyzeduration' with argument '1000000'. Reading option '-i' ... matched as input file with argument 'http://www.netsat.se/channel.ts'. Reading option '-map' ... matched as option 'map' (set input stream mapping) with argument '0:0'. Reading option '-map' ... matched as option 'map' (set input stream mapping) with argument '0:1'. Reading option '-c:v' ... matched as option 'c' (codec name) with argument 'libx264'. Reading option '-preset' ... matched as AVOption 'preset' with argument 'superfast'. Reading option '-g' ... matched as AVOption 'g' with argument '25'. Reading option '-b:v' ... matched as option 'b' (video bitrate (please use -b:v)) with argument '900k'. Reading option '-maxrate' ... matched as AVOption 'maxrate' with argument '900k'. Reading option '-bufsize' ... matched as AVOption 'bufsize' with argument '2000k'. Reading option '-filter:v' ... matched as option 'filter' (set stream filtergraph) with argument 'yadif'. Reading option '-c:a' ... matched as option 'c' (codec name) with argument 'libfdk_aac'. Reading option '-b:a' ... matched as option 'b' (video bitrate (please use -b:v)) with argument '64k'. Reading option '-f' ... matched as option 'f' (force format) with argument 'mpegts'. Reading option '-metadata' ... matched as option 'metadata' (add metadata) with argument 'chan_id=300'. Reading option '-metadata' ... matched as option 'metadata' (add metadata) with argument 'timeshift=0'. Reading option 'udp://239.240.127.64:3301?buffer_size=1316&pkt_size=1316' ... matched as output file. Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '48'. Finished splitting the commandline. Parsing a group of options: global . Applying option loglevel (set logging level) with argument 48. Successfully parsed a group of options. Parsing a group of options: input file http://www.netsat.se/channel.ts. Successfully parsed a group of options. Opening an input file: http://www.netsat.se/channel.ts. [http @ 0x3f2ce60] Setting default whitelist 'http,https,tls,rtp,tcp,udp,crypto,httpproxy' [http @ 0x3f2ce60] request: GET /channel.ts HTTP/1.1 User-Agent: Lavf/57.40.101 Accept: */* Range: bytes=0- Connection: close Host: www.netsat.se Icy-MetaData: 1 [mpegts @ 0x3f2c7a0] Format mpegts probed with size=2048 and score=50 [mpegts @ 0x3f2c7a0] stream=0 stream_type=2 pid=83f prog_reg_desc= [mpegts @ 0x3f2c7a0] stream=1 stream_type=4 pid=8a3 prog_reg_desc= [mpegts @ 0x3f2c7a0] Before avformat_find_stream_info() pos: 0 bytes read:49026 seeks:0 nb_streams:2 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2500 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2499 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2498 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2497 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2496 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2495 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2494 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2493 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2492 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2491 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2490 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2489 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2488 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2487 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2486 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2485 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2484 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2483 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2482 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2481 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2480 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2479 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2478 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2477 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2476 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2475 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2474 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2473 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2472 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2471 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2470 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2469 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2468 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2467 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2466 [mpegts @ 0x3f2c7a0] probing stream 1 pp:2465 [mpegts @ 0x3f2c7a0] Probe with size=102480, packets=2500 detected mp3 with score=50 [mpegts @ 0x3f2c7a0] probed stream 1 [mp2 @ 0x3f3d9e0] Header missing [mpegts @ 0x3f2c7a0] max_analyze_duration 1000000 reached at 1008000 microseconds st:1 [mpegts @ 0x3f2c7a0] After avformat_find_stream_info() pos: 2787288 bytes read:2789244 seeks:0 frames:67 Input #0, mpegts, from 'http://www.netsat.se/channel.ts': Duration: N/A, start: 22346.331678, bitrate: N/A Program 1811 Metadata: service_name : Syrian Drama TV service_provider: JMC Stream #0:0[0x83f], 23, 1/90000: Video: mpeg2video (Main), 1 reference frame ([2][0][0][0] / 0x0002), yuv420p(tv, left), 720x576 [SAR 16:15 DAR 4:3], 0/1, 25 fps, 25 tbr, 90k tbn, 50 tbc Stream #0:1[0x8a3](ara), 44, 1/90000: Audio: mp2 ([4][0][0][0] / 0x0004), 48000 Hz, stereo, s16p, 160 kb/s
vs
ffmpeg-2.8.7 (1s start time - I dont see any "probing stream 1 pp:")
ffmpeg -analyzeduration 1000000 -i http://www.netsat.se/channel.ts -map 0:0 -map 0:1 -c:v libx264 -preset superfast -g 25 -b:v 900k -maxrate 900k -bufsize 2000k -filter:v yadif -c:a libfdk_aac -b:a 64k -f mpegts -metadata chan_id=300 -metadata timeshift=0 "udp://239.240.127.64:3301?buffer_size=1316&pkt_size=1316" -loglevel 48 ffmpeg version 2.8.7 Copyright (c) 2000-2016 the FFmpeg developers built with gcc 4.9.2 (Debian 4.9.2-10) configuration: --prefix=/home/company/company_packages/ffmpeg_build --pkg-config-flags=--static --extra-cflags=-I/home/company/company_packages/ffmpeg_build/include --extra-ldflags=-L/home/company/company_packages/ffmpeg_build/lib --bindir=/home/company/company_packages/bin --enable-gpl --enable-libass --enable-libfdk-aac --enable-libfreetype --enable-libmp3lame --enable-libtheora --enable-libvorbis --enable-libx264 --enable-libx265 --enable-nonfree --enable-libzvbi libavutil 54. 31.100 / 54. 31.100 libavcodec 56. 60.100 / 56. 60.100 libavformat 56. 40.101 / 56. 40.101 libavdevice 56. 4.100 / 56. 4.100 libavfilter 5. 40.101 / 5. 40.101 libswscale 3. 1.101 / 3. 1.101 libswresample 1. 2.101 / 1. 2.101 libpostproc 53. 3.100 / 53. 3.100 Splitting the commandline. Reading option '-analyzeduration' ... matched as AVOption 'analyzeduration' with argument '1000000'. Reading option '-i' ... matched as input file with argument 'http://www.netsat.se/channel.ts'. Reading option '-map' ... matched as option 'map' (set input stream mapping) with argument '0:0'. Reading option '-map' ... matched as option 'map' (set input stream mapping) with argument '0:1'. Reading option '-c:v' ... matched as option 'c' (codec name) with argument 'libx264'. Reading option '-preset' ... matched as AVOption 'preset' with argument 'superfast'. Reading option '-g' ... matched as AVOption 'g' with argument '25'. Reading option '-b:v' ... matched as option 'b' (video bitrate (please use -b:v)) with argument '900k'. Reading option '-maxrate' ... matched as AVOption 'maxrate' with argument '900k'. Reading option '-bufsize' ... matched as AVOption 'bufsize' with argument '2000k'. Reading option '-filter:v' ... matched as option 'filter' (set stream filtergraph) with argument 'yadif'. Reading option '-c:a' ... matched as option 'c' (codec name) with argument 'libfdk_aac'. Reading option '-b:a' ... matched as option 'b' (video bitrate (please use -b:v)) with argument '64k'. Reading option '-f' ... matched as option 'f' (force format) with argument 'mpegts'. Reading option '-metadata' ... matched as option 'metadata' (add metadata) with argument 'chan_id=300'. Reading option '-metadata' ... matched as option 'metadata' (add metadata) with argument 'timeshift=0'. Reading option 'udp://239.240.127.64:3301?buffer_size=1316&pkt_size=1316' ... matched as output file. Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '48'. Finished splitting the commandline. Parsing a group of options: global . Applying option loglevel (set logging level) with argument 48. Successfully parsed a group of options. Parsing a group of options: input file http://www.netsat.se/channel.ts. Successfully parsed a group of options. Opening an input file: http://www.netsat.se/channel.ts. [http @ 0x3fcd0e0] request: GET /channel.ts HTTP/1.1 User-Agent: Lavf/56.40.101 Accept: */* Range: bytes=0- Connection: close Host: www.netsat.se Icy-MetaData: 1 [mpegts @ 0x3fcc7a0] Format mpegts probed with size=2048 and score=100 [mpegts @ 0x3fcc7a0] stream=0 stream_type=2 pid=83f prog_reg_desc= [mpegts @ 0x3fcc7a0] stream=1 stream_type=4 pid=8a3 prog_reg_desc= [mpegts @ 0x3fcc7a0] Before avformat_find_stream_info() pos: 0 bytes read:109508 seeks:0 [mp3 @ 0x3fdcb40] Header missing [mpegts @ 0x3fcc7a0] max_analyze_duration 1000000 reached at 1008000 microseconds st:1 [mpegts @ 0x3fcc7a0] After avformat_find_stream_info() pos: 692404 bytes read:696186 seeks:0 frames:67 Input #0, mpegts, from 'http://www.netsat.se/channel.ts': Duration: N/A, start: 22572.219678, bitrate: N/A Program 1811 Metadata: service_name : Syrian Drama TV service_provider: JMC Stream #0:0[0x83f], 23, 1/90000: Video: mpeg2video (Main), 1 reference frame ([2][0][0][0] / 0x0002), yuv420p(tv, left), 720x576 [SAR 16:15 DAR 4:3], 1/50, max. 15000 kb/s, 25 fps, 25 tbr, 90k tbn, 50 tbc Stream #0:1[0x8a3](ara), 44, 1/90000: Audio: mp2 ([4][0][0][0] / 0x0004), 48000 Hz, stereo, s16p, 160 kb/s
(Side note: I know the logs above show ffmpeg "N-80789-gc5566f0" which is not latest git - but I have tried this on latest git as well so we know the issue is there)
Does anyone know why this command is slow-starting in ffmpeg newer than 2.8.7 ?
Thanks
Change History (6)
comment:1 by , 8 years ago
Version: | unspecified → git-master |
---|
follow-up: 3 comment:2 by , 8 years ago
comment:3 by , 8 years ago
Replying to cehoyos:
Which commit introduced the issue you see?
I am not sure, it must be somewhere between 2.8.7 (Feynman) and 3.0.2 (Einstein).
I can try to hunt it down.
comment:4 by , 8 years ago
I have found the regression.
It was introduced by the following commit:
https://github.com/FFmpeg/FFmpeg/commit/4bec36f98c5150b09d45740f3e1c80526e85b676
Removing the lines
if (pes->stream_type == 4) st->request_probe = 50;
from master fixes the problem I have with slow-starting transcodes. I suggest that if ffmpeg wants an extra probe for stream_type == 4 then it should make it optional somehow.
comment:5 by , 8 years ago
Reproduced by developer: | set |
---|---|
Resolution: | → fixed |
Status: | new → closed |
comment:6 by , 8 years ago
Component: | undetermined → avformat |
---|---|
Keywords: | regression probe added |
Priority: | normal → important |
Which commit introduced the issue you see?