Closed Salvora closed 4 years ago
That’s a problem I’ve not heard yet. Could you enable debug in your config and share the log after reproducing the error?
The one log message you shared is expected, and will be logged when closing the camera view. I plan to suppress that message in the future due to the confusion it causes.
That’s a problem I’ve not heard yet. Could you enable debug in your config and share the log after reproducing the error?
The one log message you shared is expected, and will be logged when closing the camera view. I plan to suppress that message in the future due to the confusion it causes.
I have restarted homebridge and opened up a live stream of the 1st cam. The first thing I noticed was even after I closed the live stream, the logs didn't stop. I closed home app and opened home screen again and only then logs stopped. Then I try to open up the livestream of the 2nd cam but it didn't respond. Logs are attached homebridgelog1.txt
Again, this time I restarted homebridge. Opened live stream. Closed home app and tried to open the same live stream. Again same thing happened. After I closed live stream, it didn't terminate the connection. Let me know if you need additional info.
Interesting, I'll look through the log you provided later today, but it sounds like in some cases, FFmpeg is not getting closed when you close the stream for some reason.
Ironically, the sigkill message you mentioned earlier is what you should see when FFmpeg gets closed, so when you see that, it's probably when things are working.
It's hard to tell what's going on in those logs, I'll probably push a beta the makes logging a bit easier for me to follow soon.
In the meantime, since it sounds like ffmpeg isn't closing as expected, can you run pgrep -f -a ffmpeg
while you're watching a camera and then once again after you close it but are still seeing the logging, and post both results here?
As discussed, I pushed a beta with some logging improvements. You can install it with sudo npm install -g homebridge-camera-ffmpeg@beta --unsafe-perm
. The pgrep command I asked for in the previous comment would still be very helpful though.
It's hard to tell what's going on in those logs, I'll probably push a beta the makes logging a bit easier for me to follow soon.
In the meantime, since it sounds like ffmpeg isn't closing as expected, can you run
pgrep -f -a ffmpeg
while you're watching a camera and then once again after you close it but are still seeing the logging, and post both results here?
Tried that,
When I run pgrep -f -a ffmpeg
while doing nothing after restarting homebridge. I get nothing
When I run while watching stream, I get this
14768 ffmpeg -rtsp_transport tcp -vcodec h264_mmal -re -i rtsp://***@***/cam/realmonitor?channel=1&subtype=1 -map 0:0 -vcodec libx264 -pix_fmt yuv420p -r 20 -f rawvideo -preset ultrafast -tune zerolatency -vf scale=1280:720 -b:v 299k -bufsize 598k -maxrate 299k -payload_type 99 -ssrc 4356950 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params dK9KSDDXk6y49CR/4mD1uuKddRf/4mT2L6KpwmiE srtp://192.168.1.221:61079?rtcpport=61079&localrtcpport=61079&pkt_size=1316 -loglevel debug
14986 ffmpeg -rtsp_transport tcp -vcodec h264_mmal -re -i rtsp://***@***/cam/realmonitor?channel=1&subtype=1 -frames:v 1 -vf scale=480:270 -f image2 -
When I run even after I closed the stream and waited 5 mins, I still got previous result. I am guessing it is still streaming.
That’s what I expected to see, given your description of the issue. Good to have confirmation though.
Do the still images also stop updating when this happens as well?
How are you viewing the camera on your iOS device? I’m assuming the Home app, but third party apps can support cameras now too.
What version of iOS are you running? Are you on the iOS 14 beta?
Are you able to try the beta I pushed out and resubmit your logs? There have been no changes that should fix anything, but some minor tweaks that should make it easier for me to see what’s going on.
you can try to use vcodec
= copy
, this solved my issues with ffmpeg crashes.
@b2un0 It sounds like they're having the opposite problem, with ffmpeg not ever stopping.
HI, sporadically I experience a similar issue. In my case the camera complains in Home App that the maximum number of streams is reached, although no one is watching. When I then check the logs ffmpeg is still streaming. In this case only the restart of homebridge helps. Until now I couldn't find any way to reproduce this. This happens with iOS13 and OSX15.5. Maybe the Home App does not reliable send the stop stream request?
@california444 Thats what it’s looking like. Trying to think if there is another way to handle stopping FFmpeg if HomeKit never sends the message.
There is always the option of adding a maximum streaming time, but that feels like a pretty ugly kludge.
That’s what I expected to see, given your description of the issue. Good to have confirmation though.
Do the still images also stop updating when this happens as well?
What do you mean by that? I am closing the stream through Home App and I am also closing home app so there is no live view. Hell, I even turned off my phone (: . Even after a couple of hours without homebridge restart when I run
pgrep -f -a ffmpeg
I still get some results.How are you viewing the camera on your iOS device? I’m assuming the Home app, but third party apps can support cameras now too.
Home App
What version of iOS are you running? Are you on the iOS 14 beta?
IOS 13.6 Are you able to try the beta I pushed out and resubmit your logs? There have been no changes that should fix anything, but some minor tweaks that should make it easier for me to see what’s going on.
I have already installed the beta. (homebridge-camera-ffmpeg v2.3.1-beta.3) Like I did previously, I restarted the homebridge Launched HomeApp Opened up a stream for 1st cam. Closed the stream from home app. Closed the home app. Opened up the stream again for the 1st cam. (Failed to load this time) Here are the logs. homebridge.log
What do you mean by that? I am closing the stream through Home App and I am also closing home app so there is no live view.
I mean the little snapshots that update about every 10 seconds when you're looking at a room in the Home app.
What do you mean by that? I am closing the stream through Home App and I am also closing home app so there is no live view.
I mean the little snapshots that update about every 10 seconds when you're looking at a room in the Home app.
Ah sorry, the still images
Yeah, 2 of them stopped updating one of them updated just now.
It is weird. Let me say this again, this issue came up after I updated the plugin. Unfortunately, I don't remember from which version I updated.
I plan to go through the logic in older versions to see if they handled things any differently, I just haven't had the chance yet. I'm guessing you must have been using a pre-2.0.0 version, as nothing has changed significantly since then.
HI, sporadically I experience a similar issue. In my case the camera complains in Home App that the maximum number of streams is reached, although no one is watching. When I then check the logs ffmpeg is still streaming. In this case only the restart of homebridge helps. Until now I couldn't find any way to reproduce this. This happens with iOS13 and OSX15.5. Maybe the Home App does not reliable send the stop stream request?
This happens every time or occasionally? For me it happens all the time.
I’ve looked through the old code, and the only significant change I see is from 1.3.0 to 2.0.0 when we switched to bridged cameras instead of them needing to be separate devices. And I don’t believe there is a way back to the old way without switching away from bridged cameras.
We seem to be handling the disconnection in a similar way to other plugins with bridged cameras too, so I might check to see if I can find similar reports happening with any of them.
Just brainstorming a little here, I am able to detect the open UDP port with NMAP while the stream is running: sudo nmap -p [port used for srtp] -sU [client IP address]
. Perhaps I could add a config option to enable an optional check to see if the port is still open periodically, and kill ffmpeg if it isn't.
If anyone having this issue wants to try running the nmap command and letting me know if the port is still open after closing the video, that would help me decide whether this is a good idea.
You can get the IP and port numbers by enabling debug mode for the camera and looking for the line that starts with '[Camera Name] command: ffmpeg' right after you start the video. Look for the section of that line that looks like 'srtp://10.0.1.135:58720' for your IP and port number. I also just pushed a beta that drastically cuts down the amount of noise in debug mode, so that should help you find that line.
I’ve looked through the old code, and the only significant change I see is from 1.3.0 to 2.0.0 when we switched to bridged cameras instead of them needing to be separate devices. And I don’t believe there is a way back to the old way without switching away from bridged cameras.
We seem to be handling the disconnection in a similar way to other plugins with bridged cameras too, so I might check to see if I can find similar reports happening with any of them.
Do you think the problem might be originating from my homebridge installation? You know, I had to delete and readd cams due to this change and it is not like a clean installation. I also don't know how common is this problem? Can anyone try to replicate?
HI, sporadically I experience a similar issue. In my case the camera complains in Home App that the maximum number of streams is reached, although no one is watching. When I then check the logs ffmpeg is still streaming. In this case only the restart of homebridge helps. Until now I couldn't find any way to reproduce this. This happens with iOS13 and OSX15.5. Maybe the Home App does not reliable send the stop stream request?
This happens every time or occasionally? For me it happens all the time.
This happens only very occasionally, And it was also happening with v1.3...
@Salvora Everyone had to delete their old cameras from HomeKit during the upgrade to 2.0.0, so that’s not it. I wish I was able to replicate the problem, but I’ve been unable to.
A little bit update, I have cleared the homebridge cached accessories then did "Unpair Bridges / Cameras / TVs / External Accessories" also unpaired and re-paired homebridge again. The issue still persists.
I saw that you pushed another update and I updated to the latest. Tried again but still no change.
However, I noticed that when I open a stream for ipcam1 and try the pgrep -f -a ffmpeg
I first see this (I am guessing this is for still images):
27261 ffmpeg -rtsp_transport tcp -re -i rtsp://Homebridge:Homebridge@laxcamprolook.laxhome.org:554/1 -frames:v 1 -vf scale=480:270 -f image2 -
then I get these consistently while the stream is open:
27302 ffmpeg -rtsp_transport tcp -vcodec h264_mmal -re -i rtsp://Homebridge:Homebridge@laxcamscsi.laxhome.org/cam/realmonitor?channel=1&subtype=1 -map 0:0 -vcodec libx264 -pix_fmt yuv420p -r 25 -f rawvideo -preset ultrafast -tune zerolatency -vf scale=1280:720 -b:v 299k -bufsize 598k -maxrate 299k -payload_type 99 -ssrc 13869250 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params QG6NydxQOSzGYax9OsnosUlKWZRJuHefG0iUYR1m srtp://192.168.1.221:54180?rtcpport=54180&localrtcpport=54180&pkt_size=1316 -map 0:1 -acodec libfdk_aac -profile:a aac_eld -flags +global_header -f null -ar 16k -b:a 24k -bufsize 24k -ac 1 -payload_type 110 -ssrc 887564 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params WD0C8m7NqKs7BPVBHCFSyPQyeARhP+Gt8Mzd+y8P srtp://192.168.1.221:58833?rtcpport=58833&localrtcpport=58833&pkt_size=188
when I close the stream:
27302 ffmpeg -rtsp_transport tcp -vcodec h264_mmal -re -i rtsp://Homebridge:Homebridge@laxcamscsi.laxhome.org/cam/realmonitor?channel=1&subtype=1 -map 0:0 -vcodec libx264 -pix_fmt yuv420p -r 25 -f rawvideo -preset ultrafast -tune zerolatency -vf scale=1280:720 -b:v 299k -bufsize 598k -maxrate 299k -payload_type 99 -ssrc 13869250 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params QG6NydxQOSzGYax9OsnosUlKWZRJuHefG0iUYR1m srtp://192.168.1.221:54180?rtcpport=54180&localrtcpport=54180&pkt_size=1316 -map 0:1 -acodec libfdk_aac -profile:a aac_eld -flags +global_header -f null -ar 16k -b:a 24k -bufsize 24k -ac 1 -payload_type 110 -ssrc 887564 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params WD0C8m7NqKs7BPVBHCFSyPQyeARhP+Gt8Mzd+y8P srtp://192.168.1.221:58833?rtcpport=58833&localrtcpport=58833&pkt_size=188
27696 ffmpeg -rtsp_transport tcp -re -i rtsp://Homebridge:Homebridge@laxcamprolook.laxhome.org:554/1 -frames:v 1 -vf scale=480:270 -f image2 -
27302 ffmpeg -rtsp_transport tcp -vcodec h264_mmal -re -i rtsp://Homebridge:Homebridge@laxcamscsi.laxhome.org/cam/realmonitor?channel=1&subtype=1 -map 0:0 -vcodec libx264 -pix_fmt yuv420p -r 25 -f rawvideo -preset ultrafast -tune zerolatency -vf scale=1280:720 -b:v 299k -bufsize 598k -maxrate 299k -payload_type 99 -ssrc 13869250 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params QG6NydxQOSzGYax9OsnosUlKWZRJuHefG0iUYR1m srtp://192.168.1.221:54180?rtcpport=54180&localrtcpport=54180&pkt_size=1316 -map 0:1 -acodec libfdk_aac -profile:a aac_eld -flags +global_header -f null -ar 16k -b:a 24k -bufsize 24k -ac 1 -payload_type 110 -ssrc 887564 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params WD0C8m7NqKs7BPVBHCFSyPQyeARhP+Gt8Mzd+y8P srtp://192.168.1.221:58833?rtcpport=58833&localrtcpport=58833&pkt_size=188
27696 ffmpeg -rtsp_transport tcp -re -i rtsp://Homebridge:Homebridge@laxcamprolook.laxhome.org:554/1 -frames:v 1 -vf scale=480:270 -f image2 -
27302 ffmpeg -rtsp_transport tcp -vcodec h264_mmal -re -i rtsp://Homebridge:Homebridge@laxcamscsi.laxhome.org/cam/realmonitor?channel=1&subtype=1 -map 0:0 -vcodec libx264 -pix_fmt yuv420p -r 25 -f rawvideo -preset ultrafast -tune zerolatency -vf scale=1280:720 -b:v 299k -bufsize 598k -maxrate 299k -payload_type 99 -ssrc 13869250 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params QG6NydxQOSzGYax9OsnosUlKWZRJuHefG0iUYR1m srtp://192.168.1.221:54180?rtcpport=54180&localrtcpport=54180&pkt_size=1316 -map 0:1 -acodec libfdk_aac -profile:a aac_eld -flags +global_header -f null -ar 16k -b:a 24k -bufsize 24k -ac 1 -payload_type 110 -ssrc 887564 -f rtp -srtp_out_suite AES_CM_128_HMAC_SHA1_80 -srtp_out_params WD0C8m7NqKs7BPVBHCFSyPQyeARhP+Gt8Mzd+y8P srtp://192.168.1.221:58833?rtcpport=58833&localrtcpport=58833&pkt_size=188
27745 ffmpeg -rtsp_transport tcp -vcodec h264_mmal -re -i rtsp://Homebridge:Homebridge@laxcamdahua.laxhome.org/cam/realmonitor?channel=1&subtype=1 -frames:v 1 -vf scale=480:270 -f image2 -
Notice that when I was on the stream there was only 1 cam listed:
rtsp://Homebridge:Homebridge@laxcamscsi.laxhome.org/cam/realmonitor?channel=1&subtype=1
However, when I closed the stream I see other cams too.
rtsp://Homebridge:Homebridge@laxcamdahua.laxhome.org/cam/realmonitor?channel=1&subtype=1
rtsp://Homebridge:Homebridge@laxcamprolook.laxhome.org:554/1
It is weird because I have only opened a single cam. Why do I still see these?
Next I tried to remove the "videoProcessor": "ffmpeg", to see if the built-in ffmpeg fixes the problem. However, it didn't help. The only thing remaining to do is a clean install of raspian with homebridge of which I am reluctant to do.
I don’t see how reinstalling your OS would resolve this (though I am still stumped as to the cause).
Also, any lines that end in -f image2 -
are going to be used for taking screenshots. I only see one ‘stuck’ video FFmpeg instance, and that is process number 27302.
Also, can you try the nmap command I mentioned back in this comment: https://github.com/homebridge-plugins/homebridge-camera-ffmpeg/issues/651#issuecomment-659110469
If the port is closed, that gives me some possibilities to detect this state, though I’m not sure any I’ve come up with are too great.
Also, can you try the nmap command I mentioned back in this comment: #651 (comment)
If the port is closed, that gives me some possibilities to detect this state, though I’m not sure any I’ve come up with are too great. I installed nmap and while the stream is running I run that command.
It seems while the stream is running that port on the client side is open but while it is not running it is closed.
I have also a synology NAS and in order to replicate the issue I installed homebridge-ffmpeg on it with docker. Changed my config a little bit for NAS doesn't have HW acc. There is no problem on the NAS. The stream stops when I close it.
Another idea is to downgrade the ffmpeg and try to find out exactly which version caused this issue. Then we can move on from there.
Interesting that it works fine with your setup on different hardware. I can’t imagine what would be different.
You could try downgrading, but I’m guessing that it works on 1.3.0 and below but has the issue on 2.0.0 and up, since that was the only major change. And unfortunately, we cannot implement the 1.3.0 method with the current setup of bridged cameras.
Given that the port does close when it’s done, I could possibly write something to check the port state, but I can’t think of a way to do that without running Homebridge as root...
Allright, tried another thing. installed a second homebridge instance on my pi with hb-service install --user homebridgetwo --service-name homebridge-two --port 8400 used the same config as my previous one and checked if the issue still persists. There was no problem. I am guessing there is something wrong with my main homebridge instance. What is the problem though? I am more and more close to going yolo and making a clean install.
Well, dang. I’m completely stumped. Clearly something got mangled with your original install, but heck if I know what.
I guess it doesn’t make sense to do a codefix for this then though.
Well, dang. I’m completely stumped. Clearly something got mangled with your original install, but heck if I know what.
I guess it doesn’t make sense to do a codefix for this then though.
Yeah, it is very weird. It was working OK before update though. That is the thing that baffles me. If no one can replicate this I think this is my own problem. Guess I will do a clean raspian installation while I am at it. Thanks for the support
Yea, I guess we’ll close this out for now, and hope it doesn’t ever happen again.
A little bit update, I did a clean raspian installation. Totally clean. Installed the homebridge and I am stuck with the same problem again.
The rest is standard. I also used LTS node version this time.
Node.js Version v12.18.2 Npm Version v6.14.6
The only thing out of the norm for my homebridge installation is, it runs with sudo.
sudo usermod -aG sudo homebridge
sudo visudo /etc/sudoers
homebridge ALL=(ALL) NOPASSWD: ALL
Maybe some permission issue with the new version?
Well, darn, guess I’ll reopen this. There is definitely something going on here, and I was able to find a way to force the issue to happen locally, now I just need to figure out how to resolve this.
Well, darn, guess I’ll reopen this. There is definitely something going on here, and I was able to find a way to force the issue to happen locally, now I just need to figure out how to resolve this.
My money is on permission issues :D
The problem, as far as I can tell, is that there are some cases where Homebridge just never gets the notice that the stream has stopped, so it never closes FFmpeg.
I was able to force the issue by viewing a camera then kicking on airplane mode. After that, the FFmpeg process will run until I get on the box and manually kill it.
Hmm, What is weird is 1- This problem came up after the update 2- There was no problem when I created a second homebridge instance or use docker image. The only different thing from my normal setup was this was not using sudo. 3- Clean install latest Raspberry OS also gives this problem
I wonder if there are actually multiple causes of this then, and your cause is different than the other. This whole thing is a bit weird all around. @california444 did report seeing this issue occasionally under 1.3.0 though, so maybe it was just always there...
I wonder if there are actually multiple causes of this then, and your cause is different than the other. This whole thing is a bit weird all around. @california444 did report seeing this issue occasionally under 1.3.0 though, so maybe it was just always there...
Hmm, I didn't notice that before.
Guess I will wait a little bit for further testing and if I cannot find any solution. I will just create a second instance and run ffmpeg there as a workaround.
I have noticed that while I can recreate the issue on this plugin, homebridge-ring seems to have some mitigation for it. I’m looking at that code now to see if it can apply to this, and have reached out to that developer. Fingers crossed.
Weird thing again. I again created a second instance of homebridge to just move my cameras there but it is giving me the same problem. Apparently, I didn't test enough before. The only viable option is docker on syno nas but there is no HW acc. there.
I’m working on what should be a fix now. Should have a beta out this weekend.
I've put a fix for this into the new beta, you can install that with sudo npm install -g homebridge-camera-ffmpeg@beta --unsafe-perm
. Please let me know if this resolves your issues.
Hmm,
there is a need to install get-port module for this to work.
I installed with
sudo npm install -g get-port
I tried couple of times with different cameras.
It seems to be resolved. Stream stops when I close the stream from the home app and I can reconnect again but I will keep testing.
Great. Not sure why get-port didn’t automatically get pulled down, it’s marked as a dependency. I’ll look into that.
Got that fixed, made a minor mistake in the package.json, get-port should be installed automatically starting with the current beta.
Thanks for the fix
Just brainstorming a little here, I am able to detect the open UDP port with NMAP while the stream is running:
sudo nmap -p [port used for srtp] -sU [client IP address]
. Perhaps I could add a config option to enable an optional check to see if the port is still open periodically, and kill ffmpeg if it isn't.If anyone having this issue wants to try running the nmap command and letting me know if the port is still open after closing the video, that would help me decide whether this is a good idea.
You can get the IP and port numbers by enabling debug mode for the camera and looking for the line that starts with '[Camera Name] command: ffmpeg' right after you start the video. Look for the section of that line that looks like 'srtp://10.0.1.135:58720' for your IP and port number. I also just pushed a beta that drastically cuts down the amount of noise in debug mode, so that should help you find that line.
Did you implement this idea?
A similar idea. When configured properly, HomeKit sends a UDP ping back to Homebridge roughly every half second while the video is being streamed. I got that set up, and am now watching for those pings.
Describe The Bug: It's been a while since I updated the plugin. Maybe 2-3 months. Anyway, I have updated the plugin but it seems 3 of my cameras are not stable. After restarting homebridge I can view the livestream but if I close and try to open the live stream again, it loses the connection.
I checked the changelog and it seems now we have built-in ffmpeg. I added "videoProcessor": "ffmpeg", to get back to my old setup but it is no good. Additionally, after update connecting to my cams seems to be slower than before.
To Reproduce: Restart homebridge, go to homescreen and open up a camera livestream close the livestream try to open it again.
Expected behavior: Livestream should open again.
Logs:
I am getting above log occasionally. Sometimes there is no log output at all.
Homebridge Config:
Screenshots:
Environment: