homebridge-plugins/homebridge-camera-ffmpeg

All frames dropped from ESP32-Cam

maciekish opened this issue · 3 comments

Describe The Problem:
Hi, I have just set up an ESP32-Cam, which works great in my browser, and snaphots work in HomeKit. But when i tap the camera to watch it, debug logging says ffmpeg is dropping all the frames. The server is definitely powerful enough to handle it (x86 unRAID, streaming an UniFI AI 360 camera works).

I have tried, unbridge true/false, packetSize removed/188 and blank encoderOptions. All same result.

To Reproduce:
Add an ESP32-Cam to HomeBridge and try to view it via the "Home" app on iOS.

Logs:

[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] Starting video stream: 1280 x 720, 20 fps, 299 kbps
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] Stream command: ffmpeg -re -f mjpeg -i http://10.0.3.91:81 -an -sn -dn -codec:v libx264 -pix_fmt yuv420p -color_range mpeg -r 20 -f rawvideo -preset ultrafast -filter:v scale='min(1280,iw)':'min(720,ih)':force_original_aspect_ratio=decrease,scale=trunc(iw/2)*2:trunc(ih/2)*2 -b:v 299k -payload_type 99 -ssrc 3523393 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params 7ywjPYD9i8eTomXCYjGydEUpGwVJo0wlHbgH9n6N srtp://10.0.0.127:64453?rtcpport=64453&pkt_size=188 -loglevel level+verbose -progress pipe:1
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info] ffmpeg version 6.0-homebridge-alpine-x86_64-static Copyright (c) 2000-2023 the FFmpeg developers
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   built with gcc 12.2.1 (Alpine 12.2.1_git20220924-r10) 20220924
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   configuration: --enable-hardcoded-tables --enable-nonfree --enable-gpl --enable-hardcoded-tables --enable-hardcoded-tables --enable-openssl --enable-libdav1d --enable-libsvtav1 --enable-libx264 --enable-libx265 --enable-libvpx --enable-libxvid --enable-libvidstab --enable-libaom --enable-libzimg --enable-lv2 --enable-libopencore_amrnb --enable-libopencore_amrwb --enable-libmp3lame --enable-libopus --enable-libvorbis --enable-libtheora --enable-libfdk-aac --enable-libwebp --enable-libsrt --enable-libvpl --enable-vaapi --disable-ffnvcodec --enable-amf --disable-debug --disable-shared --enable-pthreads --enable-static --enable-version3 --extra-cflags='-I/build/workspace/include -I/build/workspace/include/lilv-0' --extra-ldexeflags=-static --extra-ldflags=-L/build/workspace/lib --extra-libs='-ldl -lpthread -lm -lz' --pkgconfigdir=/build/workspace/lib/pkgconfig --pkg-config-flags=--static --prefix=/build/workspace --extra-version=homebridge-alpine-x86_64-static
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libavutil      58.  2.100 / 58.  2.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libavcodec     60.  3.100 / 60.  3.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libavformat    60.  3.100 / 60.  3.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libavdevice    60.  1.100 / 60.  1.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libavfilter     9.  3.100 /  9.  3.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libswscale      7.  1.100 /  7.  1.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libswresample   4. 10.100 /  4. 10.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [info]   libpostproc    57.  1.100 / 57.  1.100
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [tcp @ 0x154621cf5180] [verbose] Starting connection attempt to 10.0.3.91 port 81
[1/3/2024, 12:01:00 AM] [Camera FFmpeg] [Swinki] [tcp @ 0x154621cf5180] [verbose] Successfully connected to 10.0.3.91 port 81
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info] Input #0, mjpeg, from 'http://10.0.3.91:81':
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]   Duration: N/A, bitrate: N/A
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]   Stream #0:0: Video: mjpeg (Baseline), 1 reference frame, yuvj422p(pc, bt470bg/unknown/unknown, center), 1280x720, 25 tbr, 1200k tbn
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info] Stream mapping:
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]   Stream #0:0 -> #0:0 (mjpeg (native) -> h264 (libx264))
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info] Press [q] to stop, [?] for help
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_0 @ 0x154621cdbd00] [verbose] w:min(1280,iw) h:min(720,ih) flags:'' interl:0
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_1 @ 0x154621cd0800] [verbose] w:trunc(iw/2)*2 h:trunc(ih/2)*2 flags:'' interl:0
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [graph 0 input from stream 0:0 @ 0x154621cd0900] [verbose] w:1280 h:720 pixfmt:yuvj422p tb:1/1200000 fr:25/1 sar:0/1
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_0 @ 0x154621cdbd00] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuvj422p sar:0/1 flags:(null)
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [swscaler @ 0x154621846040] [warning] deprecated pixel format used, make sure you did set range correctly
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_1 @ 0x154621cd0800] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuv420p sar:0/1 flags:0x00000004
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_0 @ 0x154621cdbd00] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuvj422p sar:0/1 flags:(null)
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_0 @ 0x154621cdbd00] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuvj422p sar:0/1 flags:(null)
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_0 @ 0x154621cdbd00] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuvj422p sar:0/1 flags:(null)
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [swscaler @ 0x154621846040] [warning] deprecated pixel format used, make sure you did set range correctly
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_1 @ 0x154621cd0800] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuv420p sar:0/1 flags:0x00000004
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [swscaler @ 0x154621846040] [warning] deprecated pixel format used, make sure you did set range correctly
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_1 @ 0x154621cd0800] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuv420p sar:0/1 flags:0x00000004
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [swscaler @ 0x154621846040] [warning] deprecated pixel format used, make sure you did set range correctly
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [Parsed_scale_1 @ 0x154621cd0800] [verbose] w:1280 h:720 fmt:yuvj422p sar:0/1 -> w:1280 h:720 fmt:yuv420p sar:0/1 flags:0x00000004
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2 AVX512
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] profile Constrained Baseline, level 3.1, 4:2:0, 8-bit
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info] Output #0, rtp, to 'srtp://10.0.0.127:64453?rtcpport=64453&pkt_size=188':
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]   Metadata:
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]     encoder         : Lavf60.3.100
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]   Stream #0:0: Video: h264, 1 reference frame, yuv420p(tv, bt470bg/unknown/unknown, progressive, center), 1280x720 (0x0), q=2-31, 299 kb/s, 20 fps, 90k tbn
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]     Metadata:
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]       encoder         : Lavc60.3.100 libx264
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]     Side data:
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info]       cpb: bitrate max/min/avg: 0/0/299000 buffer size: 0 vbv_delay: N/A
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info] frame=    0 fps=0.0 q=0.0 size=       0kB time=-577014:32:22.77 bitrate=  -0.0kbits/s speed=N/A    
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [vost#0:0/libx264 @ 0x154621cd4040] [verbose] Past duration 0.799995 too large
[1/3/2024, 12:01:01 AM] [Camera FFmpeg] [Swinki] [info] frame=    0 fps=0.0 q=0.0 size=       0kB time=-577014:32:22.77 bitrate=  -0.0kbits/s speed=N/A    
[1/3/2024, 12:01:02 AM] [Camera FFmpeg] [Swinki] [info] frame=    0 fps=0.0 q=0.0 size=       0kB time=-577014:32:22.77 bitrate=  -0.0kbits/s speed=N/A    
[1/3/2024, 12:01:02 AM] [Camera FFmpeg] [Swinki] [vost#0:0/libx264 @ 0x154621cd4040] [verbose] *** dropping frame 10 at ts 8
[1/3/2024, 12:01:02 AM] [Camera FFmpeg] [Swinki] [info] frame=    0 fps=0.0 q=0.0 size=       0kB time=-577014:32:22.77 bitrate=  -0.0kbits/s dup=0 drop=1 speed=N/A    
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [vost#0:0/libx264 @ 0x154621cd4040] [verbose] *** dropping frame 14 at ts 12
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [info] frame=    0 fps=0.0 q=0.0 size=       0kB time=-577014:32:22.77 bitrate=  -0.0kbits/s dup=0 drop=2 speed=N/A    
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] Stopped video stream.
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [info] 
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] 
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [q] command received. Exiting.
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] 
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [out#0/rtp @ 0x154621cff180] [verbose] All streams finished
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [out#0/rtp @ 0x154621cff180] [verbose] Terminating muxer thread
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [AVIOContext @ 0x154621cf5d00] [verbose] Statistics: 85944 bytes written, 0 seeks, 504 writeouts
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [info] frame=   18 fps=7.2 q=-1.0 Lsize=      84kB time=00:00:00.85 bitrate= 808.9kbits/s dup=0 drop=2 speed=0.339x    
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [AVIOContext @ 0x154621d00e00] [verbose] Statistics: 1291 bytes written, 0 seeks, 6 writeouts
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [info] video:77kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 8.828445%
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [verbose] Input file #0 (http://10.0.3.91:81):
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [verbose]   Input stream #0:0 (video): 20 packets read (1129190 bytes); 20 frames decoded; 
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [verbose]   Total: 20 packets (1129190 bytes) demuxed
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [verbose] Output file #0 (srtp://10.0.0.127:64453?rtcpport=64453&pkt_size=188):
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [verbose]   Output stream #0:0 (video): 18 frames encoded; 18 packets muxed (78972 bytes); 
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [verbose]   Total: 18 packets (78972 bytes) muxed
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] Getting the first frames took 2.788 seconds.
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] frame I:1     Avg QP:43.00  size:  9526
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] frame P:17    Avg QP:41.24  size:  4085
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] mb I  I16..4: 100.0%  0.0%  0.0%
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] mb P  I16..4: 33.6%  0.0%  0.0%  P16..4: 10.3%  0.0%  0.0%  0.0%  0.0%    skip:56.1%
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] final ratefactor: 47.12
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] coded y,uvDC,uvAC intra: 4.9% 21.3% 3.7% inter: 2.1% 8.1% 0.1%
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] i16 v,h,dc,p: 52% 20% 15% 13%
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] i8c dc,h,v,p: 80%  7% 12%  1%
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [libx264 @ 0x154621cd5440] [info] kb/s:701.97
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [verbose] Terminating demuxer thread 0
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] [AVIOContext @ 0x154621cf5880] [verbose] Statistics: 1193787 bytes read, 0 seeks
[1/3/2024, 12:01:03 AM] [Camera FFmpeg] [Swinki] FFmpeg exited with code: 0 and signal: null (Expected)

