Calling play_media for Plex devices doesn't update Plex Server

[mdrichardson]

The problem

If you call play_media with a media_player.plex* device, the media will play, but the Plex Server won't show that any clients are playing in the Dashboard. Because media_player.plex* gets its state from the server, it also won't show that anything is playing.

If media is played directly from the Plex Client (not at all through Home Assistant), everything updates appropriately.

Environment

• Home Assistant release with the issue: 0.105.0
• Last working Home Assistant release (if known): Unknown, but I think this was working a week or so ago.
• Operating environment (Hass.io/Docker/Windows/etc.): Pi 3b+
• Integration causing this issue: Plex
• Link to integration documentation on our website: https://www.home-assistant.io/integrations/plex/
• Plex Server Version: 1.18.5.2309

Problem-relevant configuration.yaml

N/A

Traceback/Error logs

Nothing relevant. After calling play_media:

2020-02-07 09:20:45 DEBUG (SyncWorker_18) [homeassistant.components.plex.server] Updating devices
2020-02-07 09:20:45 DEBUG (SyncWorker_18) [homeassistant.components.plex.server] Refreshing XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX-com-plexapp-android
2020-02-07 09:20:45 DEBUG (SyncWorker_18) [homeassistant.components.plex.server] Refreshing XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX-com-plexapp-android
2020-02-07 09:20:45 DEBUG (MainThread) [homeassistant.components.plex.media_player] Refreshing media_player.plex_living_room [<PlexClient:http://XX.XX.XX.X::Living-Room> / None]
2020-02-07 09:20:45 DEBUG (MainThread) [homeassistant.components.plex.media_player] Refreshing media_player.plex_rec_room [<PlexClient:http://XX.XX.XX.X::Rec-Room-TV> / None]
2020-02-07 09:20:45 DEBUG (SyncWorker_17) [homeassistant.components.plex.sensor] Refreshing sensor [sensor-XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX]

Additional information

Maybe we need to send a subscribe command on behalf of the client?

From what I can tell based on a quick read-through, it looks like play_media uses hass to actually play the media. Would it not make more sense to use plexapi?

Probably related feature request

[probot-home-assistant]

Hey there @jjlawren, mind taking a look at this issue as its been labeled with a integration (plex) you are listed as a codeowner for? Thanks!

[jjlawren]

The integration simply shows the active sessions that the Plex server reports back. Seems like a Plex issue if they're not even showing up in the dashboard. Is the media being played located on the Plex server you're monitoring?

[mdrichardson]

@jjlawren I was thinking that could be the issue as well, except that it works fine if I play media through the regular plex clients (Shield Plex App, Plex mobile app, Plex for Web, etc)--even the media_player.plex* updates appropriately if I play through there, just not with play_media.

Is the media being played located on the Plex server you're monitoring?

Yep. Just one Plex server and I'm calling it using similar commands in my other issue (although this issue is more for Shield clients):

entity_id: "media_player.plex_living_room"
media_content_id: "{\"library_name\":\"TV Shows\",\"show_name\":\"Superstore\",\"season_number\":\"5\",\"episode_number\":\"14\",\"shuffle\":\"0\"}"
media_content_type: "EPISODE"

---

I don't believe this is related, but my only errors in my logs are Heartbeat errors:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_ws.py", line 102, in _send_heartbeat
    self._loop.create_task(self._writer.ping())  # type: ignore
AttributeError: 'NoneType' object has no attribute 'ping'
2020-02-07 10:09:54 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback WebSocketResponse._send_heartbeat()
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_ws.py", line 102, in _send_heartbeat
    self._loop.create_task(self._writer.ping())  # type: ignore
AttributeError: 'NoneType' object has no attribute 'ping'
2020-02-07 10:09:54 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback WebSocketResponse._send_heartbeat()
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_ws.py", line 102, in _send_heartbeat
    self._loop.create_task(self._writer.ping())  # type: ignore
AttributeError: 'NoneType' object has no attribute 'ping'
2020-02-07 10:09:55 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback WebSocketResponse._send_heartbeat()
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_ws.py", line 102, in _send_heartbeat
    self._loop.create_task(self._writer.ping())  # type: ignore
AttributeError: 'NoneType' object has no attribute 'ping'

And I've monitored my firewall, just in case, and nothing is being blocked.

[mdrichardson]

I'm combing through Plex logs now and will add anything I find "intersting" (after calling play_media to my Shield):

Feb 07, 2020 10:58:04.440 [7516] DEBUG - Streaming Resource: Added session da56c5e2f61313a9-com-plexapp-android
Feb 07, 2020 10:58:04.440 [7516] DEBUG - Found session GUID of da56c5e2f61313a9-com-plexapp-android in session start.
Feb 07, 2020 10:58:04.440 [7516] DEBUG - Using session GUID da56c5e2f61313a9-com-plexapp-android for new transcode session.
Feb 07, 2020 10:58:04.440 [7516] VERBOSE - [IDLE] Adding (3->4) work item transcoder - da56c5e2f61313a9-com-plexapp-android
Feb 07, 2020 10:58:04.440 [7516] VERBOSE - [IDLE] * http_download - /video/:/transcode/universal/session/da56c5e2f61313a9-com-plexapp-android/base/00000.ts - 3 active item(s)
Feb 07, 2020 10:58:04.440 [7516] VERBOSE - [IDLE] * http_download - /video/:/transcode/universal/session/da56c5e2f61313a9-com-plexapp-android/base/00001.ts - 3 active item(s)
Feb 07, 2020 10:58:04.440 [7516] VERBOSE - [IDLE] * transcoder - da56c5e2f61313a9-com-plexapp-android - 4 active item(s)
Feb 07, 2020 10:58:04.440 [7516] DEBUG - Cleaning directory for session da56c5e2f61313a9-com-plexapp-android ()
[...]
// IS THIS IMPORTANT?
Feb 07, 2020 10:58:04.456 [15072] DEBUG - Request came in with unrecognized domain / IP <MYDOMAIN>.net' in header Host; treating as non-local

---

I should also note that calling the /status/sessions/ API results in:

{
    "MediaContainer": {
        "size": 0
    }
}

However, if I call /transcode/sessions, I actually get the transcoding session

[jjlawren]

Odd, I'm not familiar with that endpoint. The plexapi library expects all actively playing sessions to be under the /status/sessions endpoint: Source.

Maybe the Plex API has changed with a recent upgrade.

[mdrichardson]

@jjlawren I think the transcode endpoint is a separate tracker for sessions that are actually transcoding. Between that endpoint and the logs, it appears transcoding is working fine, which makes sense, since it's needed for playback. For whatever reason, client status isn't being tracked.

[mdrichardson]

I've also determined that Plex Webhooks won't fire if using play_media. These also work fine if playing via non-HA means.

[jjlawren]

I'm saying that all active playing sessions used to be reported when calling /status/sessions even if they were transcoding. Something seems to have changed on the Plex server behavior.

[mdrichardson]

@jjlawren I see. I'll try downgrading the server and see if that fixes things.

[mdrichardson]

I tested a few different versions:

• 1.16.3.1402-22929c8a2 (July 2019): Media wouldn't play at all
• 1.17.0.1709-982421575 (Sep 2019): Media wouldn't play at all
• 1.18.1.1973-0f4abfbcc (Oct 2019): No status tracking
• 1.18.2.2058-e67a4e892 (Nov 2019): No status tracking
• 1.18.5.2309-f5213a238 (Current): No status tracking

[jjlawren]

Thanks for being so thorough. Unfortunately I'm not sure what to make of the results. It doesn't seem like any version is working properly for you...

[mdrichardson]

@jjlawren No problem. Happy to help. And I can't seem to make anything of it, either. I take it that things work for you just fine?

[mdrichardson]

@jjlawren I turned on network logging in the Shield and see this:

02-07 16:36:16.271  i: Fetching [method:POST] http://<HA IP>:32400/:/timeline?X-Plex-Token=...null-1oWp6J-3Yt2u93mEz_v&includeExternalMedia=1
02-07 16:36:16.279  i: Time out fetching http://<HA IP>:32400/:/timeline?X-Plex-Token=...null-1oWp6J-3Yt2u93mEz_v.

Plex edits out the token, but I find the null part interesting. It looks like the Shield is either:

1. Having trouble reaching HA, or more likely,
2. Is trying to submit /timeline to HA when it should be going to Plex (it is definitely HA's IP and not Plex's that I edited out)

/playQueue, /transcode and all the other calls are going to the Plex IP. It's just /subscribe going to HA.

Not sure how to fix this, but that seems like the issue. I'd guess it is something related to this

[jjlawren]

I got my hands on a Shield and reproduced the issue. It looks like it's a combination of (newer) behavior of the Plex client on Shield and the subscription command sent during a media playback request in the underlying library.

Basically it requests the Shield to call back to the HA address on the server's port with POST state updates. This will always fail. I think with HA this will need to be changed to a poll mechanism, which should be fine as we're already notified of updates via the websocket connection.

Opened an issue for the library here.

[jjlawren]

Alright, so even when skipping the callback subscription command, the server still doesn’t report playback status on the normal /status/sessions endpoint when starting playback on a Shield device over the API. I can’t reproduce this behavior on any other device I have. Not sure how to resolve yet.

[jjlawren]

Although the subscription calls seem incorrect, they don't seem to be related to the Plex server not reporting the playback status. Old Shield Plex clients behave fine (ie, roll back to the one that's preinstalled on the Shield and it reports playback fine). The newer ones appear to have some issue when playback is started via the player's API.

I posted on the Plex forums a while back with info for their devs and I've been testing each incremental version released. No fixes available yet.

[jjlawren]

I'm still seeing this behavior on the latest Shield client released a few days ago.

As a sanity check, @mdrichardson is your Shield client on a different subnet as your Plex server, and/or are there any possible networking restrictions between them? I have mine on separate VLANs and only allow known Plex ports through. Curious if that could be a common theme that should be explored further.

[mdrichardson]

@jjlawren I have two Shields and both are on the same subnet with everything else--haven't separated everything into VLANs yet. I still haven't had a chance to really test this, but I'll watch my firewall logs to see if anything is getting blocked--shouldn't be though as I allow all traffic between LAN clients.

I just migrated Plex to a Linux LXC in Proxmox from Windows, so I'll see if that makes a difference as well.

[jjlawren]

Well, this looks promising: https://forums.plex.tv/t/plex-for-android/29115/341

Plex for Android 8.0.0

FIXES:

• Player: Play progress would sometimes not be reported to the server.

Edit: Nope, still broken.

[mdrichardson]

@jjlawren That's my experience, as well. Still getting the error I mentioned above

[jjlawren]

@jjlawren That's my experience, as well. Still getting the error I mentioned above

Thanks for confirming. I've started to get some feedback over in the Plex forums that seems to acknowledge the issue(s): https://forums.plex.tv/t/no-session-status-when-starting-playback-on-shield-over-remote-control-api/555067

[dmintz7]

I'm getting this same issue using an Amazon Fire TV. The media plays fine but nothing is reported to the sessions endpoint. I also tried on my iphone and the session is reported.

I've been trying to think of a workaround since this is also effecting how plex syncs with trakt

[jjlawren]

@dmintz7 this seems to be a Plex issue with AndroidTV clients. I'm sure it's not showing up in your Plex Web activity, either. I'm working with Plex to get this resolved.

[github-actions]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[jjlawren]

Still chasing this problem upstream. Would like to keep this open for now in case others encounter the same issue.

[github-actions]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[jjlawren]

I may have finally tracked this down. Created pkkid/python-plexapi#826 upstream to fix. I'll need to test more to be sure.