search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.8k stars 30.89k forks source link

Problem with dlna_dmr in 0.76.0b5 #16016

Closed DavidFW1960 closed 6 years ago

DavidFW1960 commented 6 years ago

0.76.0b5 Home Assistant release with the issue:

Last working Home Assistant release (if known): 0.76.0b2 (I think)

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

Hassio on Raspbian (Dale3h script) on Pi3B Component/platform:

Description of problem:

Log being flooded with below errors and components VERY slow to be detected.. one still not detected after an hour.

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

discovery:
  enable:
    - dlna_dmr

Traceback (if applicable):

 17 2018 17:33:46 GMT+1000 (Australian Eastern Standard Time)

Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 234, in async_update_ha_state
    entity_picture = self.entity_picture
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/media_player/__init__.py", line 930, in entity_picture
    image_hash = self.media_image_hash
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/media_player/__init__.py", line 535, in media_image_hash
    url = self.media_image_url
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/media_player/dlna_dmr.py", line 354, in media_image_url
    return self._device.media_image_url
  File "/usr/local/lib/python3.6/site-packages/async_upnp_client/dlna.py", line 479, in media_image_url
    for res in item.resources:
AttributeError: 'VideoItem' object has no attribute 'resources'

Additional information: Hassio on Raspbian (Dale3h script) on Pi3B @balloob said to raise an issue and tag @StevenLooman as well

StevenLooman commented 6 years ago

Thank you for reporting, I'll look into it.

StevenLooman commented 6 years ago

Shot myself in the foot I guess. Fixed in python-didl-lite, upgraded dependency in async_upnp_client, in turn, upgraded dependency in home-assistant.

DavidFW1960 commented 6 years ago

0.76.1 Not getting floods of errors now and my osmc vero4 is coming up but my onkyo is still not showing and I'm seeing this in the log as well:

Log Details (WARNING) Mon Aug 20 2018 09:18:17 GMT+1000 (Australian Eastern Standard Time)

Platform dlna_dmr not ready yet. Retrying in 180 seconds.

The Onkyo was auto-detected in b0 and created an entity registry entry for it automatically....

StevenLooman commented 6 years ago

Can you enable debugging log messages and share the results? You can enable debugging messages (and only enable message for dlna_dmr/async_upnp_client, other parts will be silenced) by adding this to your home assistant configuration:

logger:
  default: warning
  logs:
    homeassistant.components.discovery: debug
    homeassistant.components.media_player.dlna_dmr: debug
    async_upnp_client: debug
    async_upnp_client.dlna: debug
    async_upnp_client.traffic: info

You can set the last entry from info to debug to gather even more data. But I don't think that is necessary.

DavidFW1960 commented 6 years ago

Cheers. Here is the log as requested

