Plex buffering then failing to play randomly

Server Version#: plexmediaserver-1.20.3.3483-211702a9f.x86_64.rpm (CentOS Linux release 8.2.2004 (Core))
Player Version#: Roku Express Plex app. Maybe version 6.6.12.6662-64d4a08ac

I recently Changed out my OS disks (reinstalled the OS and Plex) and I moved my plex from CentOS7 on spinning disks to CentOS8 on SSDs. I believe I followed these steps https://support.plex.tv/articles/201370363-move-an-install-to-another-system/ correctly and everything seems to be working.

The problem I’m having videos that never buffered before are now randomly buffering then failing to play shortly after. Some times its fine, some times its not. Here are the logs that I can see when the error happens.

Oct 25, 2020 08:48:51.936 [0x7f6af67fc700] WARN - Got a request to stop a transcode session without a session GUID (or with an invalid one).
#Above I stopped playing something above and re-started the same video when you see the fontselect error.
Oct 25, 2020 08:48:53.150 [0x7f6af5ffb700] ERROR - [Transcoder] [Parsed_inlineass_2 @ 0x2091680] fontselect: Using default font family: (Arial, 400, 0) -> /usr/lib/plexmediaserver/Resources/Fonts/DejaVuSans-Regular.ttf, 0, DejaVuSans

Oct 25, 2020 08:51:00.755 [0x7f6b06c77700] ERROR - getaddrinfo(192-168-0-3.abcdefghijklmnopqrstuvwxyz012345.plex.direct) failed: -2
Oct 25, 2020 08:51:23.022 [0x7f6b07478700] WARN - NAT: PMP, timed out waiting for response.
Oct 25, 2020 08:51:26.024 [0x7f6b07478700] ERROR - Error issuing curl_easy_perform(handle): 28
#Plex app on roku started to buffer around here but fixed itself within ~30 sec

