Why is PMS becoming unresponsive / "crashed" almost every night? Please help

BinaryJay · April 9, 2021, 12:44pm

Server Version#: 1.22.2.4282
Logs.zip (2.2 MB)

Almost every day, usually overnight but not every time, I’ll go to bed for the night and PMS is working fine and wake up in the morning and no clients can connect to it, not even the client on the Shield itself. I also can’t connect to the web ui directly by IP address - it just times out. The shield itself remains online/on the network and all other applications continue to work normally.

I’ve attached logs with debug logging enabled, it was working fine last night and now this morning it isn’t … again. So far, I haven’t had anybody from Plex look at the logs I’ve posted in any other threads about server unavailability/crashing. Please help.

BinaryJay · April 10, 2021, 2:36pm

And it happened again last night. Logs attached again after restarting.

Plex Media Server Logs_2021-04-10_10-35-01.zip (723.9 KB)

BobSnot · April 11, 2021, 1:06am

what’s special about your network setup, every hour you get this error

Apr 10, 2021 02:59:53.448 [12545] ERROR - Unable to open named mutex 9334581e-7251-4ef7-a8ec-5bfe8e89ff68 with option 1: Function not implemented
Apr 10, 2021 03:00:02.533 [12589] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 04:00:02.663 [14794] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 04:00:05.673 [14794] ERROR - Error issuing curl_easy_perform(handle): 28
Apr 10, 2021 05:00:02.813 [16034] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 05:00:05.824 [16034] ERROR - Error issuing curl_easy_perform(handle): 28
Apr 10, 2021 06:00:02.912 [17646] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 06:00:05.923 [17646] ERROR - Error issuing curl_easy_perform(handle): 28
Apr 10, 2021 07:00:03.012 [19121] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 07:00:06.023 [19121] ERROR - Error issuing curl_easy_perform(handle): 28
Apr 10, 2021 08:00:03.097 [20111] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 08:00:06.108 [20111] ERROR - Error issuing curl_easy_perform(handle): 28
Apr 10, 2021 09:00:08.529 [21766] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 09:00:11.540 [21766] ERROR - Error issuing curl_easy_perform(handle): 28
Apr 10, 2021 10:00:08.659 [23631] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 10:00:11.670 [23631] ERROR - Error issuing curl_easy_perform(handle): 28

Then at around 3am it gets really fatal