2018-08-21 10:35:13 INFO (MainThread) [homeassistant.components.discovery] Found new service: hassio {}
2018-08-21 10:35:32 WARNING (SyncWorker_9) [netdisco.ssdp] Error fetching description at http://10.90.11.39:8888/upnp_descriptor_0
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Found new service: dlna_dmr {'host': '10.90.11.12', 'port': 1887, 'ssdp_description': 'http://10.90.11.12:1887/', 'name': 'osmc_vero4', 'model_name': 'Kodi', 'model_number': '17.6', 'serial': None, 'manufacturer': 'XBMC Foundation', 'udn': 'uuid:bb762f71-7a40-eb83-4b32-1b31b86cdb79', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaRenderer:1'}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: tivo_dvr {'host': '10.90.11.17', 'port': 31339, 'hostname': 'DVR-A9A9.local.', 'properties': {'protocol': 'tivo-remote', 'path': '/', 'swversion': '11.3b10.2017.10.11-1506-01-2-Z-663', 'platform': 'tcd/Series3', 'TSN': '66300018021A9A9'}}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: home_assistant {'host': '10.90.11.22', 'port': 8123, 'hostname': 'Home._home-assistant._tcp.local.', 'properties': {'version': '0.76.1', 'base_url': 'http://10.90.11.22:8123', 'requires_api_password': True}}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: fritzbox {'host': '10.90.11.1', 'port': 49000, 'ssdp_description': 'http://10.90.11.1:49000/fboxdesc.xml', 'name': 'FRITZ!Box 7590', 'model_name': 'FRITZ!Box 7590', 'model_number': 'avme', 'serial': None, 'manufacturer': 'AVM Berlin', 'udn': 'uuid:123402409-bccb-40e7-8e6c-E0286D762BAB', 'upnp_device_type': 'urn:schemas-upnp-org:device:fritzbox:1'}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Found new service: roku {'host': '10.90.11.14', 'port': 8060, 'ssdp_description': 'http://10.90.11.14:8060/', 'name': 'Telstra TV - 5X46AJ056306', 'model_name': 'Telstra TV', 'model_number': '4200TL', 'serial': '5X46AJ056306', 'manufacturer': 'Roku', 'udn': 'uuid:05a04191-6800-10db-80f2-88dea96eb763', 'upnp_device_type': 'urn:roku-com:device:player:1-0'}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: dlna_dms {'host': '10.90.11.12', 'port': 1389, 'ssdp_description': 'http://10.90.11.12:1389/DeviceDescription.xml', 'name': 'osmc_vero4', 'model_name': 'Kodi', 'model_number': '17.6', 'serial': None, 'manufacturer': 'XBMC Foundation', 'udn': 'uuid:ca4daa08-1396-a181-6c3c-c959335ead86', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaServer:1'}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: dlna_dms {'host': '10.90.11.1', 'port': 49000, 'ssdp_description': 'http://10.90.11.1:49000/MediaServerDevDesc.xml', 'name': 'AVM FRITZ!Mediaserver', 'model_name': 'FRITZ!Box 7590', 'model_number': 'avme', 'serial': None, 'manufacturer': 'AVM Berlin', 'udn': 'uuid:fa095ecc-e13e-40e7-8e6c-e0286d762bab', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaServer:1'}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: dlna_dms {'host': '10.90.11.36', 'port': 49152, 'ssdp_description': 'http://10.90.11.36:49152/MediaServer.xml', 'name': 'STB 10.90.11.36', 'model_name': 'Fetch DLNA1.5 DMS', 'model_number': '1', 'serial': '001', 'manufacturer': 'Fetch Technologies Co., Ltd', 'udn': 'uuid:898f9738-d930-4db4-a3cf-0c565c6da4e8', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaServer:1'}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: dlna_dms {'host': '10.90.11.5', 'port': 52478, 'ssdp_description': 'http://10.90.11.5:52478/', 'name': 'PlayOn: WILLIAMS', 'model_name': 'Windows MediaMall Server', 'model_number': '4.4.29.23033', 'serial': None, 'manufacturer': 'MediaMall Technologies, Inc.', 'udn': 'uuid:f2c60e3d-c5dc-4acd-a1a0-da505e31b0d2', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaServer:1'}
2018-08-21 10:35:38 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: dlna_dms {'host': '10.90.11.90', 'port': 49000, 'ssdp_description': 'http://10.90.11.90:49000/MediaServerDevDesc.xml', 'name': 'AVM FRITZ!Mediaserver', 'model_name': 'FRITZ!Box 7490', 'model_number': 'avme', 'serial': None, 'manufacturer': 'AVM Berlin', 'udn': 'uuid:fa095ecc-e13e-40e7-8e6c-0896d773c800', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaServer:1'}
2018-08-21 10:35:50 INFO (MainThread) [homeassistant.components.media_player.dlna_dmr] UPNP/DLNA event handler listening on: http://10.90.11.22:8301/notify
2018-08-21 10:35:50 DEBUG (MainThread) [homeassistant.components.media_player.dlna_dmr] Adding device: <Entity osmc_vero4: off>
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.dlna] Subscribing to service: <UpnpService(urn:upnp-org:serviceId:AVTransport, uuid:bb762f71-7a40-eb83-4b32-1b31b86cdb79)>
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client] Subscribing to: <UpnpService(urn:upnp-org:serviceId:AVTransport, uuid:bb762f71-7a40-eb83-4b32-1b31b86cdb79)>, callback URL: http://10.90.11.22:8301/notify
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client] Got SID: uuid:7b33d8ed-1c1e-a5f9-2f92-e53ebe3f0c37, renewal_time: 2018-08-21 11:05:50.364507
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.dlna] Subscribing to service: <UpnpService(urn:upnp-org:serviceId:RenderingControl, uuid:bb762f71-7a40-eb83-4b32-1b31b86cdb79)>
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client] Subscribing to: <UpnpService(urn:upnp-org:serviceId:RenderingControl, uuid:bb762f71-7a40-eb83-4b32-1b31b86cdb79)>, callback URL: http://10.90.11.22:8301/notify
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.aiohttp] Received request: <BaseRequest NOTIFY /notify >
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.aiohttp] NOTIFY response status: 200
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client] Got SID: uuid:c0f410d2-c28a-36ce-1afd-5ce2767f0a2c, renewal_time: 2018-08-21 11:05:50.415860
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.dlna] Got no value for volume_level
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.dlna] Got no value for volume_mute
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.aiohttp] Received request: <BaseRequest NOTIFY /notify >
2018-08-21 10:35:50 DEBUG (MainThread) [async_upnp_client.aiohttp] NOTIFY response status: 200
DavidFW1960 commented 6 years ago