Oct 25, 2020 08:55:03.401 [0x7f6ae3fff700] INFO - AutoUpdate: no updates available
Oct 25, 2020 08:55:14.032 [0x7f6a0effd700] INFO - AutoUpdate: no updates available
Oct 25, 2020 09:00:05.575 [0x7f6ab97fa700] ERROR - getaddrinfo(192-168-0-3.abcdefghijklmnopqrstuvwxyz012345.plex.direct) failed: -2
Oct 25, 2020 09:00:27.847 [0x7f6ab97fa700] WARN - NAT: PMP, timed out waiting for response.
Oct 25, 2020 09:00:30.848 [0x7f6ab97fa700] ERROR - Error issuing curl_easy_perform(handle): 28
Oct 25, 2020 09:22:56.150 [0x7f6b04e44700] ERROR - [Transcoder] [Parsed_inlineass_2 @ 0x2091680] fontselect: Using default font family: (Arial, 400, 100) -> /usr/lib/plexmediaserver/Resources/Fonts/DejaVuSans-Regular.ttf, 0, DejaVuSans
Oct 25, 2020 09:23:39.632 [0x7f6a9bfff700] ERROR - getaddrinfo(192-168-0-3.abcdefghijklmnopqrstuvwxyz012345.plex.direct) failed: -2
Oct 25, 2020 09:23:41.352 [0x7f6a9b7fe700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Oct 25, 2020 09:23:41.453 [0x7f6a9b7fe700] INFO - Network Service: Abandoning browse socket, it was closed.
Oct 25, 2020 09:23:41.453 [0x7f6a9b7fe700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Oct 25, 2020 09:23:41.553 [0x7f6a9b7fe700] INFO - Network Service: Abandoning browse socket, it was closed.
Oct 25, 2020 09:24:01.907 [0x7f6a7f7fe700] WARN - NAT: PMP, timed out waiting for response.
Oct 25, 2020 09:24:04.908 [0x7f6a7f7fe700] ERROR - Error issuing curl_easy_perform(handle): 28
Oct 25, 2020 09:25:57.715 [0x7f6b07c79700] WARN - JobManager: Could not find job for handle 135093
Oct 25, 2020 09:25:59.808 [0x7f6b07c79700] WARN - JobManager: Could not find job for handle 135133
Oct 25, 2020 09:26:01.307 [0x7f6b07c79700] WARN - JobManager: Could not find job for handle 135160
Oct 25, 2020 09:26:02.529 [0x7f6b07c79700] WARN - JobManager: Could not find job for handle 135182
#Roku plex died here, I assume after the local cache ran out.

I can clearly see that I have a network issue, I guess the socket was killed by SOMETHING right? The server it self was bored, I have lots of free RAM and was using about 10% CPU at the time. No Errors or anything in server logs from what I can see, no IO wait, nothing that I can tell would cause this.

I’m thinking my problem has something to do with the move to a new OS/Disks but I’m not sure how to solve it. Searching on the net hasn’t helped me and so I’m wondering if you guys know how I can solve this or have suggestions for me to look into. My current guess is the getaddrinfo error.

[root@03 Logs]# grep "ERROR - getaddrinfo" Plex\ Media\ Server.log | wc -l
22
[root@03 Logs]#

thanks!

May I have the full DEBUG logs ZIP which captures these issues?
(you need to turn DEBUG logging back on – keeping VERBOSE OFF)

I cannot diagnose from a snippet

PS: Nothing is saved by turning Debug off. Log file sizes are fixed.

Sure, let me just enable it, stop plex, clean up the logs, start plex and try to replicate the issue. Once I’ve done this I’ll “download logs” from the Troubleshooting area of the Web UI.

Just to note, my wifi network (roku) and LAN network(plex) are separated by PFSense, though I have no blocking rules between the two. However, I did recently block everything but TCP/UDP 53 on the firewall (edit: with the destination the FW/Gateway so that it was ONLY used for DNS and blocked access to stuff like the web interface.) only on the wifi side. I’ve since removed this rule and thought I fixed the issue but that seems unlikely.

To determine the external IPv4 address, or to request a port mapping, a NAT-PMP client sends its request packet to port 5351 of its configured gateway address, and waits 250 ms for a response. If no NAT-PMP response is received from the gateway after 250 ms, the client retransmits its request and waits 500 ms.

Okay, here you are. I believe they’re attached.

Server Log time:
~~13h51 - buffering
13h53 - buffering
13h54 - failed.
15h55 - download logs from webUI

about 15Min into a movie.
Plex Media Server Logs_2020-10-25_13-55-08.zip (179.4 KB)

Anyone have any ideas?

My next guess is to downgrade the plex server to see if that fixes my problem. I cant see why it would be a later version of CentOS or the SSD disks =\

Thank you for the logs.

  1. I see the transcoder running to convert the audio – Roku.
  2. The transcoder loads up the Roku buffers, gets ahead itself, then goes to sleep – normal.
  3. 13:53 - transcoder buffer filling again and going to sleep
Oct 25, 2020 13:53:41.303 [0x7f19b7fff700] DEBUG - [Transcode] Transcoder segment range: 0 - 1030 (1030)
Oct 25, 2020 13:53:41.303 [0x7f19fe507700] DEBUG - [Transcode] Transcoder segment range: 0 - 1031 (1030)
Oct 25, 2020 13:53:41.318 [0x7f19b6ffd700] DEBUG - [Transcode] Session c7958c8f-99ed-450d-b05b-6bfd9103fc49-1 (3) is throttling
Oct 25, 2020 13:53:41.318 [0x7f19b67fc700] DEBUG - [Transcoder] Throttle - Going into sloth mode.
Oct 25, 2020 13:53:42.106 [0x7f19fdd06700] DEBUG - Auth: authenticated user 1 as EhSea
Oct 25, 2020 13:53:42.106 [0x7f19b67fc700] DEBUG - Request: [192.168.10.124:33205 (WAN)] GET /:/timeline?playbackTime=835000&time=876000&duration=7244448&state=playing&ratingKey=33570&key=%2Flibrary%2Fmetadata%2F33570&playQueueItemID=177554 (10 live) GZIP Signed-in Token (EhSea)
Oct 25, 2020 13:53:42.107 [0x7f19b67fc700] DEBUG - Client [061a544b99f765441535d93bd42f4913] reporting timeline state playing, progress of 876000/7244448ms for guid=, playbackTime=835000ms ratingKey=33570 url=, key=/library/metadata/33570, containerKey=, metadataId=33570, source=
Oct 25, 2020 13:53:42.107 [0x7f19b67fc700] DEBUG - Play progress on 33570 'Hot Fuzz' - got played 876000 ms by account 1!
Oct 25, 2020 13:53:42.107 [0x7f19b67fc700] DEBUG - [Now] User is EhSea (ID: 1)
Oct 25, 2020 13:53:42.107 [0x7f19b67fc700] DEBUG - [Now] Device is Roku (Express).
Oct 25, 2020 13:53:42.107 [0x7f19b67fc700] DEBUG - [Now] Profile is Roku-7.x

Notice the IP address:

Request: [192.168.10.124:33205 (WAN)] 

It changes state between LAN and WAN. This should not happen.

What are the LAN IP addresses of this server ?
Is it in a VM ?

The LAN ip of Plex is 192.168.0.3

The WLAN ip of Roku is 192.168.10.124

my wan is 24.X.X.X

No, It is not a VM.
MOBO: MSI B450I GAMING PLUS AC
CPU: AMD Ryzen 5 2400G with Radeon Vega Graphics
RAM: Corsair CMK32GX4M2D3000C16 Vengeance LPX 32GB (2 x 16GB) DDR4 3000

plugged directly into LAN of NetGate SG-1100. Wifi is UBIQUITI UAP-AC-LITE on the OPT port

I do block everything but SSH, HTTP(S), and TCP 32400 inbound on 192.168.0.3 and roku does whatever it wants.

Maybe because its a different network it’s considered as a WAN connection? seems to be taking the correct path to Plex.

Oct 26, 2020 13:00:33.435 [0x7fea497fa700] DEBUG - Transcoder segment range: 0 - 1969 (1969)
Oct 26, 2020 13:00:33.435 [0x7fea4a7fc700] DEBUG - Transcoder segment range: 0 - 1970 (1969)
Oct 26, 2020 13:00:35.505 [0x7feabb7fe700] DEBUG - Auth: authenticated user 1 as EhSea
Oct 26, 2020 13:00:35.505 [0x7fea4a7fc700] DEBUG - Request: [192.168.10.124:40669 (WAN)] GET /video/:/transcode/universal/session/94e9dd51-7bf8-4913-aebb-897c9a20f813-556/base/01842.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (11 live) Signed-in Token (EhSea)
Oct 26, 2020 13:00:35.505 [0x7fea4a7fc700] DEBUG - Asked for segment 1842 from session.
Oct 26, 2020 13:00:35.505 [0x7fea4a7fc700] DEBUG - Returning segment 1842 from session
Oct 26, 2020 13:00:35.505 [0x7fea4a7fc700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-94e9dd51-7bf8-4913-aebb-897c9a20f813-556-45e3242a-4222-43d5-9330-a1c8aa63fbf9/media-01842.ts is 1755168 (of total: 1755168).
Oct 26, 2020 13:00:35.507 [0x7feabb7fe700] DEBUG - Completed: [192.168.10.124:40669] 200 GET /video/:/transcode/universal/session/94e9dd51-7bf8-4913-aebb-897c9a20f813-556/base/01842.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (11 live) 1ms 1755168 bytes (pipelined: 171)
Oct 26, 2020 13:00:35.507 [0x7feabb7fe700] DEBUG - Removed transcode data consumer, active count 1 => 0

So, I still have NO idea what’s going on. I cleared IPTables status, started watching the same movie and we have:

[root@03 ~]#  iptables -nvL
Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
 576K   74M ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0            state RELATED,ESTABLISHED
    0     0 ACCEPT     icmp --  *      *       0.0.0.0/0            0.0.0.0/0           
 6579  395K ACCEPT     all  --  lo     *       0.0.0.0/0            0.0.0.0/0           
    2   120 ACCEPT     tcp  --  *      *       192.168.0.0/16       0.0.0.0/0            state NEW tcp dpt:22
  188 11280 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0            state NEW tcp dpt:32400
    0     0 ACCEPT     tcp  --  *      *       192.168.10.124       0.0.0.0/0            tcp dpt:32400
    0     0 DROP       all  --  *      *       0.0.0.0/0            0.0.0.0/0           

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         

Nothing is blocking anything between WLAN/LAN in any direction on the FW. This means that I’m not dropping any expected syn requests. the Movie still buffers and fails.

I tried another time where I drop the connection between WLAN and LAN on the FW, Plex just restarts the connection on a new source port like nothing happened.

I downgraded to plexmediaserver-1.19.3.2764-ef515a800.x86_64.rpm and I still have the same problem.

Now I think something is wrong with CentOS8 or the SSDs I put in.

Edit:

maybe something is killing it?
Oct 26, 2020 14:33:18.116 [0x7feac0f64700] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 165593 is -9 (signal: Killed)

Edit 2: That happens when I stop the video properly so that’s not it.

I’ve tried different clients (smart TV, Xbox), even my laptop plugged into the same network using the browser player. All experience similar issues.

I’m going to try a CentOS7 VM next, move plex server to that as I don’t really want to re-install my base OS =\

Puttting it in a VM isn’t going to help when the base OS is having problems

Please recreate that failure from Centos 8 again, capture the logs, and attach the ZIP.
I’d like to see them.

FWIW: Plex does not like multiple home LAN subnets unless you specifically tell it about them. By default, it stays on the default adapter’s LAN. Also remember, broadcast packets don’t cross subnet boundaries.

I’ve never considered that Plex being in a different broadcast domain then my player as a problem. I understand I miss out on things like casting from a computer and what not but I never used that stuff anyway. I also prefer to keep my WIFI network and LAN network separate… If required I can tell Plex about my WIFI /24 network but I’m not sure how, nor have I ever needed to do that before.

Here is the buffer issue again. I stopped the plex service, cleaned up the logs, started plex, then started watching one thing, stopped half way though and started watching another TV show. Near the end it started to buffer again, played for ~2 seconds, started to buffer a second time and quit. I walked over to my PC and downloaded the logs.

Plex Media Server Logs_2020-10-27_19-52-00.zip (511.5 KB)

I’m curious why you think a VM will not resolve the problem. as far as I understand it the only thing that changed between when things were fine is the OS disks and version of the OS. I don’t (yet) consider the SSDs the problem so it must be some package in CentOS8 that doesn’t play well with Plex.

A trick I use:

  1. Subnet A = 192.168.0.x, Subnet B = 192.168.1.x
  2. All hosts , except PMS host, have a /24 subnet mask
  3. The PMS host has a /23 (it can see both subnets as if one subnet)

Reviewing your logs now.

Looking at your Logs:

  1. If you want to merge subnets as I do, 192.168.10.x and 192.168.11.x would work
    (the trick is toggling the LSB)

  2. The roku is definitely having fits.

Oct 27, 2020 19:40:45.608 [0x7fdf72ffd700] DEBUG - [Now] User is EhSea (ID: 1)
Oct 27, 2020 19:40:45.608 [0x7fdf72ffd700] DEBUG - [Now] Device is Roku (Express).
Oct 27, 2020 19:40:45.608 [0x7fdf72ffd700] DEBUG - [Now] Profile is Roku-7.x
Oct 27, 2020 19:40:45.608 [0x7fdf72ffd700] DEBUG - [Now] Updated play state for /library/metadata/21347.
Oct 27, 2020 19:40:45.608 [0x7fdf72ffd700] DEBUG - Statistics: (154ad7a9a4370ae28e7848c8972b01c6) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Oct 27, 2020 19:40:45.611 [0x7fe0263b3700] DEBUG - Completed: [192.168.10.112:43372] 200 GET /:/timeline?playbackTime=20000&time=1734000&state=playing&ratingKey=21347&key=%2Flibrary%2Fmetadata%2F21347&col=1&row=1&context=home%3Ahub.home.ondeck&duration=2564864&playQueueItemID=178603 (10 live) TLS GZIP 5ms 496 bytes (pipelined: 2)
Oct 27, 2020 19:40:47.295 [0x7fe0263b3700] DEBUG - Auth: authenticated user 2995921 as akutzner
Oct 27, 2020 19:40:47.295 [0x7fdf72ffd700] DEBUG - Request: [XXX.XXX.XXX.XXX.58733 (WAN)] GET /:/eventsource/notifications (11 live) TLS Signed-in Token (akutzner)
Oct 27, 2020 19:40:47.295 [0x7fdf72ffd700] DEBUG - Content-Length is -1 (of total: -1).
Oct 27, 2020 19:40:48.779 [0x7fe026bb4700] DEBUG - handleStreamWrite code 104: Connection reset by peer
Oct 27, 2020 19:40:48.779 [0x7fe026bb4700] DEBUG - NotificationStream: Removing because of error

->> Oct 27, 2020 19:40:48.779 [0x7fe026bb4700] DEBUG - handleStreamWrite code 104: Connection reset by peer

Is this the 9.4.0 firmware? (I know of it due to an audio regression. I wonder if there’s yet another regression?)

Alright, After work tonight I’ll introduce a switch between my FW and WIFI AP so that I can plug plex directly into the same network. I’ll just let it DHCP and update my external NAT for the new local IP. From here I’ll try watching things, in either case I’ll report back. Personally, the two networks have never been a problem so it’ll be interesting if this solves it.

The roku? I just powered it on and its:

Model 3900X - Roku Express
Software Version - 9.3.0 build 4194-51

Roku Plex is 6.6 build 12 in settings it shows 6.6.12.6662-64d4a08ac

edit: I’m going to try and get a new public IP too and sed it out from the logs in the future.

Same network same problem. 13h37
plex: 192.168.10.3
roku: 192.168.10.112

Plex Media Server Logs_2020-10-28_13-38-14.zip (46.9 KB)

Alright, I’ve undone everything, It’s back on the LAN and roku on WLAN, firewalls fixed, SELinux enabled, everything back to the way it was when I started to troubleshoot. Maybe even a little more clean.

While on my phone on reddit last night I found a link to the a thread here about the roku preview channel of Plex. The thread listed the change log/bug fixes and the last post was a day ago so I thought it’d try it out. It’s 2 versions ahead of stable (v16 instead of v14 IIRC). I’d post it here but that was last night and I dont seem to have it any more… Here’s the second link from a search that should help.

My smartTV still has problems with playing some videos but I’ve bought a couple PIs to install rasplex and I’m hopeful that’ll clear up the rest of my problems. btw flirc is Amazing, usb IR reader to work with any remote. I use to use it until I got a smartTV+Roku but now I’m getting a pi with wifi :slight_smile: Hopefully someone got Netflix working with the PI/rasplex too.

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