Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

LivestreamNotRunningError Start of livestream for device T8200N0XXXXXXXXX was not also requested by this client #21

Closed
conorlap opened this issue Aug 18, 2021 · 10 comments
Assignees
Labels

Comments

@conorlap
Copy link

Describe the bug

I've set-up a script in Home Assistant that calls 'start_livestream' targeted at my Eufy 2k Wired doorbell, however most of the time when I trigger this script I get the below error in bropat/eufy-security-ws logs:

2021-08-18 14:32:15.041  ERROR Message error 
 LivestreamNotRunningError  Start of livestream for device T8200N0XXXXXXXXX was not also requested by this client
details:
{
  name: 'LivestreamNotRunningError'

�������
m
error stack:
• message_handler.ts:139 handle
    src/lib/device/message_handler.ts:139:31
• server.ts:46 device
    src/lib/server.ts:46:34
• server.ts:98 receiveMessage
    src/lib/server.ts:98:58
• server.ts:57 <anonymous>
    src/lib/server.ts:57:53
• events.js:400 emit
    events.js:400:28
• websocket.js:1009 receiverOnMessage
    node_modules/ws/lib/websocket.js:1009:20
• events.js:400 emit
    events.js:400:28
• receiver.js:522 dataMessage
    node_modules/ws/lib/receiver.js:522:14
• receiver.js:440 getData
    node_modules/ws/lib/receiver.js:440:17
• receiver.js:148 startLoop

Occasionally it does work but mostly not. The stream always seems to start when the docker (bropat/eufy-security-ws) is restarted - in fact I've noticed that the doorbell seems to automatically start streaming as soon as bropat/eufy-security-ws is started. Because of this, maybe I can't always properly STOP the stream using Home Assistant as the "start stream" command didn't come from Home Assistant...? aka "was not also requested by this client" from the error log.

I've even tried calling 'stop_livestream' , waiting a few seconds and then calling 'start_livestream' but still same issue and no stream starts.

Expected behaviour
I expect the livestream to start when triggered so that I can view the video stream on my Home Assistant dashboard whenever I wish.

Versions:

I also have encountered the below error in the logs when attempting to start livestream:


2021-08-16 20:15:31.029  WARN Station T8200N0XXXXXXXXX - Result data for command not received 
{
  message: {
    sequence: 34,
    command_type: 1700,
    nested_command_type: 1000,
    channel: 0,
    data: <Buffer d1 00 00 22 58 5a 59 48 a4 06 74 01 00 00 01 00 00 00 00 00 7b 22 63 6f 6d 6d 61 6e 64 54 79 70 65 22 3a 31 30 30 30 2c 22 64 61 74 61 22 3a 7b 22 61 ... 342 more bytes>,
    retries: 1,
    acknowledged: true,
    return_code: -133,
    timeout: Timeout {
      _idleTimeout: 20000,
      _idlePrev: null,
      _idleNext: null,
      _idleStart: 217867957,
      _onTimeout: [Function (anonymous)],
      _timerArgs: undefined,
      _repeat: null,
      _destroyed: false,
      [Symbol(refed)]: true,
      [Symbol(kHasPrimitive)]: false,
      [Symbol(asyncId)]: 27024870,
      [Symbol(triggerId)]: 5643274
    }
  }
}
@bropat
Copy link
Owner

bropat commented Aug 18, 2021

@conorlap

I cannot follow this statement

I've set-up a script in Home Assistant that calls 'start_livestream' targeted at my Eufy 2k Wired doorbell, however most of the time when I trigger this script I get the below error in bropat/eufy-security-ws logs:

because the error LivestreamNotRunningError is only triggered if you try to stop the livestream from a websocket client connection that has not executed a start livestream command:

throw new LivestreamNotRunningError(`Start of livestream for device ${serialNumber} was not also requested by this client`);

To understand exactly what is happening, you have to activate the debug mode of eufy-security-ws. This is activated by setting the DEBUG variable:

https://github.com/bropat/eufy-security-ws#docker


in fact I've noticed that the doorbell seems to automatically start streaming as soon as bropat/eufy-security-ws is started

eufy-security-ws starts the stream ONLY on request. There is no automatism.

I think the problem lies in the client-side implementation:

https://github.com/fuatakgun/eufy_security/blob/a08b547007e90947b1b966b81aff19a846f6e622/custom_components/eufy_security/camera.py#L129-L131

And maybe the rest too.

@bropat bropat self-assigned this Aug 18, 2021
@conorlap
Copy link
Author

I've sent you the log files via Home Assistant forum PM.

Please note I am in BST timezone but the logs are reporting GMT time, so I've set my times back 1 hour below. The below two scenarios relate to the two separate log files I sent you.

Scenario 1:

8.02pm - the stream works after restarting Home Assistant & Eufy Security dockers and I call Eufy Security: Start Live Stream over P2P within Home Assistant
8.08pm - automatically stops streaming
8.10pm - I try to trigger start live stream again, nothing happens.
8.11pm - I send Eufy Security: Stop Live Stream over P2P command
30 seconds later: I sent start livestream command, nothing happens.
8.14pm - I sent livestream command, nothing happens.

Scenario 2:

8.34pm - the stream works after restarting home assistant & eufy security dockers and I call Eufy Security: Start Live Stream over P2P
30 seconds later: I call Eufy Security: Stop Live Stream over P2P, it looks like it stops for a split second then starts back.
Repeat the stop command a few times, still does not fully stop - the stream only seems to stop by itself after several minutes.

Also, regarding

I cannot follow this statement

I've set-up a script in Home Assistant that calls 'start_livestream' targeted at my Eufy 2k Wired doorbell, however most of the time when I trigger this script I get the below error in bropat/eufy-security-ws logs:

This was my mistake, I was calling stop livestream command - not start!

@fuatakgun
Copy link
Contributor

Hi all,

When HA is starting up, integration is checking live stream state and if it is running, it sends a message as start_livestream so that it can get video chunks.

Live stream can be started independent of HA, it can be always up and running independent of HA. I see some cases users are recording to NAS, so it is always running but this was an example of RTSP, not sure if it is possible with P2P.

So, back to story, if a client (this can be HA or mobile app) initiated a p2p live stream, it can only be stopped by initiator.

When you get this error, it means something else started it.

@bropat what is the correct way to identify clients triggered start events? Can we inform user on this?

@fuatakgun
Copy link
Contributor

One thing to add; if you enable preload stream on HA, it will try to start streaming automatically when HA is starting up, but you should be able to stop it because you are the initiator client here.

@bropat
Copy link
Owner

bropat commented Aug 19, 2021

@fuatakgun

I'll explain it better with an example.

Preface:

  • There are 4 clients that are connected via the websocket interface.
  • All of them start/stop the livestream of the same device.

Example:

  1. Client 1 has started the livestream, this leads to the effective start of the p2p livestream
  2. Client 2 has started the livestream, the livestream is already running, so this client only receives the start event and the events of the video/audio data.
  3. Client 3 tries to stop the livestream and since it has never executed a start livestream, it receives the error LivestreamNotRunningError .
  4. Client 4 starts the livestream (same as point 2).
  5. Client 4 stops the livestream. Since other clients have started the same livestream, it receives the stop event and no more video/audio data, but the actual p2p livestream is not stopped.
  6. Client 1 loses the websocket connection. As another client has started the same livestream, the p2p stream continues (if this was the last client to start the livestream, the p2p stream would effectively be stopped).
  7. Client 2 stops the livestream and since it is the last client that started the same livestream, the p2p livestream is effectively stopped.

@conorlap
Copy link
Author

One thing to add; if you enable preload stream on HA, it will try to start streaming automatically when HA is starting up, but you should be able to stop it because you are the initiator client here.

I don't have preload stream enabled.

I notice that if I open the Home Assistant app (Android), and call the stop stream service it stops the feed - but only for approx 8-10 seconds before automatically starting it again. I also called the service from my browser (macOS/Firefox) on my laptop while viewing the Android app dashboard (where all my lovelace cards are etc) and it stops it for 8-10 seconds before automatically starting it again.

However, on my laptop web browser, if I call the Eufy Security: Stop Live Stream over P2P service and then go back to my dashboard it seems to instantly start the feed again with no 8-10 second delay. Same result if I call the stop live stream service from my Android app - as long as the dashboard is in focus on the laptop web browser, it seems to automatically re-start the stream instantly with no 8-10 second delay.

After a few minutes the stream stops and then cannot be triggered again with the Eufy Security: Start Live Stream over P2P service command. When this happens, the only way I can get a live stream video feed again is by restarting @bropat 's docker container.

bropat added a commit that referenced this issue Aug 19, 2021
Updated dependency eufy-security-client, tslog and ws
@bropat
Copy link
Owner

bropat commented Aug 19, 2021

@conorlap Try version 0.4.2 and let me know.

@conorlap
Copy link
Author

Getting the following error from @fuatakgun 's HA integration in the HA logs:

2021-08-19 17:19:54 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry 192.168.0.22 for eufy_security
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/config_entries.py", line 293, in async_setup
result = await component.async_setup_entry(hass, self) # type: ignore
File "/config/custom_components/eufy_security/__init__.py", line 44, in async_setup_entry
await coordinator.initialize_ws()
File "/config/custom_components/eufy_security/coordinator.py", line 94, in initialize_ws
raise Exception("Start Listening was not completed in timely manner")
Exception: Start Listening was not completed in timely manner

@conorlap
Copy link
Author

I did a second restart of Home Assistant container and it worked when I triggered start livestream, but as soon as I triggered the stop livestream it crashed - it's saying it's Streaming - p2p under state in HA but the bropat docker gives the following:

2021-08-19 17:16:06.458  ERROR Message error 
 LivestreamNotRunningError  Livestream for device T8200N00XXXXXXX could not be stopped, because it is not running
details:
{
  name: 'LivestreamNotRunningError'
�������
m
error stack:
• message_handler.ts:145 handle
    src/lib/device/message_handler.ts:145:31
• server.ts:46 device
    src/lib/server.ts:46:34
• server.ts:98 receiveMessage
    src/lib/server.ts:98:58
• server.ts:57 <anonymous>
    src/lib/server.ts:57:53
• events.js:400 emit
    events.js:400:28
• websocket.js:1009 receiverOnMessage
    node_modules/ws/lib/websocket.js:1009:20
• events.js:400 emit
    events.js:400:28
• receiver.js:522 dataMessage
    node_modules/ws/lib/receiver.js:522:14
• receiver.js:440 getData
    node_modules/ws/lib/receiver.js:440:17
• receiver.js:148 startLoop
    node_modules/ws/lib/receiver.js:148:22

While aler9/rtsp-simple-server container gives the following in logs:

2021/08/19 17:16:05 I [1/1] [RTSP] [conn 192.168.0.22:43180] ERR: read tcp 192.168.0.22:8554->192.168.0.22:43180: i/o timeout
2021/08/19 17:16:05 I [0/0] [RTSP] [conn 192.168.0.22:43180] closed
2021/08/19 17:16:05 I [0/0] [RTSP] [conn 192.168.0.22:43282] closed
2021/08/19 17:16:05 I [0/0] [RTSP] [session 146959958] closed
2021/08/19 17:16:05 I [0/0] [path eufy_security-T8200N00XXXXXXX] destroyed
2021/08/19 17:16:05 I [0/0] [RTSP] [session 613266367] closed
2021/08/19 17:16:06 I [0/0] [RTSP] [conn 192.168.0.22:43292] opened
2021/08/19 17:16:06 I [0/0] [path eufy_security-T8200N00XXXXXXX] created
2021/08/19 17:16:06 I [0/0] [RTSP] [conn 192.168.0.22:43292] ERR: no one is publishing to path 'eufy_security-T8200N0020080003'
2021/08/19 17:16:06 I [0/0] [RTSP] [conn 192.168.0.22:43292] closed

@bropat
Copy link
Owner

bropat commented Aug 19, 2021

@conorlap On my side I have tested everything flawlessly. I think we have to wait for @fuatakgun now.

@bropat bropat closed this as completed Sep 4, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants