Is Plex integration broken?

taylormade · November 27, 2020, 8:15pm

I was having same issue with <0.117 not accepting the auth token. I just updated to 0.118.3 this week and now I’m getting this in the logs when I hit the big red ‘reconfigure’ button in the Integrations page:

2020-11-27 11:51:38 INFO (SyncWorker_9) [plexapi] Testing 6 resource connections..
2020-11-27 11:51:38 ERROR (Thread-6) [plexapi] https://<my_address_1>.plex.direct:32400: HTTPSConnectionPool(host='<my_address_1>.plex.direct', port=32400): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f64a820b580>: Failed to establish a new connection: [Errno -2] Name does not resolve'))
2020-11-27 11:51:38 ERROR (Thread-11) [plexapi] http://<my_address_3>:8443: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))
2020-11-27 11:51:41 INFO (SyncWorker_9) [plexapi] Resource connection ERR (0s): https://<my_address_1>.plex.direct:32400?X-Plex-Token=<hidden>
2020-11-27 11:51:41 INFO (SyncWorker_9) [plexapi] Resource connection OK (0s): https://<my_address_2>.plex.direct:32400?X-Plex-Token=<hidden>
2020-11-27 11:51:41 INFO (SyncWorker_9) [plexapi] Resource connection OK (3s): https://<my_address_3>.plex.direct:8443?X-Plex-Token=<hidden>
2020-11-27 11:51:41 INFO (SyncWorker_9) [plexapi] Resource connection OK (0s): http://<my_address_1>:32400?X-Plex-Token=<hidden>
2020-11-27 11:51:41 INFO (SyncWorker_9) [plexapi] Resource connection OK (0s): http://<my_address_2>:32400?X-Plex-Token=<hidden>
2020-11-27 11:51:41 INFO (SyncWorker_9) [plexapi] Resource connection ERR (0s): http://<my_address_3>:8443?X-Plex-Token=<hidden>
2020-11-27 11:51:41 INFO (SyncWorker_9) [plexapi] Connecting to Resource: https://<my_address_2>.plex.direct:32400?X-Plex-Token=<hidden>
2020-11-27 11:51:41 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_protocol.py", line 422, in _handle_request
    resp = await self._request_handler(request)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_app.py", line 499, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_middlewares.py", line 118, in impl
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 18, in request_context_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 72, in ban_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 127, in auth_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 129, in handle
    result = await result
  File "/usr/src/homeassistant/homeassistant/components/config/config_entries.py", line 160, in get
    return await super().get(request, flow_id)
  File "/usr/src/homeassistant/homeassistant/helpers/data_entry_flow.py", line 92, in get
    result = await self._flow_mgr.async_configure(flow_id)
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 155, in async_configure
    result = await self._async_handle_step(flow, cur_step["step_id"], user_input)
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 213, in _async_handle_step
    result: Dict = await getattr(flow, method)(user_input)
  File "/usr/src/homeassistant/homeassistant/components/plex/config_flow.py", line 327, in async_step_use_external_token
    return await self.async_step_server_validate(server_config)
  File "/usr/src/homeassistant/homeassistant/components/plex/config_flow.py", line 237, in async_step_server_validate
    self.hass.config_entries.async_update_entry(entry, data=data)
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 788, in async_update_entry
    if data is not _UNDEF and entry.data != data:  # type: ignore
AttributeError: 'NoneType' object has no attribute 'data'

It tried hitting my plex server using its private internal address, my public IP, and a public IP I assume is owned by Plex. But then it just poos itself. Over in the UI, it says “Please wait while the integration is being installed” and then just hung in a swirling circle.

I figure if I remove the integration and put it back, that might help. But I can’t remove the integration because of the big red ‘reconfigure’ button.

taylormade · November 27, 2020, 9:21pm

I just updated from 0.118.3 to 0.118.4 and tried again.

The first time I tried hitting ‘reconfigure’, it attempts to connect to plex.tv to pull a token and then redirect a page on my local server to finish the auth. The problem at this point is that it gets the IP address of my local server wrong (it’s putting in an IP for a docker container that is unrelated to plex, which is unsurprisingly not answering on the plex port.)

Subsequent attempts after that throw the above python error.

jjlawren · November 27, 2020, 9:30pm

Have you customized your http: config?

As a workaround you can edit the URL that fails to connect to the docker IP and put in your locally connectable IP. Keep the rest of the path as-is. This should work automatically but something is not working as expected.

taylormade · November 27, 2020, 10:56pm

I haven’t customized http: config, but have in Plex -> Settings -> Network set server to respond to a specific interface and in Server -> Remote Access have forced the port. Both of those were to ensure Plex remote access worked.

I had tried changing that IP embedded in the URL and it never takes. I’ve pulled the target url from the redirect out, changed the IP, and then gone there, and my plex server tells me it authenticated.

Another thing I noticed (stupid user error) was the big red ‘reconfigure’ button over the plex integration was not the only plex integration tile in the page of Integrations. I didn’t notice it was in there twice. Using the other one I was able to delete the integration, restart HA, and then add it back in. It still tried to send the token to the wrong IP address, but this time when I changed the IP address in the redirect url and hit it again it appears to have accepted the token and is adding entities back in as they turn on.

jjlawren · November 28, 2020, 1:30am

None of those should make a difference here, unless the port is forwarded from a different port externally.

If I read the rest of your post correctly you’re up and running again?

taylormade · November 28, 2020, 8:30pm

you’re up and running again?

Yes. It appears to be.

When I installed the integration from scratch, it still tried to go to the wrong IP address. When I changed the IP embedded in the URL, it accepted the token and seems to have linked up correctly. The entities for a couple of key players seems to have changed names, which was just a minor update to the lovelace card to get them back to where they were. Part of me really wants to track down where it is getting the wrong IP from, but now that it is working it a lower priority under other stuff that is still broke.

jjlawren · November 28, 2020, 9:36pm

A couple things to check:

Is the docker instance running in host mode? I believe it must be to be a supported HA installation.
Are you running a reverse proxy?

taylormade · November 28, 2020, 10:41pm

The docker container is in NAT mode with port forwarding passing a couple of ports from host to guest. It gets 10.0.3.5 as an address. There are three other containers running that are assigned 10.0.3.2-4, with the host at 10.0.3.1 providing them dhcp. The host then NATs the addresses to its 192.168.0.0/16 address to get to the rest of the network. So, I reach all four containers by going to different ports on the host’s 192.168.0.0 address. Two of the containers are Node-Red and Mosquitto, which HA is able to connect to by going to the host’s 192.168.0.0 address. The final container is unrelated to HA or Plex, so its address shouldn’t be referenced anywhere in either’s configs and there shouldn’t be any comms from them to/from it.

One of the problems this caused was that the plex server can see the 10.0.3.1 interface. That’s why I had to lock it to the 192.168.0.0 interface instead of leaving it at the default of ‘any’. When it advertises 10.0.3.1 as its internal address to the plex cloud for remote access, the clients go out to the plex domain and then can’t connect because that 10. network is only accessible inside the host.

If HA was picking up its or plex’s 10. address, I could make sense of that. But since it is picking up an address from the unrelated container, I’m confused.

jjlawren · November 29, 2020, 1:15am

Those all sound like side effects of running in NAT mode. Is there a reason you won’t/can’t run in host mode?

SpikeyGG · December 30, 2020, 12:19pm

@jjlawren, I’ve noticed that my Plex integration is very hit and miss, mostly miss. It seems most of the time I get a message in my log after a restart to the effect of:

Logger: homeassistant.components.plex
Source: components/plex/__init__.py:117
Integration: Plex Media Server (documentation, issues)
First occurred: 5:03:36 AM (1 occurrences)
Last logged: 5:03:36 AM

Plex server (https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443) could not be reached: [HTTPSConnectionPool(host='185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct', port=8443): Max retries exceeded with url: / (Caused by SSLError(SSLEOFError(8, 'EOF occurred in violation of protocol (_ssl.c:1124)')))]

I’ve modified some of the characters in the string so it’s not my actual URL but when I take the original and plug it into my web browser it comes up with Plex. Is there a way for me to further debug this on my end? If I remove and reinstall the integration it works fine. I’ve done this a few times but obviously not an ideal way to fix it long term. I checked my machine running Plex and it is running in host mode.

jjlawren · December 30, 2020, 1:55pm

Have you customized the Plex port? 8443 is not the default.
Have you tried locking down the interface Plex uses to the host’s IP instead of “any”? That’s available under the “Network” settings page.
Are other log messages available?

SpikeyGG · December 30, 2020, 7:35pm

Not to my knowledge. I’m looking at Plex settings, under SETTINGS->Remote Access and it shows this:

Is there somewhere else I can look for custom Plex port config?

I have configured that to be the hardware ethernet port on the board. My options are:

