Core: Kodi Media Player stopped working since 0.65

[schneekluth]

Home Assistant release (hass --version):
0.65.2

Python release (python3 --version):
3.5.3

Component/platform:
Kodi media player

Description of problem:
Since 0.65 Kodi media player is no longer working. When Hass boots up the state is received correctly but after that the component does not longer allow playback control. When you press the play button nothing happens and some seconds later the media player shows state "off".

Problem-relevant configuration.yaml entries and steps to reproduce:

- platform: kodi
  host: XXX.XXX.XXX.XX
  port: 80
  name: 'Cubox'
  turn_off_action:
    service: media_player.kodi_call_method
    data:
      entity_id: media_player.cubox
      method: System.Reboot
  username: !secret kodi_user
  password: !secret kodi_password

After enabling debug logging for the component the following error appears when I try to reboot Kodi with the turn_off_action:

hass[12981]: 2018-03-11 09:43:12 WARNING (MainThread) [homeassistant.components.media_player.kodi] TransportError trying to run API method media_player.cubox.System.Reboot({})

[tadly]

Are you sure about port 80?
Kodis webserver usually runs on port 8080 unless you changed that.

IF you changed the port to 80, on which OS do you have kodi running?
Some operating systems don't allow none admin/root users to bind 80.

I'd suggest putting it back to 8080 for testing at least.

[jiriwendl]

I have the same problem.
It works in version 0.64.3.
Does not work in version 0.65.2 with the same configuration.

[jonudewux]

Same here, on 0.64.3 it was working.

[schneekluth]

@Tadly Yes, port 80 is correct. Kodi runs on a tiny Cubox and I've changed it to 80 because it's only purpose is running Kodi. There was no issue with the component and port 80 before.

[tadly]

@schneefux Please test it real quick anyways.
I have a felling that some part of the kodi component (or somewhere deeper) the http api gets used for something even though it shouldn't at all with this kind of config.
Even username and password aren't actually required because you are connecting to kodi via websocket (which doesn't need authentication and is a different port entirely).

That said, for me the kodi works most of the time and I've been trying to figure out why it sometimes looses sync for a bit now.

This could be related to #11625

[schneekluth]

Changing to port 8080 does not solve the problem. I've also setup kodi as notification platform and this works as expected (even with port 80):

  - name: kodi
    platform: kodi
    host: XXX.XXX.XXX.XX
    port: 80
    username: !secret kodi_user
    password: !secret kodi_password

When reverting back to 64.3 everything works as expected.

@jiriwendl and @jonudewux have you changed ports from 8080 to something else?

[jiriwendl]

@schneekluth
My configuration:

media_player:
  - platform: kodi
    host: xxx.xxx.xxx.xxx

Port on kodi: 8080

[tadly]

@schneekluth thanks for verifying

At this point I suspect the issue being somewhere deeper especially as I have state issues with z-wave and kodi works, while a friends setup is exactly the opposite (z-wave works just fine, but kodi is apparently always off now).

That's gonna be a tricky one I guess...

[tadly]

So I just now recreated .homeassistant/deps (deleting the folder and letting hass bootstrap again) and now kodi is also broken for me.
Gonna reinstall the entirety of hass...

[Merwenus]

Same problem here, v65.2.
Can't wake or suspend or control kodi.

Error calling async_mute_volume on entity media_player.kodi: TransportError("Error calling method 'Application.SetMute': Transport Error", TimeoutError())
16:43 components/media_player/kodi.py (ERROR)
Error calling async_mute_volume on entity media_player.kodi: TransportError("Error calling method 'Application.SetMute': Transport Error", TimeoutError())
16:43 components/media_player/kodi.py (ERROR)
Error calling async_volume_down on entity media_player.kodi: TransportError("Error calling method 'Input.ExecuteAction': Transport Error", TimeoutError())
16:43 components/media_player/kodi.py (ERROR)
TransportError trying to run API method media_player.kodi.System.Suspend({})
16:39 components/media_player/kodi.py (WARNING)

Sometimes I get a pretty nice task.py error too, I just restarted and logs are gone, but will copy paste here when it occures again.

[mikalauskas]

same on 0.65.2

Mar 11 20:53:47 rpi hass[10124]: /srv/homeassistant/lib/python3.5/site-packages/jsonrpc_websocket/jsonrpc.py:38: RuntimeWarning: coroutine 'ClientWebSocketResponse.send_str' was never awaited self._client.send_str(message.serialize())
Mar 11 20:53:47 rpi hass[10124]: 2018-03-11 20:53:47 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.kodi is taking over 10 seconds

[tadly]

