Log errors for snapshot handler

[soulcook]

Describe The Problem: Since the latest release of Homebridge, I'm getting these errors in the logs:

[Living Room Camera] Snapshot request handler provided empty image buffer!
[Living Room Camera] The image snapshot handler for the given accessory is slow to respond! See https://git.io/JtMGR for more info.
[Living Room Camera] Snapshot request handler provided empty image buffer!
[Living Room Camera] The image snapshot handler for the given accessory is slow to respond! See https://git.io/JtMGR for more info.
[Living Room Camera] Snapshot request handler provided empty image buffer!
[Hall Camera] Snapshot request handler provided empty image buffer!

I have no idea what the empty image buffer issue is about, but — if you don't mind me commenting on this – the "slow to respond" issue usually means that you're handling the snapshot requests synchronously when you should be handling them asynchronously. Homebridge polls its accessories in a single thread, and so doesn't like to be kept waiting. It's better just to return a cached snapshot straight away without blocking, and at the same time fire off a function call to get a new snapshot. When the new one arrives, you can call updateCharacteristic() asynchronously.

To Reproduce: Run homebridge-ffmpeg under Hombridge v1.3.1.

Homebridge Config:

{
    "name": "Camera ffmpeg",
    "cameras": [
        {
            "name": "Courtyard Camera",
            "videoConfig": {
                "source": "-rtsp_transport tcp -re -i rtsp://admin:Secure99@192.168.185.10",
                "stillImageSource": "-i http://admin:Secure99@192.168.185.10/cgi-bin/snapshot.cgi",
                "maxStreams": 2,
                "maxFPS": 20,
                "maxBitrate": 300,
                "vcodec": "libx264",
                "packetSize": 1316,
                "audio": false,
                "debug": false
            }
        },
        {
            "name": "Garden Camera",
            "manufacturer": "Amcrest",
            "videoConfig": {
                "source": "-rtsp_transport tcp -re -i rtsp://admin:Secure99@192.168.185.11",
                "stillImageSource": "-i http://admin:Secure99@192.168.185.11/cgi-bin/snapshot.cgi",
                "maxStreams": 2,
                "maxFPS": 20,
                "maxBitrate": 300,
                "vcodec": "libx264",
                "packetSize": 1316,
                "audio": false,
                "debug": false
            }
        },
        {
            "name": "Greenhouse Camera",
            "videoConfig": {
                "source": "-rtsp_transport tcp -re -i rtsp://admin:Secure99@192.168.185.12",
                "stillImageSource": "-i http://admin:Secure99@192.168.185.12/cgi-bin/snapshot.cgi",
                "maxStreams": 2,
                "maxFPS": 20,
                "maxBitrate": 300,
                "vcodec": "libx264",
                "packetSize": 1316,
                "audio": false,
                "debug": false
            }
        },
        {
            "name": "Patio Camera",
            "videoConfig": {
                "source": "-rtsp_transport tcp -re -i rtsp://admin:Secure99@192.168.185.13",
                "stillImageSource": "-i http://admin:Secure99@192.168.185.13/cgi-bin/snapshot.cgi",
                "maxStreams": 2,
                "maxFPS": 20,
                "maxBitrate": 300,
                "vcodec": "libx264",
                "packetSize": 1316,
                "audio": false,
                "debug": false
            }
        },
        {
            "name": "Hall Camera",
            "videoConfig": {
                "source": "-rtsp_transport tcp -re -i rtsp://admin:Secure99@192.168.185.14",
                "stillImageSource": "-i http://admin:Secure99@192.168.185.14/cgi-bin/snapshot.cgi",
                "maxStreams": 2,
                "maxFPS": 20,
                "maxBitrate": 300,
                "vcodec": "libx264",
                "packetSize": 1316,
                "audio": false,
                "debug": false
            }
        },
        {
            "name": "Living Room Camera",
            "videoConfig": {
                "source": "-rtsp_transport tcp -re -i rtsp://admin:Secure99@192.168.185.15",
                "stillImageSource": "-i http://admin:Secure99@192.168.185.15/cgi-bin/snapshot.cgi",
                "maxStreams": 2,
                "maxFPS": 20,
                "maxBitrate": 300,
                "vcodec": "libx264",
                "packetSize": 1316,
                "audio": false,
                "debug": false
            }
        }
    ],
    "platform": "Camera-ffmpeg"
}

Environment:

• Node.js Version: v14.15.5
• NPM Version: v6.14.11
• Homebridge Version: v1.3.1
• Homebridge Camera FFmpeg Version: v3.1.0
• Homebridge Config UI X Plugin Version: v4.39.1
• Operating System: macOS 11.2.2

[Sunoo]

Snapshot request handler provided empty image buffer! means that what you have defined in stillImageSource isn't providing a snapshot. You'll need to either correct the URL or remove that option and allow the plugin to pull the first frame from source.

The image snapshot handler for the given accessory is slow to respond! means that it's taking at least 5 seconds to return that nothing.

Version 3.1.1 added some additional messaging to explain slow responses, and I'll likely be adding better logging of the errors when attempting to fetch a snapshot whenever the next version is released.

Also, no offense, but you apparently have very little understanding of how cameras work in Homebridge. There is no updateCharacteristic for snapshots, it is only possible to respond to HomeKit polling for new images. Returning a cached snapshot immediately would mean that when off your home network, you need to wait a full minute before getting an updated snapshot. Also, the latest snapshot displayed in the Home app may be the last frame of the video stream you were watching, since that wasn't handled as a snapshot, it wouldn't be in cache, so returning the cached snapshot on the next request would show an image older than what had been displayed in the app.

[soulcook]

Thanks for the quick reply, Dave.

I understand your points, but:

• My stillImageSource URLs definitively work. If I request one of the URLs in a browser a still image is returned instantly, and most of the time it works fine with the plug-in. It’s just that occasionally I get these messages in the log. Is it worth re-requesting the image if this happens? I think it may be only in the latest version that Homebridge has started complaining about it. Is the camera returning an empty response to the plug-in? Or is the plug-in timing out and deliberately sending an empty buffer to Homebridge?

• Sorry, you’re right, I have experience of other accessories in Homebridge but not cameras. Now you point it out I can see why updateCharacteristic wouldn’t make sense. But I wonder why Homebridge is complaining about slow responses to GET requests when all the cameras are on the local network and I never see any latency when I query the snapshot URL in a browser.

Maybe you could set a timeout on the GET handling, and, on the rare occasions when the snapshot is slow to arrive, send a cached one instead. I agree that it’s not as good as sending a “live” snapshot, but it’s likely to be better in general than returning nothing, and would avoid Homebridge complaining about empty buffers and slow responses.

Just a thought.

[soulcook]

I've just installed the new version, which (based on the release notes) looks as if it might make a difference. Will report back.

[Sunoo]

If the URLs work, then they are working intermittently. Not much I can do about that. Getting no image back is the only reason an empty buffer would be sent to Homebridge. Requesting the image a second time makes little sense, and would only further delay response to Homebridge, resulting in more warnings of slowness.

The reason you didn’t see these warnings in versions of Homebridge older than 1.3 is because v1.3 was the first to have these checks. Older versions would just silently fail when handed an empty image buffer.

For whatever reason, many cameras take a long time to actually return a snapshot (or the first frames of video). This is the main cause of slowness in this plugin. In v3.1.1, when the camera takes longer than 5 seconds, I’ve adding warnings to the log reporting how long that took. I may lower that threshold in future versions.

[soulcook]

Understood. Thank you.