I also see that it found a TiVo but that's not coming up either and it didn't come up in b0 and is not in my entity registry

StevenLooman commented 6 years ago

The discovery component finds multiple things, not all things found are supported by Home Assistant. In this case we are only interested in dlna_dmr devices.

From the logs I see no abnormal things for the osmc_vero4 device. It is detected and notifications are received (not all directly, hence the Got no value for ... messages, but that is no problem as they are probably received directly after (next lines)).

This line can be your problem though:

2018-08-21 10:35:32 WARNING (SyncWorker_9) [netdisco.ssdp] Error fetching description at http://10.90.11.39:8888/upnp_descriptor_0

Not sure what this device is. I had a similar problem where my PiMusicbox got a new IP address, but the UPnP/DLNA service on the PiMusicbox was still advertising its old IP address. Restarting the service (or rebooting the device) helped in this case. Can you try this with your Onkyo?

If you are up for it, you can also run this on the terminal, possibly from your virtualenv/docker/container:

$ python -m netdisco

This will give you some information about the different devices. In my case, I see things like this:

dlna_dmr:
[{'host': '192.168.1.14',
  'manufacturer': 'Samsung Electronics',
  'model_name': 'UE50KU6000',
  'model_number': 'AllShare1.0',
  'name': '[TV] Samsung 6 Series (50)',
  'port': 9197,
  'serial': '0CCS3HIHC00137H',
  'ssdp_description': 'http://192.168.1.14:9197/dmr',
  'udn': 'uuid:4d672690-9e27-4f2a-8426-3e8334427884',
  'upnp_device_type': 'urn:schemas-upnp-org:device:MediaRenderer:1'},
 {'host': '192.168.1.15',
  'manufacturer': 'JF Light Industries',
  'model_name': 'UpMPD',
  'model_number': '1.0',
  'name': 'MusicBox',
  'port': 49152,
  'serial': '42',
  'ssdp_description': 'http://192.168.1.15:49152/description.xml',
  'udn': 'uuid:e3a17dd5-9d85-3131-3c34-b827eb498d72',
  'upnp_device_type': 'urn:schemas-upnp-org:device:MediaRenderer:1'}]

Had to run it twice to get the dlna_dmr devices though.

DavidFW1960 commented 6 years ago

Hi @StevenLooman it wasn't the osmc_vero4 - that one is working since you fixed it. The problem is with my Onkyo receiver which was detected by discovery and added to my known_deviced.yaml file.

Here is my netdisco output from homeassistant docker container


bash-4.4# python -m netdisco

dlna_dmr:
[{'host': '10.90.11.12',
  'manufacturer': 'XBMC Foundation',
  'model_name': 'Kodi',
  'model_number': '17.6',
  'name': 'osmc_vero4',
  'port': 1887,
  'serial': None,
  'ssdp_description': 'http://10.90.11.12:1887/',
  'udn': 'uuid:bb762f71-7a40-eb83-4b32-1b31b86cdb79',
  'upnp_device_type': 'urn:schemas-upnp-org:device:MediaRenderer:1'},
 {'host': '10.90.11.39',
  'manufacturer': 'ONKYO',
  'model_name': 'TX-NR1009',
  'model_number': 'TX-NR1009',
  'name': 'TX-NR1009',
  'port': 8888,
  'serial': None,
  'ssdp_description': 'http://10.90.11.39:8888/upnp_descriptor_0',
  'udn': 'uuid:4ab0f3f2-baf3-f2b9-b2fa-f209bab9b30a',
  'upnp_device_type': 'urn:schemas-upnp-org:device:MediaRenderer:1'}]

Discovered 8 devices
bash-4.4#

It's just giving an error in Lovelace - red card.

I did a hard boot of the Onkyo and restarted Home Assistant....

Well bugger me!!! the reboot fixed it and it's come up again. Nice.

Sorry about that. Thanks for your help and care.
StevenLooman commented 6 years ago

Great! No problem, happy to help.