search

mrlt8 / docker-wyze-bridge

WebRTC/RTSP/RTMP/LL-HLS bridge for Wyze cams in a docker container
GNU Affero General Public License v3.0
2.63k stars 162 forks source link

Doorbell stream falls behind (day/night fps) #340

Closed mrlt8 closed 2 years ago

mrlt8 commented 2 years ago

Originally posted by @dnestico in https://github.com/mrlt8/docker-wyze-bridge/issues/330#issuecomment-1097491395

mrlt8 commented 2 years ago

@dnestico Please let me know if you're still seeing a delay with v1.3.3

dnestico commented 2 years ago

I've just installed it now and I'll monitor it for a bit, it's already 5 mins like right after installing though.

Maybe it will catch up later when I check again though. Also, I wish my thumbnails would work again too.

mrlt8 commented 2 years ago

Ok, I just spun up a HA vm with v1.3.3, and forced the rotation on a normal feed to replicate as much as I can without an actual doorbell. Ran for about 30 min.

  1. RTSP stream in VLC (with reduced caching) is less than 1/2 second behind the wyze app.
  2. FFmpeg entity in HA is about 2 seconds behind the wyze app.
  3. Snapshots continue to work and are about 5 seconds behind the wyze app.
  4. The interval between snapshots is about every 10s even with RTSP5. possible keyframe issue..?

Is anyone else experience the doorbell falling behind?

dnestico commented 2 years ago

The snapshot issue must still be a home assistant issue it looks like because it definitely isn't working for me: https://github.com/home-assistant/core/issues/69128#issuecomment-1100913544

I'm just updating HA again right now we'll see if fixed.

I switched from FFMPEG to generic though because I was told it was better, it does load faster but it looks like it has these issues.

The doorbell falling behind is just weird though because still on the latest update it's still behind the rest, reloading the page usually brings it from 5 hours behind to around 20-30 mins behind (probably a browser caching issue), staying in sync with the other cams just doesn't work for some reason and yes I have doorbell rotation on.

davet2001 commented 2 years ago

If you installed HA 2022.4.0 and then upgraded to a newer version your thumbnails won't work until you either re trigger the YAML import (by deleting the camera from the UI and restarting) or edit the camera config and click next. The problem was with the YAML import which left the content type setting blank when importing a specific configuration.

The snapshots should come back if you do this.

dnestico commented 2 years ago

Do you mean "still image URL"? Because my thumbnails were working actually, they just stopped updating after a couple hours.

Screen Shot 2022-04-17 at 1 21 07 PM
davet2001 commented 2 years ago

@dnestico Ok, yes, that issue only applies if you have the still image url blank.

A still image url as you have in the picture should keep working as long as there's a valid image at that location.

BTW that still image url is quite a strange one. I assume you have another process copying images to your local storage.

dnestico commented 2 years ago

That's the snapshot url it gave me on the entity.. and like I said it was working for a bit now it doesn't, I checked the url and pretty much it's not updating and always the same image now

davet2001 commented 2 years ago

@dnestico If you have configured http://homeassistant:8123/local/driveway.jpg, it means you are telling HA to set up a proxy server, so that any time someone asks for a camera snapshot, it goes and loads an image from the local/driveway.jpg file, and serves it back on the proxy server.

In any case, if you give .../local/driveway.jpg as a file, it's up to you to update that file. It's not being generated or updated by HA - just an image on the HA server's storage.

If your stream is working correctly, I suggest deleting the still_image_url field and letting the stream component automatically generate still images. No need for any service running to update driveway.jpg

dnestico commented 2 years ago

The generic camera doesn't seem to update the thumbnails though, it only did that when I was on FFMPEG, and what I meant was that URL was updating the image for a couple hours before and now it stopped.

I am considering switching back to FFMPEG from generic though just for the thumbnails.

davet2001 commented 2 years ago

Maybe I didn't explain well.

What created the file http://homeassistant:8123/local/driveway.jpg ?

The generic camera integration will just display it. It won't change it or update it.

