search

homebridge-eufy-security / plugin

Homebridge plugin to control certain Eufy Security devices
Apache License 2.0
168 stars 23 forks source link

[Bug]: Snapshot updates problem #43

Closed njuart closed 2 years ago

njuart commented 2 years ago

What happened?

Hi, after 2.0 update I've started to notice that there is a problem with catching snapshots. It works like 1 out 5 times. And if it was not updated it breaks the whole flow and stream becomes unresponsive. Attached some log snippet. I also have all the options active in my Indoor 2K camera config (Unbridge Camera, Force Refresh Snapshot, Improve livestream caching, Use RTSP). Thx in advance.

Device Type

Indoor Camera (Supported)

Plugin Version

v2.0.x (Supported)

HomeBridge Version

v1.4.x (Supported)

NodeJS Version

v16 (Supported)

Operating System

Raspbian 10+ (Supported)

Relevant log output

[Eufy camera 2ADF] The image snapshot handler for the given accessory is slow to respond! See https://homebridge.io/w/JtMGR for more info.
[5/27/2022, 8:04:11 PM] [EufySecurity-2.0.0] ERROR: write EPIPE
  err: Error: write EPIPE
      at afterWriteDispatched (node:internal/stream_base_commons:160:15)
      at writeGeneric (node:internal/stream_base_commons:151:3)
      at Socket._writeGeneric (node:net:817:11)
      at Socket._write (node:net:829:8)
      at writeOrBuffer (node:internal/streams/writable:389:12)
      at _write (node:internal/streams/writable:330:10)
      at Socket.Writable.write (node:internal/streams/writable:334:10)
      at VideostreamProxy.ondata (node:internal/streams/readable:754:22)
      at VideostreamProxy.emit (node:events:527:28)
      at addChunk (node:internal/streams/readable:315:12)