Homebridge Config:

{
    "bridge": {
        "name": "Homebridge 07E4",
        "username": "0E:41:94:A3:07:E4",
        "port": 51070,
        "pin": "123-41-234",
        "advertiser": "avahi"
    },
    "accessories": [],
    "platforms": [
        {
            "name": "Config",
            "port": 8581,
            "platform": "config"
        },
        {
            "controllers": [
                {
                    "address": "10.0.0.1",
                    "username": "*******",
                    "password": "*******"
                }
            ],
            "name": "UniFi Protect",
            "platform": "UniFi Protect",
            "options": [
                "Enable.Video.Transcode.Hardware.D021F9D6D96C",
                "Enable.Video.Transcode.Hardware",
                "Enable.Motion.SmartDetect.ObjectSensors",
                "Enable.Audio.Filter.Noise.D021F9D6D96C",
                "Enable.Audio.Filter.Noise.FftNr.D021F9D6D96C.90",
                "Enable.Audio.Filter.Noise.HighPass.D021F9D6D96C.200",
                "Enable.Audio.Filter.Noise.LowPass.D021F9D6D96C.1000",
                "Enable.Video.Transcode.Hardware.70A7410FD91C"
            ]
        },
        {
            "name": "Camera FFmpeg",
            "cameras": [
                {
                    "name": "Swinki",
                    "model": "ESP32-Cam",
                    "motion": true,
                    "motionTimeout": 5,
                    "unbridge": true,
                    "videoConfig": {
                        "source": "-re -f mjpeg -i http://10.0.3.91:81",
                        "stillImageSource": "-f mjpeg -i http://10.0.3.91/capture",
                        "maxStreams": 1,
                        "maxWidth": 1280,
                        "maxHeight": 720,
                        "maxFPS": 20,
                        "packetSize": 188,
                        "encoderOptions": "-preset ultrafast",
                        "debug": true
                    }
                }
            ],
            "platform": "Camera-ffmpeg"
        }
    ]
}

Environment:

  • Node.js Version: v18.18.2
  • NPM Version: 9.8.1
  • Homebridge Version: 1.7.0
  • Homebridge Camera FFmpeg Version: 6.0-homebridge-alpine-x86_64-static
  • Homebridge Config UI X Plugin Version: v4.54.1
  • Operating System: unRaid 6.12.6 (Docker)
Sunoo commented

Did you attach the right log? I only see it mention 2 dropped frames in the log you provided.

I stopped it as soon as the messages appeared. The connection is weak and very few frames come in. However nothing is ever sent to the iOS client.

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.