[FFmpeg-trac] #10303(undetermined:new): https a lot of reconnects/206 requests with particular files

FFmpeg trac at avcodec.org
Mon Apr 3 12:10:57 EEST 2023


#10303: https a lot of reconnects/206 requests with particular files
-------------------------------------+-------------------------------------
             Reporter:  maclin       |                     Type:  defect
               Status:  new          |                 Priority:  normal
            Component:               |                  Version:
  undetermined                       |  unspecified
             Keywords:               |               Blocked By:
             Blocking:               |  Reproduced by developer:  0
Analyzed by developer:  0            |
-------------------------------------+-------------------------------------
 Summary of the bug:
 How to reproduce:
 {{{

 ffmpeg version 4.2.8 Copyright (c) 2000-2022 the FFmpeg developers
 built with gcc 9 (Ubuntu 9.4.0-1ubuntu1~20.04.1)
 configuration: --disable-debug --disable-doc --disable-ffplay --enable-
 avresample --enable-cuda --enable-cuvid --enable-fontconfig --enable-gpl
 --enable-libaom --enable-libaribb24 --enable-libass --enable-libbluray
 --enable-libfdk_aac --enable-libfreetype --enable-libkvazaar --enable-
 libmp3lame --enable-libnpp --enable-libopencore-amrnb --enable-
 libopencore-amrwb --enable-libopenjpeg --enable-libopus --enable-libsrt
 --enable-libtheora --enable-libvidstab --enable-libvorbis --enable-libvpx
 --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxcb
 --enable-libxvid --enable-libzmq --enable-nonfree --enable-nvenc --enable-
 openssl --enable-postproc --enable-shared --enable-small --enable-version3
 --extra-cflags='-I/opt/ffmpeg/include -I/opt/ffmpeg/include/ffnvcodec
 -I/usr/local/cuda/include/' --extra-ldflags='-L/opt/ffmpeg/lib
 -L/usr/local/cuda/lib64 -L/usr/local/cuda/lib32/' --extra-libs=-ldl
 --extra-libs=-lpthread --prefix=/opt/ffmpeg
 libavutil      56. 31.100 / 56. 31.100
 libavcodec     58. 54.100 / 58. 54.100
 libavformat    58. 29.100 / 58. 29.100
 libavdevice    58.  8.100 / 58.  8.100
 libavfilter     7. 57.100 /  7. 57.100
 libavresample   4.  0.  0 /  4.  0.  0
 libswscale      5.  5.100 /  5.  5.100
 libswresample   3.  5.100 /  3.  5.100
 libpostproc    55.  5.100 / 55.  5.100


 ffmpeg -v verbose -xerror -progress progressbar_1_pass1_350 -reconnect 1
 -reconnect_delay_max 60 -timeout 60000 -i
 https://storage.local/input/2023-03-31-20-26-17.mxf -an -pass 1
 -passlogfile passlog_1 -threads 0 -codec:v libx264 -b:v 350k -flags
 +loop+mv4 -cmp 256 -partitions
 +parti4x4+parti8x8+partp4x4+partp8x8+partb8x8 -me_method hex -subq 7
 -trellis 1 -refs 5 -bf 3 -x264opts
 b-pyramid=normal:weightb:mixed_refs:8x8dct -coder 1 -me_range 16 -g 25
 -keyint_min 25 -r 25 -sc_threshold 0 -i_qfactor 0.71 -qmin 0 -qmax 40
 -qdiff 4 -s 640x360 -aspect 16:9 -pix_fmt yuv420p -movflags +faststart -f
 rawvideo -y /dev/null
 }}}

 On output i see this (small part of it):

 {{{
 [tcp @ 0x56217ca91180] Starting connection attempt to 10.100.0.90 port 443
 [tcp @ 0x56217ca91180] Successfully connected to 10.100.0.90 port 443
 [tcp @ 0x56217ca009c0] Starting connection attempt to 10.100.0.90 port 443
 [tcp @ 0x56217ca009c0] Successfully connected to 10.100.0.90 port 443
 [tcp @ 0x56217cfbd0c0] Starting connection attempt to 10.100.0.90 port 443
 [tcp @ 0x56217cfbd0c0] Successfully connected to 10.100.0.90 port 443
 [tcp @ 0x56217ca8c300] Starting connection attempt to 10.100.0.90 port 443
 [tcp @ 0x56217ca8c300] Successfully connected to 10.100.0.90 port 443
 [tcp @ 0x56217c9eeb00] Starting connection attempt to 10.100.0.90 port 443
 [tcp @ 0x56217c9eeb00] Successfully connected to 10.100.0.90 port 443
 [tcp @ 0x56217ca00cc0] Starting connection attempt to 10.100.0.90 port 443
 [tcp @ 0x56217ca00cc0] Successfully connected to 10.100.0.90 port 443
 [tcp @ 0x56217ca944c0] Starting connection attempt to 10.100.0.90 port 443
 [tcp @ 0x56217ca944c0] Successfully connected to 10.100.0.90 port 443
 }}}

 And on nginx logs i see this (small part of it):

 {{{
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 4 "-" "Lavf/58.29.100" "-"
 "LOCATION_NAME=" "REQ_TIME=0.000" "CONN_TIME=0.004"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 114362 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.010" "CONN_TIME=0.014"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 96 "-" "Lavf/58.29.100" "-"
 "LOCATION_NAME=" "REQ_TIME=0.000" "CONN_TIME=0.004"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 130746 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.010" "CONN_TIME=0.015"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1120 "-" "Lavf/58.29.100" "-"
 "LOCATION_NAME=" "REQ_TIME=0.000" "CONN_TIME=0.005"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 130742 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.009" "CONN_TIME=0.014"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 114356 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.010" "CONN_TIME=0.014"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 114355 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.010" "CONN_TIME=0.015"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 97971 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.010" "CONN_TIME=0.014"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 6782646 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.226" "CONN_TIME=0.231"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1425076 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.045" "CONN_TIME=0.048"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1392308 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.043" "CONN_TIME=0.047"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1408692 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.052" "CONN_TIME=0.056"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1425076 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.045" "CONN_TIME=0.049"
 10.100.0.91 - - [03/Apr/2023:07:58:10 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1425076 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.043" "CONN_TIME=0.047"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1425075 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.039" "CONN_TIME=0.043"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1408691 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.042" "CONN_TIME=0.045"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1441459 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.041" "CONN_TIME=0.044"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1425075 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.040" "CONN_TIME=0.043"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1392307 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.040" "CONN_TIME=0.044"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1408691 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.039" "CONN_TIME=0.043"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1425075 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.042" "CONN_TIME=0.045"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1752755 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.049" "CONN_TIME=0.053"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1392307 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.040" "CONN_TIME=0.044"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1408691 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.048" "CONN_TIME=0.052"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1719987 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.050" "CONN_TIME=0.053"
 10.100.0.91 - - [03/Apr/2023:07:58:11 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1425075 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.040" "CONN_TIME=0.044"
 }}}

 If i change input from http to https - then i see fast encoding (6x
 instead of 1-2x) and no reconnects.
 On nginx side i see last big 206 request

 {{{
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 4 "-" "Lavf/58.29.100" "-"
 "LOCATION_NAME=" "REQ_TIME=0.000" "CONN_TIME=0.000"
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 109722 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.006" "CONN_TIME=0.005"
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 96 "-" "Lavf/58.29.100" "-"
 "LOCATION_NAME=" "REQ_TIME=0.000" "CONN_TIME=0.000"
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 1120 "-" "Lavf/58.29.100" "-"
 "LOCATION_NAME=" "REQ_TIME=0.000" "CONN_TIME=0.000"
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 286378 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.006" "CONN_TIME=0.006"
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 109716 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.005" "CONN_TIME=0.005"
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 109715 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.004" "CONN_TIME=0.004"
 10.100.0.91 - - [03/Apr/2023:08:01:03 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 109715 "-" "Lavf/58.29.100"
 "-" "LOCATION_NAME=" "REQ_TIME=0.005" "CONN_TIME=0.005"
 10.100.0.91 - - [03/Apr/2023:08:01:08 +0000] "GET
 /input/2023-03-31-20-26-17.mxf HTTP/1.1" 206 193128032 "-"
 "Lavf/58.29.100" "-" "LOCATION_NAME=" "REQ_TIME=4.264" "CONN_TIME=4.264"
 }}}


 Nginx conf is here:
 {{{
 server{
     listen       10.100.0.90:443 ssl;
     listen       10.100.0.90:80 default_server;
     server_name   storage.local;
     ssl_certificate /etc/nginx/crt/local.crt;
     ssl_certificate_key /etc/nginx/crt/local.key;

     sendfile on;
     tcp_nodelay on;
     tcp_nopush on;
     directio 500m;
     keepalive_timeout 30;
     client_max_body_size 10G;

     open_file_cache off;

     location ~* ^/(input)\/.* {
         root /storage/;
         location ~* (mp4|mpeg|mpg|mxf|ts)$ {
         add_header Content-disposition "attachment";
         }
 }
 }}}

 File 2023-03-31-20-26-17.mxf example can be taken here:
 https://pixeldrain.com/u/2DqLPpAp
 https://disk.yandex.ru/d/DF5PoWO3qTPQIQ


 P.s. this behaviour with https is only with this kind of mxf file. If i
 change file for another mp4 file - it does not matter http or https, no
 reconnects and pretty speedy converting.

 P.p.s. ffmpeg and nginx are in dockers conatiners, im sure this is not an
 issue, just in case highlited it.
-- 
Ticket URL: <https://trac.ffmpeg.org/ticket/10303>
FFmpeg <https://ffmpeg.org>
FFmpeg issue tracker


More information about the FFmpeg-trac mailing list