Apr 10, 2021 02:51:53.662 [12025] ERROR - NAT: PMP::getPublicIP, couldn’t initialize: -3:Unable to get Gateway
Apr 10, 2021 02:51:58.580 [12023] ERROR - Error parsing content.
Apr 10, 2021 02:51:58.581 [12023] ERROR - Error parsing XML: Error parsing file.
Apr 10, 2021 02:51:58.581 [12023] ERROR - Grabber: Error obtaining device status.
Apr 10, 2021 02:51:58.584 [12023] ERROR - DVR:Device: Error refreshing existing device device://tv.plex.grabbers.tunerservice/dvb%23hdhr%231036B0DB, marking as dead.
Apr 10, 2021 02:52:00.940 [12084] ERROR - XML: Entity: line 1:
Apr 10, 2021 02:52:00.940 [12084] ERROR - XML: parser
Apr 10, 2021 02:52:00.940 [12084] ERROR - XML: error :
Apr 10, 2021 02:52:00.940 [12084] ERROR - XML: Start tag expected, ‘<’ not found
Apr 10, 2021 02:52:00.940 [12084] ERROR - XML: status=ok
Apr 10, 2021 02:52:00.940 [12084] ERROR - XML: ^
Apr 10, 2021 02:52:00.940 [12084] ERROR - Error parsing content.
Apr 10, 2021 02:52:00.941 [12084] ERROR - Error parsing XML: Error parsing file.
Apr 10, 2021 02:52:00.941 [12084] ERROR - SSDP: Error parsing device schema for http://192.168.1.59:9080
Apr 10, 2021 02:52:30.933 [12084] ERROR - XML: Entity: line 1:
Apr 10, 2021 02:52:30.933 [12084] ERROR - XML: parser
Apr 10, 2021 02:52:30.933 [12084] ERROR - XML: error :
Apr 10, 2021 02:52:30.933 [12084] ERROR - XML: Start tag expected, ‘<’ not found
Apr 10, 2021 02:52:30.933 [12084] ERROR - XML: status=ok
Apr 10, 2021 02:52:30.933 [12084] ERROR - XML: ^
Apr 10, 2021 02:52:30.933 [12084] ERROR - Error parsing content.
Apr 10, 2021 02:52:30.934 [12084] ERROR - Error parsing XML: Error parsing file.
Apr 10, 2021 02:52:30.934 [12084] ERROR - SSDP: Error parsing device schema for http://192.168.1.59:9080
Apr 10, 2021 02:53:00.360 [12084] ERROR - XML: Entity: line 1:
Apr 10, 2021 02:53:00.360 [12084] ERROR - XML: parser
Apr 10, 2021 02:53:00.360 [12084] ERROR - XML: error :
Apr 10, 2021 02:53:00.360 [12084] ERROR - XML: Start tag expected, ‘<’ not found
Apr 10, 2021 02:53:00.360 [12084] ERROR - XML: status=ok
Apr 10, 2021 02:53:00.360 [12084] ERROR - XML: ^
Apr 10, 2021 02:53:00.360 [12084] ERROR - Error parsing content.
Apr 10, 2021 02:53:00.361 [12084] ERROR - Error parsing XML: Error parsing file.
Apr 10, 2021 02:53:00.361 [12084] ERROR - SSDP: Error parsing device schema for http://192.168.1.59:9080
Apr 10, 2021 02:53:30.348 [12084] ERROR - XML: Entity: line 1:
Apr 10, 2021 02:53:30.348 [12084] ERROR - XML: parser
Apr 10, 2021 02:53:30.348 [12084] ERROR - XML: error :
Apr 10, 2021 02:53:30.348 [12084] ERROR - XML: Start tag expected, ‘<’ not found
Apr 10, 2021 02:53:30.348 [12084] ERROR - XML: status=ok
Apr 10, 2021 02:53:30.348 [12084] ERROR - XML: ^
Apr 10, 2021 02:53:30.348 [12084] ERROR - Error parsing content.
Apr 10, 2021 02:53:30.349 [12084] ERROR - Error parsing XML: Error parsing file.
Apr 10, 2021 02:53:30.349 [12084] ERROR - SSDP: Error parsing device schema for http://192.168.1.59:9080
Apr 10, 2021 02:54:00.913 [12084] ERROR - XML: Entity: line 1:
Apr 10, 2021 02:54:00.913 [12084] ERROR - XML: parser
Apr 10, 2021 02:54:00.913 [12084] ERROR - XML: error :
Apr 10, 2021 02:54:00.913 [12084] ERROR - XML: Start tag expected, ‘<’ not found
Apr 10, 2021 02:54:00.913 [12084] ERROR - XML: status=ok
Apr 10, 2021 02:54:00.913 [12084] ERROR - XML: ^
Apr 10, 2021 02:54:00.913 [12084] ERROR - Error parsing content.
Apr 10, 2021 02:54:00.914 [12084] ERROR - Error parsing XML: Error parsing file.
Apr 10, 2021 02:54:00.914 [12084] ERROR - SSDP: Error parsing device schema for http://192.168.1.59:9080

