Core: 0.91.0 - Camera stream recording getting stuck

[droopanu]

Home Assistant release with the issue:
0.91.0

Last working Home Assistant release (if known):
NA

Operating environment (Hass.io/Docker/Windows/etc.):
VirtualEnv on NUC

Component/platform:
https://www.home-assistant.io/components/stream/

Description of problem:
From time to time the camera streaming would not start and complain that the steam is already recording.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

  - platform: generic
    name: DaFang_stream
    username: !dafang_user
    password: !dafang_password
    authentication: basic
    still_image_url: https://192.168.86.50/cgi-bin/currentpic.cgi
    stream_source: rtsp://192.168.86.50:8554/unicast  
    verify_ssl: false
    scan_interval: 5    

Traceback (if applicable):

##Stream recording start (via script) 
2019-04-05 10:07:18 WARNING (SyncWorker_22) [homeassistant.components.python_script.record_camera_smart_noffmpeg.py] Start Recording {'entity_id': 'camera.dafang_stream', 'filename': '/tmp/video_20190405100718219019cameradafangstreamOutsideGarageMotion.mp4', 'duration': 20, 'lookback': 20}

##Another recording triggered, error returned:
2019-04-05 10:13:54 WARNING (SyncWorker_25) [homeassistant.components.python_script.record_camera_smart_noffmpeg.py] Start Recording {'entity_id': 'camera.dafang_stream', 'filename': '/tmp/video_20190405101354437809cameradafangstreamOutsideGarageMotion.mp4', 'duration': 20, 'lookback': 20}
2019-04-05 10:13:54 ERROR (MainThread) [homeassistant.core] Error executing service <ServiceCall camera.record (c:7b5adf2a7c664a598d92aa06a4ed916d): entity_id=['camera.dafang_stream'], filename=<homeassistant.helpers.template.Template object at 0x7f49607250f0>, duration=20, lookback=20>
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1147, in _safe_execute
    await self._execute_service(handler, service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity_component.py", line 188, in handle_service
    self._platforms.values(), func, call, service_name
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 314, in entity_service_call
    future.result()  # pop exception if have
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 330, in _handle_service_platform_call
    await func(entity, data)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/camera/__init__.py", line 677, in async_handle_record_service
    blocking=True, context=call.context)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1138, in async_call
    self._execute_service(handler, service_call))
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 114, in async_record
    await async_handle_record_service(hass, call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 217, in async_handle_record_service
    .format(recorder.video_path))
homeassistant.exceptions.HomeAssistantError: Stream already recording to /tmp/video_20190405100718219019cameradafangstreamOutsideGarageMotion.mp4!


##another one
2019-04-05 10:14:28 WARNING (SyncWorker_16) [homeassistant.components.python_script.record_camera_smart_noffmpeg.py] Start Recording {'entity_id': 'camera.dafang_stream', 'filename': '/tmp/video_20190405101428775627cameradafangstreamOutsideGarageMotion.mp4', 'duration': 20, 'lookback': 20}
2019-04-05 10:14:28 ERROR (MainThread) [homeassistant.core] Error executing service <ServiceCall camera.record (c:8d3e9ecdbb624c228075f1f73dbc1baf): entity_id=['camera.dafang_stream'], filename=<homeassistant.helpers.template.Template object at 0x7f48743e5240>, duration=20, lookback=20>
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1147, in _safe_execute
    await self._execute_service(handler, service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity_component.py", line 188, in handle_service
    self._platforms.values(), func, call, service_name
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 314, in entity_service_call
    future.result()  # pop exception if have
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 330, in _handle_service_platform_call
    await func(entity, data)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/camera/__init__.py", line 677, in async_handle_record_service
    blocking=True, context=call.context)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1138, in async_call
    self._execute_service(handler, service_call))
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 114, in async_record
    await async_handle_record_service(hass, call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 217, in async_handle_record_service
    .format(recorder.video_path))
homeassistant.exceptions.HomeAssistantError: Stream already recording to /tmp/video_20190405100718219019cameradafangstreamOutsideGarageMotion.mp4!

2019-04-05 10:17:26 WARNING (SyncWorker_21) [homeassistant.components.python_script.record_camera_smart_noffmpeg.py] Start Recording {'entity_id': 'camera.dafang_stream', 'filename': '/tmp/video_20190405101726592134cameradafangstreamOutsideGarageMotion.mp4', 'duration': 20, 'lookback': 20}
2019-04-05 10:17:26 WARNING (SyncWorker_21) [homeassistant.components.python_script.record_camera_smart_noffmpeg.py] Sleeping 60
2019-04-05 10:17:26 ERROR (MainThread) [homeassistant.core] Error executing service <ServiceCall camera.record (c:f3318128efe84cabbcb45d8104257676): entity_id=['camera.dafang_stream'], filename=<homeassistant.helpers.template.Template object at 0x7f4878782b70>, duration=20, lookback=20>
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1147, in _safe_execute
    await self._execute_service(handler, service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity_component.py", line 188, in handle_service
    self._platforms.values(), func, call, service_name
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 314, in entity_service_call
    future.result()  # pop exception if have
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 330, in _handle_service_platform_call
    await func(entity, data)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/camera/__init__.py", line 677, in async_handle_record_service
    blocking=True, context=call.context)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1138, in async_call
    self._execute_service(handler, service_call))
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 114, in async_record
    await async_handle_record_service(hass, call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 217, in async_handle_record_service
    .format(recorder.video_path))
homeassistant.exceptions.HomeAssistantError: Stream already recording to /tmp/video_20190405100718219019cameradafangstreamOutsideGarageMotion.mp4!

Additional information:

[hunterjm]

This is intended. Currently you can not record the same stream to multiple files at the same time. You need to wait for the previous recording to complete first.

[droopanu]

The issue is that I start a record for 20 seconds with 20 seconds lookback, and 10 minutes later it still tells me that it can not record, as it's still recording....

Look at the timestaps:

**2019-04-05 10:07:18** WARNING (SyncWorker_22) [homeassistant.components.python_script.record_camera_smart_noffmpeg.py] Start Recording {'entity_id': 'camera.dafang_stream', 'filename': '/tmp/**video_20190405100718219019cameradafangstreamOutsideGarageMotion**.mp4', **'duration': 20, 'lookback': 20}**

**2019-04-05 10:17:26 ERROR** (MainThread) [homeassistant.core] Error executing service <ServiceCall camera.record (c:f3318128efe84cabbcb45d8104257676): entity_id=['camera.dafang_stream'], filename=<homeassistant.helpers.template.Template object at 0x7f4878782b70>, duration=20, lookback=20>
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1147, in _safe_execute
    await self._execute_service(handler, service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity_component.py", line 188, in handle_service
    self._platforms.values(), func, call, service_name
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 314, in entity_service_call
    future.result()  # pop exception if have
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/service.py", line 330, in _handle_service_platform_call
    await func(entity, data)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/camera/__init__.py", line 677, in async_handle_record_service
    blocking=True, context=call.context)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1138, in async_call
    self._execute_service(handler, service_call))
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/core.py", line 1160, in _execute_service
    await handler.func(service_call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 114, in async_record
    await async_handle_record_service(hass, call)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/stream/__init__.py", line 217, in async_handle_record_service
    .format(recorder.video_path))