So if you directly open that url in your browser and refresh it but see that it is not changing when you expect, you need to look at what created the file to find the problem (it wasn't created by the the generic camera integration).

If you can get onvif or mjpeg working they are usually better options. Generic camera is a bit of a catch all for non standard cases.

dnestico commented 2 years ago

Sorry I changed it to "http://homeassistant.local:8123/local/driveway.jpg" and the image loads but again it's from a couple days ago.

What created that URL is the docker plugin on the dev branch, when I loaded it up it made camera entities that had both the "STREAM" and "IMAGE" URL. That is the URL I used for the snapshots.

But again, maybe FFMPEG might fix this but I was told that generic is faster and better so will have to test that.

davet2001 commented 2 years ago

Probably you need to find a way to see if the docker plugin is running properly.

It has created entities for you. But it has also created this jpg in /config/www/ and it is up to the plug-in to update it.

But really I recommend blanking still_url field in the configuration page based on what you've said.

mrlt8 commented 2 years ago

@dnestico please post logs from the add on. I've been trying to replicate this issue, but my streams and snapshots remain up to date.

dnestico commented 2 years ago

@davet2001 @mrlt8

So removing the image URL has now given me this screen which I didn't see before.

I set it to "video/mpeg" and that seems to have fixed it, it's now updating, gonna do it on all cameras. I will test this till tomorrow and come back here.video/mpeg

Screen Shot 2022-04-17 at 7 23 22 PM
dnestico commented 2 years ago

@mrlt8

Ok here are my logs after restarting the addon.

Both "garage" and "porch" cams are offline in HA even though the logs say the stream went up.

🚀 STARTING DOCKER-WYZE-BRIDGE v1.3.3 DEV 3 🏠 Home Assistant Mode 2022/04/17 19:28:46 [WyzeBridge] ♻️ FORCED REFRESH - Ignoring local 'user' data 2022/04/17 19:28:46 [WyzeBridge] ♻️ FORCED REFRESH - Ignoring local 'auth' data 2022/04/17 19:28:46 [WyzeBridge] ☁️ Fetching 'auth' from the Wyze API... 2022/04/17 19:28:46 [WyzeBridge] 💾 Saving 'auth' to local cache... 2022/04/17 19:28:46 [WyzeBridge] ☁️ Fetching 'user' from the Wyze API... 2022/04/17 19:28:47 [WyzeBridge] 💾 Saving 'user' to local cache... 2022/04/17 19:28:47 [WyzeBridge] ♻️ FORCED REFRESH - Ignoring local 'cameras' data 2022/04/17 19:28:47 [WyzeBridge] ☁️ Fetching 'cameras' from the Wyze API... 2022/04/17 19:28:48 [WyzeBridge] 💾 Saving 'cameras' to local cache... 🪄 BLACKLIST MODE ON 🎬 STARTING 5 OF 6 CAMERAS 2022/04/17 19:28:48 [WyzeBridge] Starting rtsp-simple-server v0.18.0 2022/04/17 19:28:48 [WyzeBridge] 🎉 Connecting to WyzeCam V3 - Luna Cam on 192.168.2.105 (1/3) 2022/04/17 19:28:48 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Doorbell on 192.168.2.104 (1/3) 2022/04/17 19:28:48 [WyzeBridge] 🎉 Connecting to WyzeCam V3 - Driveway on 192.168.2.30 (1/3) 2022/04/17 19:28:48 [WyzeBridge] 🎉 Connecting to WyzeCam V2 - Garage Cam on 192.168.2.31 (1/3) 2022/04/17 19:28:48 [WyzeBridge] 🎉 Connecting to WyzeCam V2 - Porch on 192.168.2.44 (1/3) 2022/04/17 19:28:50 [Front Doorbell] 📡 Getting 120kb/s HD stream (20fps) via LAN mode (WiFi: 100%) FW: 4.25.1.042 🔒 (DTLS) (2/3) 2022/04/17 19:28:50 [Front Doorbell] WARNING: Skipping smaller frame at start of stream (frame_size=4) 2022/04/17 19:28:50 [Garage Cam] 📡 Getting 120kb/s HD stream (15fps) via LAN mode (WiFi: 88%) FW: 4.9.8.1002 🔒 (DTLS) (2/3) 2022/04/17 19:28:50 [Porch] 📡 Getting 120kb/s HD stream (15fps) via LAN mode (WiFi: 98%) FW: 4.9.8.1002 🔒 (DTLS) (2/3) 2022/04/17 19:28:50 [Porch] WARNING: Skipping smaller frame at start of stream (frame_size=1) 2022/04/17 19:28:50 [Porch] WARNING: Waiting for keyframe 2022/04/17 19:28:50 [Luna Cam] 📡 Getting 120kb/s HD stream (20fps) via LAN mode (WiFi: 58%) FW: 4.36.3.19 (2/3) 2022/04/17 19:28:50 [Luna Cam] WARNING: Skipping smaller frame at start of stream (frame_size=1) 2022/04/17 19:28:50 [RTSP][GARAGE-CAM] ✅ '/garage-cam' stream is UP! (3/3) 2022/04/17 19:28:50 [Driveway] 📡 Getting 120kb/s HD stream (20fps) via LAN mode (WiFi: 97%) FW: 4.36.9.117 🔒 (DTLS) (2/3) 2022/04/17 19:28:50 [Driveway] WARNING: Skipping smaller frame at start of stream (frame_size=1) 2022/04/17 19:28:51 [RTSP][GARAGE-CAM] 📖 New client reading 2022/04/17 19:28:51 [RTSP][PORCH] ✅ '/porch' stream is UP! (3/3) 2022/04/17 19:28:51 [RTSP][DRIVEWAY] ✅ '/driveway' stream is UP! (3/3) 2022/04/17 19:28:51 [RTSP][LUNA-CAM] ✅ '/luna-cam' stream is UP! (3/3) 2022/04/17 19:28:51 [RTSP][PORCH] 📖 New client reading 2022/04/17 19:28:51 [RTSP][LUNA-CAM] 📖 New client reading 2022/04/17 19:28:52 [RTSP][DRIVEWAY] 📖 New client reading 2022/04/17 19:28:56 [RTSP][FRONT-DOORBELL] ✅ '/front-doorbell' stream is UP! (3/3) 2022/04/17 19:28:56 [RTSP][GARAGE-CAM] 📕 Client stopped reading 2022/04/17 19:28:56 [RTSP][FRONT-DOORBELL] 📖 New client reading 2022/04/17 19:28:56 [RTSP][PORCH] 📕 Client stopped reading 2022/04/17 19:28:57 [RTSP][DRIVEWAY] 📕 Client stopped reading 2022/04/17 19:28:58 [RTSP][LUNA-CAM] 📕 Client stopped reading 2022/04/17 19:29:02 [RTSP][FRONT-DOORBELL] 📕 Client stopped reading 2022/04/17 19:29:08 [RTSP][DRIVEWAY] 📖 New client reading 2022/04/17 19:29:08 [RTSP][LUNA-CAM] 📖 New client reading 2022/04/17 19:29:08 [RTSP][FRONT-DOORBELL] 📖 New client reading 2022/04/17 19:29:08 [RTSP][DRIVEWAY] 📖 New client reading 2022/04/17 19:29:08 [RTSP][FRONT-DOORBELL] 📖 New client reading 2022/04/17 19:29:09 [RTSP][LUNA-CAM] 📖 New client reading 2022/04/17 19:29:56 [Luna Cam] WARNING: FPS param mismatch (framerate=20) 2022/04/17 19:31:09 [Driveway] WARNING: Frame not available yet 2022/04/17 19:31:56 [RTSP][GARAGE-CAM] 📖 New client reading 2022/04/17 19:31:57 [RTSP][PORCH] 📖 New client reading 2022/04/17 19:31:58 [RTSP][DRIVEWAY] 📖 New client reading 2022/04/17 19:31:59 [RTSP][LUNA-CAM] 📖 New client reading 2022/04/17 19:32:02 [RTSP][GARAGE-CAM] 📕 Client stopped reading 2022/04/17 19:32:02 [RTSP][DRIVEWAY] 📕 Client stopped reading 2022/04/17 19:32:02 [RTSP][PORCH] 📕 Client stopped reading 2022/04/17 19:32:03 [RTSP][FRONT-DOORBELL] 📖 New client reading 2022/04/17 19:32:06 [RTSP][LUNA-CAM] 📕 Client stopped reading 2022/04/17 19:32:09 [RTSP][FRONT-DOORBELL] 📕 Client stopped reading

mrlt8 commented 2 years ago

Most likely an MQTT issue somewhere that I need to figure out, but status can be ignored if the stream is available.

Also, current dev should be v1.3.4 DEV 1. You probably need to uninstall and install the dev branch once.

dnestico commented 2 years ago

@mrlt8 Update: both cams stream just came back online and here are the logs.

Will have to see how long it lasts.

2022/04/17 19:32:09 [RTSP][FRONT-DOORBELL] 📕 Client stopped reading 2022/04/17 19:35:02 [RTSP][GARAGE-CAM] 📖 New client reading 2022/04/17 19:35:02 [RTSP][DRIVEWAY] 📖 New client reading 2022/04/17 19:35:03 [RTSP][PORCH] 📖 New client reading 2022/04/17 19:35:07 [RTSP][LUNA-CAM] 📖 New client reading 2022/04/17 19:35:08 [RTSP][GARAGE-CAM] 📕 Client stopped reading 2022/04/17 19:35:08 [RTSP][PORCH] 📕 Client stopped reading 2022/04/17 19:35:08 [RTSP][DRIVEWAY] 📕 Client stopped reading 2022/04/17 19:35:10 [RTSP][FRONT-DOORBELL] 📖 New client reading 2022/04/17 19:35:14 [RTSP][LUNA-CAM] 📕 Client stopped reading 2022/04/17 19:35:16 [RTSP][FRONT-DOORBELL] 📕 Client stopped reading 2022/04/17 19:36:42 [RTSP][PORCH] 📖 New client reading 2022/04/17 19:36:42 [RTSP][GARAGE-CAM] 📖 New client reading 2022/04/17 19:38:08 [RTSP][GARAGE-CAM] 📖 New client reading 2022/04/17 19:38:09 [RTSP][PORCH] 📖 New client reading 2022/04/17 19:38:09 [RTSP][DRIVEWAY] 📖 New client reading 2022/04/17 19:38:13 [RTSP][GARAGE-CAM] 📕 Client stopped reading 2022/04/17 19:38:14 [RTSP][PORCH] 📕 Client stopped reading 2022/04/17 19:38:14 [RTSP][DRIVEWAY] 📕 Client stopped reading 2022/04/17 19:38:15 [RTSP][LUNA-CAM] 📖 New client reading 2022/04/17 19:38:17 [RTSP][FRONT-DOORBELL] 📖 New client reading 2022/04/17 19:38:21 [RTSP][LUNA-CAM] 📕 Client stopped reading 2022/04/17 19:38:23 [RTSP][FRONT-DOORBELL] 📕 Client stopped reading

dnestico commented 2 years ago

Most likely an MQTT issue somewhere that I need to figure out, but status can be ignored if the stream is available.

Also, current dev should be v1.3.4 DEV 1. You probably need to uninstall and install the dev branch once.

Yes, when it says "unavailable" the whole stream is down and doesn't play.

Oh ok, didn't realize that cuz it didn't give a prompt to update the addon in HA. Will check it out.

mrlt8 commented 2 years ago

Are the streams still behind?

The logs should show the camera as down if the connection to the camera is lost, but otherwise the rtsp stream should always be accessible. Not sure why the clients stopped reading.

dnestico commented 2 years ago

Restarted HA litterally just 5 mins ago cuz was editing my views and everything is in near real-time 2-5 second delay... but the doorbell is sitting at 2 mins behind.

Also, how do I update the dev branch? Since it doesn't say there is an update available.

mrlt8 commented 2 years ago

I think you'd need to remove it once, go to the add-on store, refresh sources, and then install the dev add-on.

dnestico commented 2 years ago

Did exactly that, according to the logs it worked.

🚀 STARTING DOCKER-WYZE-BRIDGE v1.3.4 DEV 1

a billion client stopped/reading logs is still a thing but guess that's fine, streams are also up and the doorbell is 1 min behind, will see if it catches up.

mrlt8 commented 2 years ago

I don't think it can catch up if it's already behind. Are you letting it play for a few seconds? It may show an older time stamp at the start until it gets a newer key frame. Could also be a caching issue with your media player...

Can you filter out all the other cams to see if that helps with the delay?

dnestico commented 2 years ago

Alright, I have filtered the mac addresses of all 5 cameras except the doorbell now.

This time I see something I've never seen in the logs before...

2022/04/17 21:15:37 [WyzeBridge] Starting rtsp-simple-server v0.18.0 2022/04/17 21:15:37 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Doorbell on 192.168.2.104 (1/3) 2022/04/17 21:15:38 [Front Doorbell] 📡 Getting 120kb/s HD stream (20fps) via LAN mode (WiFi: 99%) FW: 4.25.1.042 🔒 (DTLS) (2/3) 2022/04/17 21:15:38 [Front Doorbell] WARNING: Skipping smaller frame at start of stream (frame_size=4) 2022/04/17 21:15:44 [RTSP][FRONT-DOORBELL] ✅ '/front-doorbell' stream is UP! (3/3) 2022/04/17 21:15:44 [RTSP][FRONT-DOORBELL] 📖 New client reading 2022/04/17 21:15:49 [RTSP][FRONT-DOORBELL] 📖 New client reading

Traceback (most recent call last): File "/app/rtsp_event.py", line 138, in rtsp.pub_start() File "/app/rtsp_event.py", line 66, in pub_start ).wait(10) File "/usr/local/lib/python3.10/subprocess.py", line 1204, in wait return self._wait(timeout=timeout) File "/usr/local/lib/python3.10/subprocess.py", line 1930, in _wait raise TimeoutExpired(self.args, timeout) subprocess.TimeoutExpired: Command '['ffmpeg', '-loglevel', 'fatal', '-skip_frame', 'nokey', '-rtsp_transport', 'tcp', '-i', 'rtsp://127.0.0.1:8554/front-doorbell', '-vframes', '1', '-y', '/img/front-doorbell.jpg']' timed out after 10 seconds