Any
eno2 (this is the hardware ethernet port, has my DHCP given local network IP)
br-b3d761c7a1r8 (this appears to be the virtual docker port).

I just tried enabling debug logging in Plex and then restarting HA and it came up without any error messages. I tried it again and it succeeded twice in a row. I’ve noticed this a few times in the past so I think it’s random. When you ask about log messages are you asking about Plex logging or HA logging? In HA I only ever see some envoy messages which get stacked because the service to collect data is too aggressive.

jjlawren · January 8, 2021, 1:50pm

Sorry, lost track of this thread. The other thing I can think of is that it’s trying to connect to a non-local IP and failing. Perhaps enabling some type of hairpin NAT on your router would make things a bit smoother, where connections to your own public IP would be allowed from inside your network.

If you have new logs or additional updates please let me know.

SpikeyGG · January 8, 2021, 2:16pm

Thanks @jjlawren. I have enabled the “Manually specify public port” option with the 32400 default, because that’s what I’ve forwarded but the Home Assistant error message still persists listing port 8443. Because I have the port forwarded, I’m able to stream to my mobile phone whether on or off WiFi (local) via the plex app. In fact, it looks like the error appears hourly:

First occurred: January 7, 2021, 6:15:25 AM (24 occurrences)
Last logged: 6:59:02 AM

The weird thing is that 8443 port is open to my home assistant machine so I don’t know why it would be complaining about being unable to connect. Especially, when I can open a browser and connect to that URL and it appears to work. I don’t know if I have any control over the port number on my end, is that supposed to be port 32400?

jjlawren · January 8, 2021, 3:37pm

Port 32400 is the default for Plex server communication, I’m still unclear on why 8443 is being used.

Could you update your logger config to raise up log levels for these modules and reproduce?:

logger:
  logs:
    homeassistant.components.plex: debug
    plexapi: debug

Make sure to sanitize any personal information before sharing, especially tokens.

SpikeyGG · January 9, 2021, 1:11am

Ok, I set the logging to debug on those components and restarted, when it came back I got a few messages in the logs. Here’s the dump with (what I assume is) the tokens changed slightly:

2021-01-08 18:06:17 DEBUG (SyncWorker_11) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:06:20 ERROR (MainThread) [glances_api] Can not load data from Glances API
2021-01-08 18:06:20 WARNING (MainThread) [homeassistant.config_entries] Config entry for glances not ready yet. Retrying in 5 seconds
2021-01-08 18:06:29 ERROR (MainThread) [homeassistant.components.plex] Plex server (https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443) could not be reached: [HTTPSConnectionPool(host='185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct', port=8443): Max retries exceeded with url: / (Caused by SSLError(SSLEOFError(8, 'EOF occurred in violation of protocol (_ssl.c:1125)')))]
2021-01-08 18:06:29 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 5 seconds
2021-01-08 18:06:34 DEBUG (SyncWorker_10) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:06:44 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 10 seconds
2021-01-08 18:06:54 DEBUG (SyncWorker_9) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:07:06 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 20 seconds
2021-01-08 18:07:26 DEBUG (SyncWorker_12) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:07:37 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 40 seconds

Doesn’t seem to be giving us more detail.

EDIT

Wait a tick, I refreshed it a little while later and it dumped out more detail. Looks like it eventually connected without an issue. Weird that it would fail for a few minutes, then connect. Any ideas?