I may have found the issue (which is exactly what @mikalauskas just posted).
I already created a PR for that very dependency which complains about coroutine was never awaited -> https://github.com/armills/jsonrpc-websocket/pull/1

To get kodi working again for now you can edit ~/.homeassistant/deps/lib/python3.5/site-packages/jsonrpc_websocket/jsonrpc.py (python version may vary) and replace line 38 so it reads:

yield from self._client.send_str(message.serialize())

Edit:
I'm rushing to much. I don't think this is the right fix to be done when looking at travis.
For us it does actually fix it but I don't thing that's the way to go...
I'll keep on digging

Edit 2:
Looks like I wasn't that far off after all :)

[bagfatnick]

I'm having the same problem, with Kodi's state switching to "off" after it gets turned on. I've also realised I can get a "Kodi: Error on device update" if Kodi was running when HASS is booting up.
The traceback:
`

kodi: Error on device update!
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/jsonrpc_websocket/jsonrpc.py", line 117, in wait
    yield from self._event.wait()
  File "/usr/local/lib/python3.6/asyncio/locks.py", line 271, in wait
    yield from fut
  File "/usr/local/lib/python3.6/asyncio/futures.py", line 327, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/local/lib/python3.6/asyncio/tasks.py", line 250, in _wakeup
    future.result()
  File "/usr/local/lib/python3.6/asyncio/futures.py", line 238, in result
    raise CancelledError
concurrent.futures._base.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/jsonrpc_websocket/jsonrpc.py", line 42, in send_message
    response = yield from pending_message.wait(self._timeout)
  File "/usr/local/lib/python3.6/site-packages/jsonrpc_websocket/jsonrpc.py", line 118, in wait
    return self._response
  File "/usr/local/lib/python3.6/site-packages/async_timeout/__init__.py", line 35, in __exit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.6/site-packages/async_timeout/__init__.py", line 80, in _do_exit
    raise asyncio.TimeoutError
concurrent.futures._base.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/app/homeassistant/helpers/entity_platform.py", line 188, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/app/homeassistant/helpers/entity.py", line 325, in async_device_update
    yield from self.async_update()
  File "/usr/src/app/homeassistant/components/media_player/kodi.py", line 440, in async_update
    'albumartist', 'showtitle', 'album', 'season', 'episode']
  File "/usr/local/lib/python3.6/site-packages/jsonrpc_websocket/jsonrpc.py", line 48, in send_message
    raise TransportError('Transport Error', message, exc)
jsonrpc_base.jsonrpc.TransportError: ("Error calling method 'Player.GetItem': Transport Error", TimeoutError())

`
Hope this helps somehow.

[emlove]

@Tadly Version 0.6 of jsonrpc-websocket is up. If you can bump the REQUIREMENTS in hass and it works, you can go ahead and open a PR.

[tadly]

@armills Thanks a bunch man. That was super quick!

[kbrint]

I also had working Kodi in 0.64.x and not in 0.65.2. I see normal looking JSONRPC from Kodi when state changes, but Hass insists it is "Off". This is the first time it has ever been "Off", normally it is just "Idle" when not playing.

[marijngiesen]

It's still not working for me in 0.65.4. Anyone else still having this issue?

[Norien]

On my Kodi v18(ubuntu) and Home Assistant 0.65.4 Kodi currently shows as idle however it's playing a movie. If I pause and play then correct state is shown of movie playing.

[marijngiesen]

It's working for me too in 0.65.5 👍

[tadly]

@marijngiesen @Norien If you both still have an issue try the following real quick and let me know how it went.

1. Power off the kodi device
2. Restart home-assistant
3. Power on the kodi device

In exactly this order and no cheating.

[marijngiesen]

@tadly It's fixed for me since 0.65.5

[tadly]

Whops. Missed that seconds comment. My bad :)

[thodre]

Had the same Problem. Upgrading to 0.65.5 didn't change anything. Tried what @tadly recommended but no change.

[Norien]

@tadly my home assistant is running on the same box as my Kodi. My Kodi / Hass sync seems to be working much better but it's not perfect. I've tried ending Kodi&Hass processes and bring them up in the order you suggested and I'm seeing same results.

[tadly]

@Norien thanks for letting me know.
The reason I suggested this was because a friend of mine does also have issues with the state of kodi getting "out of sync" (or whatever we gonna call it) but that seemed to be the only way for him to resolve until HA was restarted while kodi was running/online.

We should move this discussion over to #11625 as it is more fitting for the remaining issue.

[thodre]

Sorry, i screwed up there. I put enable_websocket: false in config and works perfectly.