2022/04/17 21:15:57 [RTSP][FRONT-DOORBELL] 📕 Client stopped reading 2022/04/17 21:16:35 [Front Doorbell] WARNING: FPS param mismatch (framerate=20)

mrlt8 commented 2 years ago

The timeout was added in the dev branch. Interesting, looks like the screenshots are taking a long time for some reason. I wonder if we need to add more key frames when re-encoding the stream.

Not sure why it's saying fps mismatch since it seems to be requesting 20fps and getting 20fps. I wonder if there's an issue here, I did have issues with one of my cameras when the fps went crazy.

mrlt8 commented 2 years ago

So been trying to tweak the snapshot commands, but the actual process takes a minimum of like 5 seconds for a single image in ffmpeg, but can sometimes take well over 40 seconds. Add to that the 5 second cool down, and you'd get a 10 second interval at best. New dev build (https://github.com/mrlt8/docker-wyze-bridge/commit/f38ffb7556ffdfde75b20aa71f01fdaf28c6cab4) should timeout after 25 seconds and then try again.

As for the delay, it seems like the media players in generic and ffmpeg can sometimes buffer or pause, but I found that manually moving to the very end of the timeline could sometimes help the video catch up. Again, couldn't notice any major delays outside HA in VLC or Homekit.

mrlt8 commented 2 years ago