2021-01-08 18:06:17 DEBUG (SyncWorker_11) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:06:20 ERROR (MainThread) [glances_api] Can not load data from Glances API
2021-01-08 18:06:20 WARNING (MainThread) [homeassistant.config_entries] Config entry for glances not ready yet. Retrying in 5 seconds
2021-01-08 18:06:29 ERROR (MainThread) [homeassistant.components.plex] Plex server (https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443) could not be reached: [HTTPSConnectionPool(host='185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct', port=8443): Max retries exceeded with url: / (Caused by SSLError(SSLEOFError(8, 'EOF occurred in violation of protocol (_ssl.c:1125)')))]
2021-01-08 18:06:29 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 5 seconds
2021-01-08 18:06:34 DEBUG (SyncWorker_10) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:06:44 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 10 seconds
2021-01-08 18:06:54 DEBUG (SyncWorker_9) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:07:06 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 20 seconds
2021-01-08 18:07:26 DEBUG (SyncWorker_12) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:07:37 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 40 seconds
2021-01-08 18:08:17 DEBUG (SyncWorker_11) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:08:27 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 80 seconds
2021-01-08 18:09:47 DEBUG (SyncWorker_16) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:09:58 WARNING (MainThread) [homeassistant.config_entries] Config entry for plex not ready yet. Retrying in 80 seconds
2021-01-08 18:11:18 DEBUG (SyncWorker_10) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/
2021-01-08 18:11:21 DEBUG (SyncWorker_10) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/accounts
2021-01-08 18:11:21 DEBUG (SyncWorker_10) [homeassistant.components.plex.server] Linked accounts: {'[email protected]', '[email protected]'}
2021-01-08 18:11:21 DEBUG (SyncWorker_10) [homeassistant.components.plex.server] Server owner found: '[email protected]'
2021-01-08 18:11:21 DEBUG (MainThread) [homeassistant.components.plex] Connected to: plexbox (https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443)
2021-01-08 18:11:21 DEBUG (SyncWorker_6) [plexapi] GET https://plex.tv/users/account
2021-01-08 18:11:21 DEBUG (MainThread) [homeassistant.components.plex.media_player] New entity listener created
2021-01-08 18:11:21 DEBUG (MainThread) [homeassistant.components.plex] Websocket to plexbox successful
2021-01-08 18:11:22 DEBUG (MainThread) [homeassistant.components.plex.server] Updating devices
2021-01-08 18:11:22 DEBUG (SyncWorker_11) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/clients
2021-01-08 18:11:23 DEBUG (SyncWorker_11) [plexapi] GET https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443/status/sessions
2021-01-08 18:11:23 DEBUG (SyncWorker_11) [plexapi] GET https://plex.tv/api/resources?includeHttps=1&includeRelay=1
2021-01-08 18:11:23 DEBUG (SyncWorker_11) [homeassistant.components.plex.server] Current available clients from plex.tv: []
2021-01-08 18:11:26 DEBUG (MainThread) [homeassistant.components.plex.sensor] Refreshing sensor [sensor-711ae01a222db8cf3921f1d7a88672ac28f08ab0]

jjlawren · January 11, 2021, 6:21pm

This appears like the integration is working as expected but the Plex server side (or something in between) is occasionally preventing connections. The SSL warning implies that you’re trying to connect using SSL but whatever is listening on 8443 does not (always?) support that.

Is there anything unique about the Plex server? Is there a proxy in between? Is Plex running on the same physical host as HA? Does the Plex machine go to sleep? Anything else that could be a hint?

SpikeyGG · January 12, 2021, 2:43am

I don’t think there’s anything unique about the Plex server. It’s a different machine on the network and running from a docker but the docker is in host mode so it looks native.

There’s no proxy and the Plex machine doesn’t go to sleep. I’m actually running Zoneminder on the same hardware so the CPU sits at ~40% CPU all day long. It’s a beast tho:

Xeon(R) CPU E5-2620 (6-core)
128GB Ram
10TB spinning disks

I can’t think of anything that would cause this issue. Do you think it’s a Plex feature that is trying to get to port 8443? From what you’re saying it sounds like none of the API on the HA side should be trying to use 8443 so I’m still left wondering where that is coming from…

jjlawren · January 12, 2021, 2:59am

Ok, let’s start to dig into the weeds a bit. Can you share your config entry JSON for the Plex integration in <HA_CONFIG>/.storage/core.config_entries? It’ll be the block with "domain": "plex". Please make sure to remove your token and sanitize the URL if needed.

I assume you set up Plex using the UI in the Integrations page?

SpikeyGG · January 12, 2021, 3:14am

Sure thing, here’s the whole snapshot of domain: plex from my core.config_entries file:

            {
                "entry_id": "111111111111111111111111111111111",
                "version": 1,
                "domain": "plex",
                "title": "plexbox",
                "data": {
                    "server": "plexbox",
                    "server_id": "7777777777777777777777777777777777777777",
                    "server_config": {
                        "url": "https://185-106-128-84.721e342c69554bc2a447dad4f2ad8bcb.plex.direct:8443",
                        "client_id": "66666666-6666-6666-6666-666666666666",
                        "token": "XXXXXXXXXXXXXXXXXXXX",
                        "verify_ssl": true
                    }
                },
                "options": {
                    "media_player": {}
                },
                "system_options": {
                    "disable_new_entities": false
                },
                "source": "user",
                "connection_class": "local_push",
                "unique_id": "000000000000000000000000000000000000000"
            },

I see that this is where the 8443 is coming from. The URL matches exactly from my error logs. What should that URL look like? Maybe I should delete and recreate the integration? My local machine is called ‘plexbox’.