homeassistant.exceptions.HomeAssistantError: Stream already recording to /tmp/**video_20190405100718219019cameradafangstreamOutsideGarageMotion**.mp4!

[hunterjm]

Oh. That is interesting. I missed it the first time around. Will need to look further in to it.

[droopanu]

Is there any debugging I could turn on to get you better info? :D

[way2many]

Just tested the new feature and on the first try I get the same problem.

[helto4real]

I can verify I get the same error. Exactly same setup with dafang camera and same settings.

[hunterjm]

So I can only reproduce this issue if a stream is actively being recorded, which is intended behavior. After waiting until after the previous recording is completed (file exists in output folder), I am able to call the service again with no problem.

@droopanu - It looks like you are calling this with a script, that also has a sleep in there. Can you post your script so I can try to reproduce the error?

[rtenklooster]

Having the same issues here. 6 recordings went okay but I noticed the lookback function did not work.
I have modified the recording time and set lookback to 5 seconds, after that the same error appeared when trying to record from the home assistant GUI.

No file was saved so I had to restart HA to make it work again. Same command now worked without problems.

Is the lookback function working for you? I would love to see this work!

[hunterjm]

The Preload Stream option is required for lookback to work, as mentioned in the docs.

[rtenklooster]

I have the preload option enabled. However it only starts recording one or two seconds after I submit the request with lookback 10 as parameter.
[Image]

Outlook voor iOShttps://aka.ms/o0ukef downloaden

---

Van: Jason Hunter [e-mail]
Verzonden: zondag, april 7, 2019 12:54 AM
Aan: home-assistant/home-assistant
CC: Richard; Comment
Onderwerp: Re: [home-assistant/home-assistant] 0.91.0 - Camera stream recording getting stuck (#22741)

The Preload Stream option is required for lookback to work, as mentioned in the docs.

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHubhttps://github.com/home-assistant/home-assistant/issues/22741#issuecomment-480543951, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AGNMwso_hejGIvVqf4ZpJEeupE1GVyWsks5veSWIgaJpZM4cdv1_.

[droopanu]

@hunterjm thank you for looking into this issue.
I have a python script that is triggered whenever certain sensors are triggered (door, motion, tensorflow), collects the required data, records a video and sends the images and videos via telegram. See attached.
But I don't think teh script is the issue. It looks more like a weird race condition. Maybe when too many record functions are called for the same camera ...

Funny enough, saturday morning the record function was stuck in the same situation (could not record anything new), restarted hass and it's been going on without any issues since. Could not reproduce it any more.

PS. I must say that the camera stream record and tensorflow are the two most awesome homeassistant features. :) Thank you!

Python script: (had to rename it from .py to .txt as it would not allow me to upload .py)
record_camera.txt

[droopanu]

I think figured out how to reproduce the issue.

Today, after almost a week, the issue happened again, and I was not able to record anything from a certain stream until I restarted home assistant. The only thing I did today, I moved the camera from one wifi access point to another.

So I realized that the issue might be caused by connectivity issues. So I started a stream record, rebooted the dafang camera (could also block the wifi access for a minute or so) and it got stuck again...

Hope this helps narrow down the issue.

[wilfredsmit]

22591

[BluGeni]

I have the same setup and it is working for me. I still get the errors about headers and stream already recording, but it still records the next clip if I wait 30 seconds. I think dafang has a very low cooldown between motion triggers which is why the stream already recording error is present.

[droopanu]

@hunterjm: have you managed to reproduce the issue?

I'm still getting the stuck issue and have to restart my homeassistant a few times a day to get it working again.

[droopanu]

I did more digging and looks like the issue is in the pyav/ffmpeg.
When manually running ffmpeg and restarting the camera, ffmpeg hangs, just like in the hass stream implementation, and I need to kill it.
The solution is to add stimeout option. This makes ffmpeg exit on tcp failure.

This solution only works when using tcp transport for rtsp.

I actually managed to fix it in homeassistant by adding the following to "lib/python3.6/site-packages/homeassistant/components/stream/__init__.py:

    # For RTSP streams, prefer TCP
    if isinstance(stream_source, str) \
            and stream_source[:7] == 'rtsp://' and not options:
        options['rtsp_flags'] = 'prefer_tcp'
+        options['stimeout'] = '5000000'

This means that next time the camera dies, the stream will also die and next time it's launched the lookback will not be available, but at least it does not require a full homeassistant restart.

Also, it might break cameras that can only use UDP for RTSP streaming .... Someone would need to test it

Cheers,
Liviu

[hunterjm]

@droopanu - thanks for all your work on that! Would you like to open a PR against Dev to get credit for your work? We only use TCP connections for RTSP anyway (prefer tcp option apparently doesn’t actually fallback to UDP), so i wouldn’t worry about that part.

[droopanu]

Let me see, I've never done a PR :D

Would be nice to have the streaming component automatically restart the streaming when it stops if the preloading is enabled.

[droopanu]

@hunterjm Do I need to do anything else for the PR to be merged? :)

[hunterjm]

@hunterjm Do I need to do anything else for the PR to be merged? :)

Tag me in it ;)

[cholek3]

I had similar issue with Stream, and I found out, that you need at least 5 seconds before you can call camera.record service again. In my case, I have PIR sensor triggering camera.record service with a duration of 20 seconds. If another movement was triggered between 20 up to 25th second, there was an error with "Camera stream is already recording". I simply extended PIR trigger time above 25 seconds and now it seems to be ok.

[RestOp]

Same error since year. I get
Call-service API error. Error Message: Stream already recording to XXX
It hangs, write no files more till i restart HA.

[sandos]

I am also seeing the same issue here. Might not be the same exact one but it does manifest in the same way:

homeassistant.exceptions.HomeAssistantError: Stream already recording to /media/2020-10-16--20:58:54.mp4!
File "/usr/src/homeassistant/homeassistant/components/stream/__init__.py", line 114, in async_record
await async_handle_record_service(hass, call)
File "/usr/src/homeassistant/homeassistant/components/stream/__init__.py", line 226, in async_handle_record_service
raise HomeAssistantError(f"Stream already recording to {recorder.video_path}!")
homeassistant.exceptions.HomeAssistantError: Stream already recording to /media/2020-10-16--20:58:54.mp4!

Also when this happens the actual camera view gets stuck, too, looping the same content over and over.

[RestOp]

Might not be the same exact one but it does manifest in the same way

Same

[ruimarinho]

I am experiencing the same problem with a UniFi Video setup and HASS 0.116.4.

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/automation/__init__.py", line 426, in async_trigger
    await self.action_script.async_run(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 944, in async_run
    await asyncio.shield(run.async_run())
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 198, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 206, in _async_step
    await getattr(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 413, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1315, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1350, in _execute_service
    await handler.func(service_call)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service
    await self.hass.helpers.service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 459, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 655, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 490, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/camera/__init__.py", line 762, in async_handle_record_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1315, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1350, in _execute_service
    await handler.func(service_call)
  File "/usr/src/homeassistant/homeassistant/components/stream/__init__.py", line 114, in async_record
    await async_handle_record_service(hass, call)
  File "/usr/src/homeassistant/homeassistant/components/stream/__init__.py", line 226, in async_handle_record_service
    raise HomeAssistantError(f"Stream already recording to {recorder.video_path}!")

[sandos]

There seems to be incoming changes from #42277 related to socket timeouts, so with some luck that will fix this bug as well!