@dnestico Did the issue start after updating to the March 30 firmware?

https://support.wyze.com/hc/en-us/articles/360024852172-Release-Notes

Note: We are pausing this firmware while we look into the cause of reports of longer loading times for live streams or connections failing at step 3/3. We apologize to anyone impacted by this issue.

dnestico commented 2 years ago

Not sure but it has to firmware related cuz the doorbell never had these issues like a month or 2 ago, as of right now it's on the latest update.

I'm a beta tester so it may be the beta firmware too, but I never experience these issues in the wyze app.

krystiancharubin commented 2 years ago

Stream still failing behind, over the course of about 7 hours stream is about 13 min behind. In the image you can see two timestamps, bottom one is from wyze, top one is current time from frigate.

NET_MODE: LAN
ROTATE_DOOR: "true"
RTSP_READTIMEOUT: 30
QUALITY: HD180
🚀 STARTING DOCKER-WYZE-BRIDGE v1.3.4 DEV 2
2022/04/19 16:41:40 [WyzeBridge] 📚 Using 'user' from local cache...
2022/04/19 16:41:40 [WyzeBridge] 📚 Using 'cameras' from local cache...
🎬 STARTING ALL 1 CAMERAS
2022/04/19 16:41:40 [WyzeBridge] Starting rtsp-simple-server v0.18.0
2022/04/19 16:41:40 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Door on 10.1.0.159 (1/3)
2022/04/19 16:41:42 [Front Door] 📡 Getting 180kb/s HD stream (20fps) via LAN mode (WiFi: 63%) FW: 4.25.1.038 🔒 (DTLS) (2/3)
2022/04/19 16:41:42 [Front Door] WARNING: Skipping smaller frame at start of stream (frame_size=4)
2022/04/19 16:41:47 [RTSP][FRONT-DOOR] ✅ '/front-door' stream is UP! (3/3)
2022/04/19 16:41:49 [RTSP][FRONT-DOOR] 📖 New client reading 
2022/04/19 20:19:14 [Front Door] WARNING: FPS param mismatch (framerate=20)
Screen Shot 2022-04-19 at 9 26 05 PM
mrlt8 commented 2 years ago

This does seem to be a FPS issue, probably coming from the different FPS for night/day. Is there a delay if you start the stream during the day? Does it go away if FPS_FIX is switched on?

We could try hardcoding the frame rate into the ffmpeg command, but not sure how it would do when the frame rate switched between night/day.

Also added some more tweaks to FFmpeg in Dev 3/4. Was able to get most snapshots down to 1-3 seconds, so the interval for RTSP5 is averaging about 6s.

krystiancharubin commented 2 years ago

That stream was started during the day, not sure if the delay happened throughout the day or when it switched to night vision. I tested FPS_FIX before but the stream never managed to come back up after getting the fps mismatch. Installed DEV 4 and restarted the stream during the day, will check in a few times during the day and see if there is any delay.

krystiancharubin commented 2 years ago

Stream was in sync throughout the day, when night vision activated it seems like fps changed to 15 which began the time drift. Running DEV 4 I also noticed the camera timeout much more often, seems to happen about every 30 min. With DEV 2 it was connected for many hours without any timeouts.

2022/04/20 19:30:22 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Door on 10.1.0.159 (1/3)
2022/04/20 19:30:24 [Front Door] 📡 Getting 180kb/s HD stream (20fps) via LAN mode (WiFi: 63%) FW: 4.25.1.038 🔒 (DTLS) (2/3)
2022/04/20 19:30:40 [Front Door] WARNING: Skipping smaller frame at start of stream (frame_size=4)
2022/04/20 19:30:48 [RTSP][FRONT-DOOR] ✅ '/front-door' stream is UP! (3/3)
2022/04/20 19:30:55 [RTSP][FRONT-DOOR] 📖 New client reading 
2022/04/20 20:01:07 [Front Door] WARNING: Frame not available yet
2022/04/20 20:01:36 [RTSP][FRONT-DOOR] ❌ '/front-door' stream is down
2022/04/20 20:01:36 [RTSP][FRONT-DOOR] 📕 Client stopped reading
2022/04/20 20:01:36 [Front Door] Stream did not receive a frame for over 30s
2022/04/20 20:01:37 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Door on 10.1.0.159 (1/3)
2022/04/20 20:01:57 [Front Door] IOTC_ER_TIMEOUT
2022/04/20 20:01:59 [WyzeBridge] ⏰ Timed out connecting to Front Door (20s).
2022/04/20 20:02:09 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Door on 10.1.0.159 (1/3)
2022/04/20 20:02:29 [Front Door] IOTC_ER_TIMEOUT
2022/04/20 20:02:31 [WyzeBridge] ⏰ Timed out connecting to Front Door (20s).
2022/04/20 20:02:41 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Door on 10.1.0.159 (1/3)
2022/04/20 20:02:43 [Front Door] 📡 Getting 180kb/s HD stream (20fps) via LAN mode (WiFi: 63%) FW: 4.25.1.038 🔒 (DTLS) (2/3)
2022/04/20 20:03:44 [Front Door] WARNING: Skipping smaller frame at start of stream (frame_size=4)
2022/04/20 20:04:32 [RTSP][FRONT-DOOR] ✅ '/front-door' stream is UP! (3/3)
2022/04/20 20:04:35 [RTSP][FRONT-DOOR] 📖 New client reading 
2022/04/20 20:19:37 [Front Door] WARNING: FPS param mismatch (avRecv FPS=15)