[5/27/2022, 8:04:11 PM] [EufySecurity-2.0.0] INFO:  ErrorCode EPIPE
[5/27/2022, 8:04:11 PM] [EufySecurity-2.0.0] WARN:  Fetching snapshot took 6.12 seconds. Eufy camera
[5/27/2022, 8:04:19 PM] [EufySecurity-2.0.0] INFO:  Eufy camera Starting video stream: 640x480, 30 fps, 299 kbps  (AAC-eld)
[5/27/2022, 8:04:22 PM] [EufySecurity-2.0.0] INFO:  Eufy camera Getting the first frames took 2.706 seconds.
[5/27/2022, 8:04:34 PM] [EufySecurity-2.0.0] INFO:  Eufy camera Stopped video stream.
[5/27/2022, 8:04:34 PM] [EufySecurity-2.0.0] INFO:  Eufy camera FFmpeg exited with code: 0 and signal: null (Expected)
[5/27/2022, 8:04:34 PM] [EufySecurity-2.0.0] INFO:  Connection closed by Eufy station.
[5/27/2022, 8:04:34 PM] [EufySecurity-2.0.0] INFO:  ErrorCode ECONNRESET
[5/27/2022, 8:04:34 PM] [EufySecurity-2.0.0] INFO:  Eufy camera FFmpeg exited with code: 0 and signal: null (Expected)
[5/27/2022, 8:04:40 PM] [EufySecurity-2.0.0] INFO:  Eufy camera livestream for Eufy camera has stopped.
[5/27/2022, 8:04:45 PM] [EufySecurity-2.0.0] INFO:  Eufy camera livestream for Eufy camera has started.
[5/27/2022, 8:04:45 PM] [EufySecurity-2.0.0] INFO:  Eufy camera livestream for Eufy camera has started.
[Eufy camera 2ADF] The image snapshot handler for the given accessory is slow to respond! See https://homebridge.io/w/JtMGR for more info.
[5/27/2022, 8:05:00 PM] [EufySecurity-2.0.0] WARN:  Proxy Stream (id: 37) was terminated due to inactivity.
[Eufy camera 2ADF] The image snapshot handler for the given accessory didn't respond at all! See https://homebridge.io/w/JtMGR for more info.
[Eufy camera 2ADF] The image snapshot handler for the given accessory is slow to respond! See https://homebridge.io/w/JtMGR for more info.
[5/27/2022, 8:05:33 PM] [EufySecurity-2.0.0] WARN:  Proxy Stream (id: 38) was terminated due to inactivity.
[5/27/2022, 8:05:33 PM] [EufySecurity-2.0.0] INFO:  Eufy camera livestream for Eufy camera has stopped.
[Eufy camera 2ADF] The image snapshot handler for the given accessory didn't respond at all! See https://homebridge.io/w/JtMGR for more info.
[5/27/2022, 8:05:42 PM] [EufySecurity-2.0.0] INFO:  Eufy camera livestream for Eufy camera has started.
[5/27/2022, 8:05:42 PM] [EufySecurity-2.0.0] INFO:  Eufy camera Starting video stream: 640x480, 30 fps, 299 kbps  (AAC-eld)
[5/27/2022, 8:05:43 PM] [EufySecurity-2.0.0] INFO:  Eufy camera livestream for Eufy camera has started.
[27/05/2022, 20:05:51] [homebridge-eufy-security] This plugin slows down Homebridge. The write handler for the characteristic 'Selected RTP Stream Configuration' on the accessory 'Eufy camera 2ADF' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info.
[5/27/2022, 8:05:51 PM] [EufySecurity-2.0.0] INFO:  Eufy camera Stopped video stream.
[5/27/2022, 8:05:53 PM] [EufySecurity-2.0.0] INFO:  Eufy camera FFmpeg exited with code: null and signal: SIGKILL (Forced)
[5/27/2022, 8:05:53 PM] [EufySecurity-2.0.0] INFO:  Eufy camera FFmpeg exited with code: null and signal: SIGKILL (Forced)
[Eufy camera 2ADF] The image snapshot handler for the given accessory is slow to respond! See https://homebridge.io/w/JtMGR for more info.
[5/27/2022, 8:05:58 PM] [EufySecurity-2.0.0] WARN:  Proxy Stream (id: 39) was terminated due to inactivity.
[5/27/2022, 8:06:06 PM] [EufySecurity-2.0.0] WARN:  Proxy Stream (id: 41) was terminated due to inactivity.
[Eufy camera 2ADF] The image snapshot handler for the given accessory didn't respond at all! See https://homebridge.io/w/JtMGR for more info.
[Eufy camera 2ADF] The image snapshot handler for the given accessory is slow to respond! See https://homebridge.io/w/JtMGR for more info.
[5/27/2022, 8:06:39 PM] [EufySecurity-2.0.0] WARN:  Proxy Stream (id: 43) was terminated due to inactivity.
[5/27/2022, 8:06:39 PM] [EufySecurity-2.0.0] INFO:  Eufy camera livestream for Eufy camera has stopped.
github-actions[bot] commented 2 years ago

Did you check this Common Issues pages ?

thieren commented 2 years ago

Hi!

Could you enable detailed logging in the advanced settings and post another log output? Maybe it would help if you post your json config also (without the personal information of course).

njuart commented 2 years ago

Sure, hope it helps. So flow of this log was the following:

  1. Got motion notification without snapshot
  2. Opened Home app (without pressing notification, I mean just regularly opened it), was doing nothing, only was waiting when snapshot will update in Home screen.
  3. Nothing happened, after couple of tries
  4. Put phone aside, waited a bit
  5. Got another motion notification but with snapshot already.

And this flow may be really sporadic, sometimes I can't get any snapshot at all, and stream stops working. Sometimes turning on / off camera helps, but often not. Also restarting HB helps sometimes.

Attached log and config. Thx

config.txt log.txt

thieren commented 2 years ago

Hey @njuart