2021-04-10 03:00:24,311 (231f4f54f0) : CRITICAL (peerservice:86) - Failed to fetch data from http://127.0.0.1:32400/library/sections (most recent call last):
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/System.bundle/Contents/Code/peerservice.py”, line 38, in update_dict
main_el = XML.ElementFromURL(url, cacheTime = 0)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/parsekit.py”, line 344, in ElementFromURL
method=method,
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/networkkit.py”, line 67, in _http_request
req = self._core.networking.http_request(url, *args, **kwargs)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 346, in http_request
return HTTPRequest(self._core, url, data, h, url_cache, encoding, errors, timeout, immediate, sleep, opener, follow_redirects, method)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 118, in init
self.load()
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 158, in load
f = self._opener.open(req, timeout=self._timeout)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 429, in open
response = self._open(req, data)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 447, in _open
‘_open’, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 407, in _call_chain
result = func(*args)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1228, in http_open
return self.do_open(httplib.HTTPConnection, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1201, in do_open
r = h.getresponse(buffering=True)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 1148, in getresponse
response.begin()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 448, in begin
version, status, reason = self._read_status()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 404, in _read_status
line = self.fp.readline(_MAXLINE + 1)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/socket.py”, line 480, in readline
data = self._sock.recv(self._rbufsize)
timeout: timed out

2021-04-10 03:00:24,314 (231f4f54f0) : DEBUG (networking:143) - Requesting ‘http://127.0.0.1:32400/channels/all’
2021-04-10 03:00:44,419 (231f4f54f0) : CRITICAL (peerservice:86) - Failed to fetch data from http://127.0.0.1:32400/channels/all (most recent call last):
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/System.bundle/Contents/Code/peerservice.py”, line 38, in update_dict
main_el = XML.ElementFromURL(url, cacheTime = 0)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/parsekit.py”, line 344, in ElementFromURL
method=method,
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/networkkit.py”, line 67, in _http_request
req = self._core.networking.http_request(url, *args, **kwargs)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 346, in http_request
return HTTPRequest(self._core, url, data, h, url_cache, encoding, errors, timeout, immediate, sleep, opener, follow_redirects, method)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 118, in init
self.load()
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 158, in load
f = self._opener.open(req, timeout=self._timeout)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 429, in open
response = self._open(req, data)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 447, in _open
‘_open’, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 407, in _call_chain
result = func(*args)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1228, in http_open
return self.do_open(httplib.HTTPConnection, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1201, in do_open
r = h.getresponse(buffering=True)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 1148, in getresponse
response.begin()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 448, in begin
version, status, reason = self._read_status()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 404, in _read_status
line = self.fp.readline(_MAXLINE + 1)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/socket.py”, line 480, in readline
data = self._sock.recv(self._rbufsize)
timeout: timed out

2021-04-10 03:00:44,421 (231f4f54f0) : DEBUG (runtime:924) - Response: [200] str, 0 bytes
2021-04-10 03:00:44,427 (231f4f54f0) : DEBUG (runtime:717) - Handling request GET /system/notify/serverUpdated?host=192.168.1.83
2021-04-10 03:00:44,431 (231f4f54f0) : DEBUG (runtime:814) - Found route matching /system/notify/serverUpdated
2021-04-10 03:00:44,431 (231f4f54f0) : DEBUG (peerservice:386) - Handling server update notification (192.168.1.83)
2021-04-10 03:00:44,432 (231f4f54f0) : DEBUG (peerservice:189) - Updating servers (True/False True/True/True)
2021-04-10 03:00:44,432 (231f4f54f0) : DEBUG (peerservice:164) - Fetching the current list of servers
2021-04-10 03:00:44,434 (231f4f54f0) : DEBUG (networking:143) - Requesting ‘http://127.0.0.1:32400/servers’
2021-04-10 03:01:04,538 (231f4f54f0) : CRITICAL (runtime:889) - Exception (most recent call last):
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/runtime.py”, line 843, in handle_request
result = f(**d)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/System.bundle/Contents/Code/peerservice.py”, line 390, in handle_notify
self.update_servers(required_attribs=attrs)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/System.bundle/Contents/Code/peerservice.py”, line 195, in update_servers
servers_el = self.get_servers_el()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/System.bundle/Contents/Code/peerservice.py”, line 165, in get_servers_el
return XML.ElementFromURL(‘http://127.0.0.1:32400/servers’, cacheTime = 0)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/parsekit.py”, line 344, in ElementFromURL
method=method,
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/networkkit.py”, line 67, in _http_request
req = self._core.networking.http_request(url, *args, **kwargs)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 346, in http_request
return HTTPRequest(self._core, url, data, h, url_cache, encoding, errors, timeout, immediate, sleep, opener, follow_redirects, method)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 118, in init
self.load()
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 158, in load
f = self._opener.open(req, timeout=self._timeout)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 429, in open
response = self._open(req, data)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 447, in _open
‘_open’, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 407, in _call_chain
result = func(*args)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1228, in http_open
return self.do_open(httplib.HTTPConnection, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1201, in do_open
r = h.getresponse(buffering=True)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 1148, in getresponse
response.begin()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 448, in begin
version, status, reason = self._read_status()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 404, in _read_status
line = self.fp.readline(_MAXLINE + 1)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/socket.py”, line 480, in readline
data = self._sock.recv(self._rbufsize)
timeout: timed out

2021-04-10 03:01:04,543 (231f4f54f0) : DEBUG (runtime:924) - Response: [500] 3610 bytes
2021-04-10 03:01:59,159 (2320cf54f0) : DEBUG (runtime:1156) - Starting timed thread named ‘refresh_servers’
2021-04-10 03:01:59,160 (2320cf54f0) : DEBUG (peerservice:164) - Fetching the current list of servers
2021-04-10 03:01:59,162 (2320cf54f0) : DEBUG (networking:143) - Requesting ‘http://127.0.0.1:32400/servers’
2021-04-10 03:02:19,258 (2320cf54f0) : CRITICAL (runtime:1128) - Exception in thread named ‘refresh_servers’ (most recent call last):
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/runtime.py”, line 1126, in _start_thread
f(*args, **kwargs)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/System.bundle/Contents/Code/peerservice.py”, line 169, in refresh_servers
servers_el = self.get_servers_el()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/System.bundle/Contents/Code/peerservice.py”, line 165, in get_servers_el
return XML.ElementFromURL(‘http://127.0.0.1:32400/servers’, cacheTime = 0)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/parsekit.py”, line 344, in ElementFromURL
method=method,
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/networkkit.py”, line 67, in _http_request
req = self._core.networking.http_request(url, *args, **kwargs)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 346, in http_request
return HTTPRequest(self._core, url, data, h, url_cache, encoding, errors, timeout, immediate, sleep, opener, follow_redirects, method)
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 118, in init
self.load()
File “/data/data/com.plexapp.mediaserver.smb/Resources/Plug-ins-a97b03fad/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py”, line 158, in load
f = self._opener.open(req, timeout=self._timeout)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 429, in open
response = self._open(req, data)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 447, in _open
‘_open’, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 407, in _call_chain
result = func(*args)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1228, in http_open
return self.do_open(httplib.HTTPConnection, req)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/urllib2.py”, line 1201, in do_open
r = h.getresponse(buffering=True)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 1148, in getresponse
response.begin()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 448, in begin
version, status, reason = self._read_status()
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/httplib.py”, line 404, in _read_status
line = self.fp.readline(_MAXLINE + 1)
File “/data/user/0/com.plexapp.mediaserver.smb/Resources/Python/lib/python2.7/socket.py”, line 480, in readline
data = self._sock.recv(self._rbufsize)
timeout: timed out

2021-04-10 03:59:59,163 (2320df34f0) : DEBUG (runtime:1156) - Starting timed thread named ‘invalidation_timer’

BinaryJay · April 11, 2021, 2:00am

@BobSnot Thanks for taking the time to look at the logs. I’ve also noticed these things but can’t figure out why it’s causing Plex to basically go down. My network is a bit beefier than the standard setup people have at home, but it works flawlessly with everything and those errors about getPublicIP don’t make sense to me because while plex is up (and these errors are occurring) remote access is working just fine.

As for the second set of errors, I did some digging earlier and found that the IP it’s complaining about is a Chromecast with Google TV, and Port 9080 is a port that the Netflix app uses on Android for a built in web server - to what purpose I don’t know. To attempt to isolate these particular SSDP errors (which on these forums Plex employees have told people in the past can just be ignored) I’ve disconnected the Chromecast from my network for now - though that is hardly a good long term solution if it does indeed stop PMS from freaking out.

The other thing I find bizarre is that these are all errors related to DVR which I used to use for a short time with HDHR but have had disabled with no DVR set up at all in PMS for ages so I don’t know why it’s even involving DVR at all at this point.

The last section you identified does indeed appear to be the death throes of PMS. Caused by the SSDP errors with Netflix and the Chromecast? Don’t know yet. I suppose all I can do is leave it disconnected and see if the issue recurs or not to confirm or rule that out.

I’d still love someone from Plex to weigh in, especially on the last concrete section of python errors.

@ChuckPa @StSimm1

ChuckPa · April 11, 2021, 4:34pm

Please explain “a bit beefier than the standard” ?

I could be reading some of this incorrectly (given this is only a fragment – which is prone to misinterpretation and why i don’t like fragments)

NAT PMP error 3 - It’s not allowing the operation. PMS is asking the device what its WAN-side IP is and it’s telling PMS to “Buzz off”. If this is a pfSense box, did you grant the ACL access for PMS to make the NAT-PMP/UPnP requests ?
The error 28 is simply the downstream from the first failure.
The SSDP errors. Device at 192.168.1.59 is advertising / responding with its SSDP, which should be a XML reply, and it’s not!
The failure at 03:00:44 is the result of not being able to communicate properly

2021-04-10 03:00:44,432 (231f4f54f0) : DEBUG (peerservice:164) - Fetching the current list of servers
2021-04-10 03:00:44,434 (231f4f54f0) : DEBUG (networking:143) - Requesting ‘http://127.0.0.1:32400/servers’
2021-04-10 03:01:04,538 (231f4f54f0) : CRITICAL (runtime:889) - Exception (most recent call last):

There’s a huge chunk of information missing here - specifically PMS & Plex.tv interaction.

This is why fragments are dangerous. It’s painting an incomplete, and likely inaccurate picture.

Please obtain fresh DEBUG logs, (increasing LogNumFiles="10" is a good option) and repost.

Ref: UPnP & NAT-PMP maybe not working | Netgate Forum

BinaryJay · April 11, 2021, 5:01pm

@ChuckPa The full log dumps are attached to the OP already, I’m not sure what you mean by it only being fragments?

By beefier than standard I mean I run a Zyxel ZyWall 310 as my router/firewall, but I have the Shield TV on my regular unrestricted network on ethernet with no special rules governing over it other than the NAT rule to map the plex port to the Shield. I also run a piHole but I have every public plex domain as well as plex.direct all whitelisted there so it shouldn’t be a factor.

I have UPnP/ NAT-PMP disabled, always have and always will… I have no desire to open that Pandora’s box in my network. So that explains that, if that’s all it is. I have the main plex port mapped in NAT to the Shield, and that’s all that has ever been required to keep things running before? (That’s the default port, 32400)

For what it’s worth, I didn’t encounter the crash last night while I had that Chromecast with Google TV disconnected from the network, but I had also disabled a bunch of stuff from scheduled tasks yesterday as well.

ChuckPa · April 11, 2021, 10:35pm

Jay,
Is there any way you can re-enable tasks in a controlled way?

Obviously there’s one which is tripping it up. Trying to find it is probably going to be process of elimination since the logs don’t give any indication whatsoever

BinaryJay · April 11, 2021, 11:21pm

Yes, for tonight I’ve reconnected the Chromecast with Google TV which was the source of the SSDP errors. I’ll see if it’s still up tomorrow. If it is, I’ll re-enable the scheduled tasks that I disabled one at a time until I find PMS dead again and report back. Thanks.

BinaryJay · April 13, 2021, 1:20pm

@ChuckPa

First night I reconnected my Chromecast and it stayed up.
Second night, I re-enabled “Upgrade media analysis during maintenance” in scheduled tasks and found PMS unresponsive again in the morning. I’ve disabled it again and will confirm if it’s still alive tomorrow without that task again. The weird thing is that I have manually started Analyze on my libraries while Plex was up before and it didn’t seem to die. Is the scheduled task for this doing something different than when manually triggering analyze on the libraries?

Latest logs attached after I restarted the server.
Plex Media Server Logs_2021-04-13_09-18-12.zip (7.7 MB)

Okay so… interestingly, if I run a manual analyze on one of my libraries I get similar errors BUT it recovers. The same errors seem to just end the log without the additional information about what file it was choking on when run as part of scheduled tasks.

Overnight:

Apr 13, 2021 02:05:33.009 [10596] ERROR - [Transcoder] [matroska,webm @ 0x2992c63600] Invalid EBML number size tag 0x0a at pos 996964424 (0x3b6c7848)
Apr 13, 2021 02:05:33.855 [7294] DEBUG - handleStreamRead code 1: stream truncated
Apr 13, 2021 02:05:33.855 [7294] DEBUG - NotificationStream: Removing because of error
Apr 13, 2021 02:05:34.192 [7294] DEBUG - Completed after connection close: [192.168.1.83:40464] -3 GET /:/websockets/notifications (5 live) TLS GZIP 6145778ms 19648 bytes

This is the end of that log.

Manual run of Analyze:

Apr 13, 2021 11:05:58.842 [29779] ERROR - [Transcoder] [matroska,webm @ 0x23fa463600] Invalid EBML number size tag 0x0a at pos 996964424 (0x3b6c7848)
Apr 13, 2021 11:06:01.745 [29459] DEBUG - Jobs: '/data/user/0/com.plexapp.mediaserver.smb/Resources/Plex Transcoder' exit code for process 29804 is -9 (signal: Killed)
Apr 13, 2021 11:06:01.779 [29798] DEBUG - Streaming Resource: Terminating session 0x2dbc193818:f46ffcbb-3c3e-4432-a6c2-4b1ed1ab1ee7 which is using static transcoder slot.  Used slots is now 0
Apr 13, 2021 11:06:01.779 [29474] DEBUG - Killing job.
Apr 13, 2021 11:06:01.779 [29474] DEBUG - Signalling job ID 29804 with 9
Apr 13, 2021 11:06:01.779 [29474] DEBUG - Job was already killed, not killing again.
Apr 13, 2021 11:06:01.779 [29474] DEBUG - Stopping transcode session f46ffcbb-3c3e-4432-a6c2-4b1ed1ab1ee7
Apr 13, 2021 11:06:01.782 [29774] ERROR - IntroDetector: Failed to transcode file (-9): /storage/DISKSTATION/Shows/Star Trek - The Next Generation/Season 1/S1E09-Hide And Q.mkv
Apr 13, 2021 11:06:01.851 [29798] DEBUG - Streaming Resource: Terminated session 0x2dbc193818:f46ffcbb-3c3e-4432-a6c2-4b1ed1ab1ee7 with reason Conversion failed. The transcoder exited due to an error.

Also interesting is that this is a file that I’ve had in my library for ages and it hasn’t changed but never caused problems before. Also interesting is that the file seems to play fine in Plex.

I deleted that particular file and no longer get any of those transcoder errors when manually running analyze. If this solves the issue, awesome, BUT you may want to bring this up to development because it looks like that type of transcoder error taking place in intro detection during analyze when run as part of scheduled tasks is not handled correctly and leaving the server in a bad state.

BinaryJay · April 14, 2021, 3:28pm

PMS survived the night with all of the scheduled tasks re-enabled with that particular file gone out of my library. I won’t call this conclusive until it has survived a few more nights but it is really looking like transcoder errors during intro detection when the analysis runs as part of the scheduled tasks causes the problem. When the same scheduled tasks are run manually, the error is logged but PMS continues to function normally.

It really does appear that there is an issue with the error handling when these transcoder errors occur inside the scheduled tasks process that wasn’t a problem with previous versions of PMS (this file existed for ages in my library) - I would have expected the error to be logged and handled the same during the butler process as when running manual analysis but the same error seems to be fatal in the former context.

BinaryJay · April 15, 2021, 1:03pm

PMS is still alive this morning. That’s two nights in a row now, something it hasn’t done since a few versions ago. I’d say my problem is solved, but I still think there is a problem in the error handling of the scheduled tasks that should be looked at.

system · July 14, 2021, 1:04pm

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.

Topic		Replies	Views
I'm finding Plex server stopped every day Desktops & Laptops server-windows	59	1169	February 6, 2024
PMS turning off on its own (mac) Desktops & Laptops server-mac	56	717	November 1, 2023
PMS Crashes soon after access (Clean install) Plex Media Server server-linux	27	312	January 9, 2021
Constant not-so-random crashes of PMS Desktops & Laptops server-windows	27	369	May 31, 2022
Plex Media Server keeps Crashing Desktops & Laptops server-windows	80	6214	November 22, 2018

Why is PMS becoming unresponsive / "crashed" almost every night? Please help

Related topics