With FPS_FIX=true stream just goes down when fps mismatch is detected. Seems like the change_fps function is killing the stream.

2022/04/21 01:14:12 [WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Door on 10.1.0.159 (1/3)
2022/04/21 01:14:14 [Front Door] 📡 Getting 180kb/s HD stream (20fps) via LAN mode (WiFi: 62%) FW: 4.25.1.038 🔒 (DTLS) (2/3)
2022/04/21 01:14:14 [Front Door] WARNING: Skipping smaller frame at start of stream (frame_size=4)
2022/04/21 01:14:19 [RTSP][FRONT-DOOR] ✅ '/front-door' stream is UP! (3/3)
2022/04/21 01:14:26 [RTSP][FRONT-DOOR] 📖 New client reading 
2022/04/21 01:15:05 [Front Door] WARNING: FPS param mismatch (avRecv FPS=15)
2022/04/21 01:15:37 [RTSP][FRONT-DOOR] 📕 Client stopped reading
2022/04/21 01:15:37 [RTSP][FRONT-DOOR] ❌ '/front-door' stream is down
mrlt8 commented 2 years ago

Ok, so at least we know that the night FPS is probably causing the issue.

Made some changes to change_fps so it shouldn't block the process/stream.

krystiancharubin commented 2 years ago

stream stays up when FPS changes when FPS_FIX=true, time drift persists.

mrlt8 commented 2 years ago

Bummer. Was really hoping that would fix it.

Just to confirm does the camera also drift without the rotation?

krystiancharubin commented 2 years ago

Just tested an drift still happens when there is no rotation

krystiancharubin commented 2 years ago

Seems like it keeps requesting FPS but it's not actually changing.

2022/04/23 01:30:48 [WyzeBridge][INFO][WyzeBridge] 🎉 Connecting to WyzeCam Doorbell - Front Door on 10.1.0.159 (1/3)
2022/04/23 01:30:48 [wyzecam.iotc][DEBUG][Front Door] Connect via IOTC_Connect_ByUIDEx
2022/04/23 01:30:49 [wyzecam.iotc][INFO][Front Door] AV Client Start: chan_id=0 expected_chan=0
2022/04/23 01:30:49 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] Now listening on channel id 0
2022/04/23 01:30:49 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10000ConnectRequest code=10000 resp_code=10001> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10000 txt_len=0> b''
2022/04/23 01:30:49 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10001 txt_len=17>: b"\x03\x9f<\x011ys\xb6\xe5\xb8\xcb\xd2\xbe\x8cv\xc2'"
2022/04/23 01:30:49 [wyzecam.tutk.tutk_protocol][DEBUG][Front Door] Sending response: <K10002ConnectAuth code=10002 resp_code=10003>
2022/04/23 01:30:49 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10002ConnectAuth code=10002 resp_code=10003> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10002 txt_len=22> b"\xe9\xe2\xe4\xec\x04[\x03\x88\xee\xf8\x1d'\x00\xd1P'2CAA\x01\x00"
2022/04/23 01:30:49 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10003 txt_len=651>: b'{"connectionRes":"1","cameraInfo":{"videoParm":{"type":"H264","bitRate":"180","resolution":"3","fps":"20","horizontalFlip":"1","verticalFlip":"1"},"settingParm":{"stateVision":"1","nightVision":"3","osd":"1","logSd":"1","logUdisk":"1", "telnet":"2","tz":"-4"},"basicInfo":{"firmware":"4.25.1.038","type":"Camera","hardware":"P00A0000","model":"WYZEDB3","mac":"2CAA8EF6E555","wifidb":"63"},"channelResquestResult":{"video":"1","audio":"0"},"recordType":{"type":"1"},"sdParm":{"status":"2","capacity":"0","free":"0"},"uDiskParm":{"status":"2","capacity":"0","free":"0"},"apartalarmParm":{"type":"0","startX":"0","longX":"0","startY":"0","heightY":"0"}}}'
2022/04/23 01:30:49 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10052DBSetResolvingBit code=10052 resp_code=10053> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10052 txt_len=6> b'\xb4\x00\x01\x00\x00\x00'
2022/04/23 01:30:49 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10053 txt_len=1>: b'\x01'
2022/04/23 01:30:50 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] No longer listening on channel id 0
2022/04/23 01:30:50 [WyzeBridge][INFO][Front Door] [videoParm] {'type': 'H264', 'bitRate': '180', 'resolution': '3', 'fps': '20', 'horizontalFlip': '1', 'verticalFlip': '1'}
2022/04/23 01:30:50 [WyzeBridge][INFO][Front Door] 📡 Getting 180kb/s HD stream (20fps) via LAN mode (WiFi: 63%) FW: 4.25.1.038 🔒 (DTLS) (2/3)
2022/04/23 01:30:51 [py.warnings][WARNING][Front Door] WARNING: Skipping smaller frame at start of stream (frame_size=4)
2022/04/23 01:30:55 [RTSP][FRONT-DOOR] ✅ '/front-door' stream is UP! (3/3)
2022/04/23 01:31:03 [RTSP][FRONT-DOOR] 📖 New client reading 
2022/04/23 01:31:42 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] Now listening on channel id 0
2022/04/23 01:31:42 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10020CheckCameraParams code=10020 resp_code=10021> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10020 txt_len=3> b'\x02\x03\x05'
2022/04/23 01:31:42 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10021 txt_len=20>: b'{"3":"180","5":"20"}'
2022/04/23 01:31:42 [py.warnings][WARNING][Front Door] WARNING: FPS param mismatch (avRecv FPS=15)
2022/04/23 01:31:42 [wyzecam.iotc][INFO][Front Door] Requesting frame_rate=15
2022/04/23 01:31:42 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] Now listening on channel id 0
2022/04/23 01:31:42 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10052DBSetResolvingBit code=10052 resp_code=10053> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10052 txt_len=6> b'\x00\x00\x01\x0f\x00\x00'
2022/04/23 01:31:42 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10053 txt_len=1>: b'\x01'
2022/04/23 01:31:43 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] No longer listening on channel id 0
2022/04/23 01:31:44 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] No longer listening on channel id 0
2022/04/23 01:32:34 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] Now listening on channel id 0
2022/04/23 01:32:34 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10020CheckCameraParams code=10020 resp_code=10021> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10020 txt_len=3> b'\x02\x03\x05'
2022/04/23 01:32:34 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10021 txt_len=20>: b'{"3":"180","5":"20"}'
2022/04/23 01:32:34 [wyzecam.iotc][INFO][Front Door] Requesting frame_rate=15
2022/04/23 01:32:34 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] Now listening on channel id 0
2022/04/23 01:32:34 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10052DBSetResolvingBit code=10052 resp_code=10053> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10052 txt_len=6> b'\x00\x00\x01\x0f\x00\x00'
2022/04/23 01:32:34 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10053 txt_len=1>: b'\x01'
2022/04/23 01:32:35 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] No longer listening on channel id 0
2022/04/23 01:32:35 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] No longer listening on channel id 0
2022/04/23 01:33:26 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] Now listening on channel id 0
2022/04/23 01:33:26 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10020CheckCameraParams code=10020 resp_code=10021> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10020 txt_len=3> b'\x02\x03\x05'
2022/04/23 01:33:26 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10021 txt_len=20>: b'{"3":"180","5":"20"}'
2022/04/23 01:33:26 [wyzecam.iotc][INFO][Front Door] Requesting frame_rate=15
2022/04/23 01:33:26 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] Now listening on channel id 0
2022/04/23 01:33:26 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] SEND <K10052DBSetResolvingBit code=10052 resp_code=10053> <TutkWyzeProtocolHeader prefix=b'HL' protocol=1 code=10052 txt_len=6> b'\x00\x00\x01\x0f\x00\x00'
2022/04/23 01:33:26 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] RECV <TutkWyzeProtocolHeader prefix=b'HL' protocol=11 code=10053 txt_len=1>: b'\x01'
2022/04/23 01:33:27 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] No longer listening on channel id 0
2022/04/23 01:33:27 [wyzecam.tutk.tutk_ioctl_mux][DEBUG][Front Door] No longer listening on channel id 0
mrlt8 commented 2 years ago

Thanks for the logs. It could be that the doorbell doesn't support the command to change fps. Maybe we could try changing the FPS in ffmpeg to see if that might help.

krystiancharubin commented 2 years ago

Yeah changing the fps in ffmpeg to match what camera is reporting might help. I guess we would have to kill ffmpeg and restart it with a new fps when it changes.

mrlt8 commented 2 years ago

We might be able to use K10020 to check if the night mode is on to restart ffmpeg.

mrlt8 commented 2 years ago

Any chance you could restore or reset the doorbell to see if we can get the fps to unstick? I'm guessing this could also be affecting the playback speed of the cloud recordings?

krystiancharubin commented 2 years ago

You mean do a factory reset? I don't think the FPS is stuck. During the day it reports 20fps but at night when night vision activates it changes to 15fps. I'll be able to reset it in a few weeks.

mrlt8 commented 2 years ago

The thing is that the camera is reporting 20 FPS, but the FrameInfoStruct which is returned with each frame from AVAPIs is reporting 15 FPS.

What does a media player like VLC report the FPS to be when rotation is off?

Could you try using playing with this ffmpeg cmd:

- FFMPEG_CMD_FRONT_DOOR=ffmpeg -loglevel error -fflags +genpts+flush_packets+nobuffer -flags +low_delay -analyzeduration 50 -probesize 50 -f h264 -r 15 -i - -c:v libx264 -filter:v transpose=1 -b:v 3000K -tune zerolatency -preset ultrafast -force_key_frames expr:gte(t,n_forced*2) -movflags +empty_moov+default_base_moof+frag_keyframe -rtsp_transport tcp -f rtsp rtsp://0.0.0.0:8554/{cam_name}

