Update for media_player.firetv fails: Log get several GB in one day

pipip commented 4 years ago

The problem

Home Assistant including FireTV (androidtv) works fine, so the setup in general seems fine. At some point at night (I assume when FireTV goes into sleep mode?), the log gets filled up and CPU raises slowly until 100% due to the heavy log file.

Environment

Home Assistant Core release with the issue: 0.114.3
Last working Home Assistant Core release (if known): unknown
Operating environment (OS/Container/Supervised/Core): Core (on Android via Termux)
Integration causing this issue: androidtv
Link to integration documentation on our website: https://www.home-assistant.io/integrations/androidtv

Problem-relevant `configuration.yaml`

# FireTV
  - platform: androidtv
    name: FireTV
    host: 192.168.1.xx
    exclude_unnamed_apps: true
    apps:
      com.amazon.tv.launcher: "FireTV Home"
      com.amazon.avod: "Amazon Video"
      com.einsundeinstv.player: "1&1 TV"
      com.dazn: "DAZN"

Traceback/Error logs

2020-08-24 07:40:03 WARNING (MainThread) [asyncio] socket.send() raised exception.
2020-08-24 07:40:03 ERROR (MainThread) [homeassistant.helpers.entity] Update for media_player.firetv fails
Traceback (most recent call last):
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/helpers/entity.py", line 263, in async_update_ha_state
    await self.async_device_update()
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/helpers/entity.py", line 454, in async_device_update
    await self.async_update()  # type: ignore
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/components/androidtv/media_player.py", line 363, in _adb_exception_catcher
    return await func(self, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/components/androidtv/media_player.py", line 738, in async_update
    state, self._current_app, running_apps = await self.aftv.update(
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/firetv/firetv_async.py", line 67, in update
    screen_on, awake, wake_lock_size, current_app, media_session_state, running_apps = await self.get_properties(get_running_apps=get_running_apps, lazy=lazy)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/firetv/firetv_async.py", line 111, in get_properties
    output = await self._adb.shell(constants.CMD_FIRETV_PROPERTIES_LAZY_RUNNING_APPS)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/adb_manager/adb_manager_async.py", line 314, in shell
    return await self._adb.shell(cmd)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 379, in shell
    return await self._service(b'shell', command.encode('utf8'), transport_timeout_s, read_timeout_s, timeout_s, decode)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 297, in _service
    return b''.join([x async for x in self._streaming_command(service, command, adb_info)]).decode('utf8')
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 297, in <listcomp>
    return b''.join([x async for x in self._streaming_command(service, command, adb_info)]).decode('utf8')
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 923, in _streaming_command
    await self._open(b'%s:%s' % (service, command), adb_info)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 701, in _open
    await self._send(msg, adb_info)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 892, in _send
    await self._transport.bulk_write(msg.pack(), adb_info.transport_timeout_s)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/transport/tcp_transport_async.py", line 142, in bulk_write
    await asyncio.wait_for(self._writer.drain(), timeout)
  File "/data/data/com.termux/files/usr/lib/python3.8/asyncio/tasks.py", line 483, in wait_for
    return fut.result()
  File "/data/data/com.termux/files/usr/lib/python3.8/asyncio/streams.py", line 375, in drain
    raise exc
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/helpers/entity.py", line 263, in async_update_ha_state
    await self.async_device_update()
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/helpers/entity.py", line 454, in async_device_update
    await self.async_update()  # type: ignore
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/components/androidtv/media_player.py", line 363, in _adb_exception_catcher
    return await func(self, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/components/androidtv/media_player.py", line 738, in async_update
    state, self._current_app, running_apps = await self.aftv.update(
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/firetv/firetv_async.py", line 67, in update
    screen_on, awake, wake_lock_size, current_app, media_session_state, running_apps = await self.get_properties(get_running_apps=get_running_apps, lazy=lazy)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/firetv/firetv_async.py", line 111, in get_properties
    output = await self._adb.shell(constants.CMD_FIRETV_PROPERTIES_LAZY_RUNNING_APPS)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/adb_manager/adb_manager_async.py", line 314, in shell
    return await self._adb.shell(cmd)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 379, in shell
    return await self._service(b'shell', command.encode('utf8'), transport_timeout_s, read_timeout_s, timeout_s, decode)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 297, in _service
    return b''.join([x async for x in self._streaming_command(service, command, adb_info)]).decode('utf8')
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 297, in <listcomp>
    return b''.join([x async for x in self._streaming_command(service, command, adb_info)]).decode('utf8')
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 923, in _streaming_command
    await self._open(b'%s:%s' % (service, command), adb_info)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 701, in _open
    await self._send(msg, adb_info)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/adb_device_async.py", line 892, in _send
    await self._transport.bulk_write(msg.pack(), adb_info.transport_timeout_s)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/adb_shell/transport/tcp_transport_async.py", line 142, in bulk_write
    await asyncio.wait_for(self._writer.drain(), timeout)
  File "/data/data/com.termux/files/usr/lib/python3.8/asyncio/tasks.py", line 483, in wait_for
    return fut.result()
  File "/data/data/com.termux/files/usr/lib/python3.8/asyncio/streams.py", line 375, in drain
    raise exc
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/helpers/entity.py", line 263, in async_update_ha_state
    await self.async_device_update()
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/helpers/entity.py", line 454, in async_device_update
    await self.async_update()  # type: ignore
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/components/androidtv/media_player.py", line 363, in _adb_exception_catcher
    return await func(self, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/components/androidtv/media_player.py", line 738, in async_update
    state, self._current_app, running_apps = await self.aftv.update(
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/firetv/firetv_async.py", line 67, in update
    screen_on, awake, wake_lock_size, current_app, media_session_state, running_apps = await self.get_properties(get_running_apps=get_running_apps, lazy=lazy)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/firetv/firetv_async.py", line 111, in get_properties
    output = await self._adb.shell(constants.CMD_FIRETV_PROPERTIES_LAZY_RUNNING_APPS)
  File "/data/data/com.termux/files/home/.homeassistant/deps/lib/python3.8/site-packages/androidtv/adb_manager/adb_manager_async.py", line 314, in shell
    return await self._adb.shell(cmd)
... 
...

Additional information

The provided error log gets written over and over again. Several GB a day if I do not use logrotate. Restart of home assistant solves the problem until at some point it starts all over again.

probot-home-assistant[bot] commented 4 years ago

androidtv documentation androidtv source _{^{(message by IssueLinks)}}

JeffLIrion commented 4 years ago

It looks like maybe the traceback is incomplete because I see raise exc a couple times but I don't see exactly what that exc exception is. For example:

  File "/data/data/com.termux/files/usr/lib/python3.8/asyncio/streams.py", line 375, in drain
    raise exc
  File "/data/data/com.termux/files/usr/lib/python3.8/site-packages/homeassistant/helpers/entity.py", line 263, in async_update_ha_state
    await self.async_device_update()

If you can post a log showing what this exception is, then I can handle it.

pipip commented 4 years ago

@JeffLIrion Thanks for your fast answer. Hmm, the exception is cut off in all my log files. This might be due to pm2 logging the errors. I have disabled the standard home assistant log file since this was filling up my sd card in hours (log file was several GB). I will try to get the full exception...

JeffLIrion commented 4 years ago

It would be interesting to see the full traceback, but it's OK if you can't get it. I submitted a fix that will work no matter what type of exception it encounters.

home-assistant / core