I think I traced down the error. It's a minor logic trap in the livestream handling, which has unfortunately this effect. I'm currently testing a new version, where this is hopefully fixed.

Until then:

Sorry for the inconvenience.

njuart commented 2 years ago

Hey @njuart

I think I traced down the error. It's a minor logic trap in the livestream handling, which has unfortunately this effect.

I'm currently testing a new version, where this is hopefully fixed.

Until then:

  • in the latest beta (2.0.1-beta.1) this effect is mitigated. It will still break the stream one time, but It will recover the next time you start the stream (or a snapshot request)

  • If you don't use the option useCachedLocalLivestream this should not happen

Sorry for the inconvenience.

Cool, let me know if you need some help with testing. I use useCachedLocalLivestream btw. Thx for the efforts!

thieren commented 2 years ago

Just added a fix in #53

Please wait until the PR is merged.

njuart commented 2 years ago

Thx, checked new beta. Still not every motion notification has a snapshot in it, but sometimes it does, can't follow why. And what also noticed if I get motion notification without snapshot, when I open Home app, I see black screen in Camera viewer, and it takes a couple of tries to retrieve snapshot or I even need to open a stream to have snapshot updated and I see this in logs:

image

It looks like there is some kind of timeout in getting snapshot, and if during this time snapshot is not retrieved it breaks the whole flow.

thieren commented 2 years ago

I'm working on a new way to retrieve the snapshots faster. Hopefully this will solve your issue too.

See #33 for reference.

Anyway: what beta version exactly did you use? 2.0.1-beta.2 is just a few hours out and you've already cumulated well over 150 stream sessions according to your log. Not that this is impossible, but I'd like to get to know your use case a little bit better.

njuart commented 2 years ago

Yup, using latest 2.0.1-beta.2. I basically just turned on my Indoor 2k and that's it =)) It's just working and reacts to motion, sometimes I'm checking live stream from Home app. Usually most of the time when I'm at home I keep camera turned off, as there is no actual need. Sometimes I can turn it on to check how's kid is doing for some time.

thieren commented 2 years ago

Hey @njuart

Added new snapshot handling in 2.0.1-beta.5

Could you check if this helps with your problems?

njuart commented 2 years ago

Hey man @thieren 🤝 You're ninja, played a bit with new beta, generally it became way more stable at a first sight, will share what I've noticed so far. So:

Pros:

Cons:

[6/4/2022, 10:13:37 PM] [EufySecurity-2.0.1-beta.6] ERROR: Eufy camera snapshot request timed out
[Eufy camera 2ADF] Snapshot request handler provided empty image buffer!

Also, wrote you in Discord just in case. Thx for amazing work!

thieren commented 2 years ago

Hi @njuart

we've already been over this in discord but for good measure and all the people looking for the same answers:

when I check this option Use enhanced Snapshot handling it stays unchecked after HB restart, but in config I see "forcerefreshsnap": true

This is a caching issue with the homebridge-ui. Just empty your browser cache for homebridge-ui and you should be good to go. (see also https://github.com/homebridge/plugin-ui-utils/blob/master/DEVELOPMENT.md for reference)

stream itself became slower and less responsive, like with delay, before it was almost live, I mean I saw my moves almost immediately in viewer

This seems to have something to do that your stream has a higher resolution now. Still working on that, but the slowness of the stream will be due to the higher requirements on your hardware. If you manually revert to 640x480 via settings it should be as before.

when I turn camera on and go to Home app, it works like a charm, snapshots start to update almost immediately with 10-20 seconds interval, BUT as soon as I make any motion and get notification with snapshot (which is somehow bigger and with worse quality), snapshot update flow fails, it stops updating snapshots with interval, and it updates only if I make another motion or start stream and I see this in logs

Should be fixed in latest beta. Let me know.

thieren commented 2 years ago

Hey @njuart

since you didn't had any more problems with this, I'll close the issue. If something new comes up, please reopen.