in particular -r 15

krystiancharubin commented 2 years ago

ROTATE_DOOR: "false"

Screen Shot 2022-04-24 at 10 27 14 PM

ROTATE_DOOR: "true"

Screen Shot 2022-04-24 at 10 29 44 PM

FFMPEG_CMD_FRONT_DOOR: ffmpeg -loglevel error -fflags +genpts+flush_packets+nobuffer -flags +low_delay -analyzeduration 50 -probesize 50 -f h264 -r 15 -i - -c:v libx264 -filter:v transpose=1 -b:v 3000K -tune zerolatency -preset ultrafast -force_key_frames expr:gte(t,n_forced*2) -movflags +empty_moov+default_base_moof+frag_keyframe -rtsp_transport tcp -f rtsp rtsp://0.0.0.0:8554/{cam_name}

Screen Shot 2022-04-24 at 10 28 44 PM

Still drifts with the custom ffmpeg command

mrlt8 commented 2 years ago

Would something like this help? It forces the input to 15 fps and out as 20 fps.

ffmpeg -loglevel error -fflags +genpts+flush_packets+nobuffer -flags +low_delay -analyzeduration 50 -probesize 50 -f h264 -r 15 -i - -c:v libx264 -filter:v transpose=1 -b:v 3000K -tune zerolatency -preset ultrafast -force_key_frames expr:gte(t,n_forced*2) -movflags +empty_moov+default_base_moof+frag_keyframe -rtsp_transport tcp -f rtsp -r 20 rtsp://0.0.0.0:8554/{cam_name}
krystiancharubin commented 2 years ago

Actually I just tested latest dev with the fps lock and that seems to have done the trick. Seems the camera was misreporting the fps when night vision is on causing the time drift.

mrlt8 commented 2 years ago

Marking this as resolved for now.

lunged commented 2 years ago

Is there anything I need to do to implement this fix? Env variables I am missing? I set my doorbell up tonight and it is about an hour behind now.

mrlt8 commented 2 years ago

Hmm, the fix should work with the default config. Are you on the latest build?
Is it falling behind when the night vision is on? Is this with the rotation enabled?