Endless transcoding/buffering

Plex Media Server Desktops & Laptops
21

No worries for the delay!

It is not. It’s a secondary partition on the same system drive where PMS is installed. However it’s been set up like this for years and I never had any issues up until now. It has 30GB of free space. I also tried transcoding from /dev/shm but it fails too. And now Direct Play also fails in Chrome Web, so… I don’t even think it’s a transcoding issue anymore, ugh…

Yes, but I never had any issues playing these files before. And the issue still occurs even if I don’t select any subtitles.

Unfortunately that’s the best I can install, the server is based on a HP ProLiant Microserver Gen8 with passive cooling and LGA 1155 socket, also the PSU is weak, like 250W max I believe. That’s literally the best I can get out of this server. But again, I never had any issues with any of these files for years now… So I don’t think it’s a performance issue.

22

Fair enough.

We walked the CPU side of the problem.
This is what I can see and you defended as I hoped you would.

I did find this in your logs but not certain. Do you have two Nvidia cards?

Mar 16, 2020 01:39:58.147 [0x7f2fde7fc700] DEBUG - [FFMPEG] - Loaded sym: cuImportExternalSemaphore
Mar 16, 2020 01:39:58.147 [0x7f2fde7fc700] DEBUG - [FFMPEG] - Loaded sym: cuDestroyExternalSemaphore
Mar 16, 2020 01:39:58.147 [0x7f2fde7fc700] DEBUG - [FFMPEG] - Loaded sym: cuSignalExternalSemaphoresAsync
Mar 16, 2020 01:39:58.147 [0x7f2fde7fc700] DEBUG - [FFMPEG] - Loaded sym: cuWaitExternalSemaphoresAsync
Mar 16, 2020 01:39:58.368 [0x7f303f03c700] WARN - JobManager: Could not find job for handle 2902
Mar 16, 2020 01:39:58.369 [0x7f2fde7fc700] ERROR - [FFMPEG] - cu->cuInit(0) failed
Mar 16, 2020 01:39:58.369 [0x7f2fde7fc700] ERROR - [FFMPEG] -  -> CUDA_ERROR_UNKNOWN: unknown error
Mar 16, 2020 01:39:58.369 [0x7f2fde7fc700] ERROR - [FFMPEG] - 
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Unknown error occurred
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - Scaled up video bitrate to 19332Kbps based on 3.000000x fudge factor.
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - MDE: Selected protocol dash; container: mp4
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - MDE: analyzing media item 29219
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - MDE: E1 - A Ruler's Melancholy: Direct Play is disabled
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - MDE: E1 - A Ruler's Melancholy: media must be transcoded in order to use the dash protocol
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - MDE: E1 - A Ruler's Melancholy: selected subtitle cannot be converted to a compatible format, burning into video stream
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - MDE: E1 - A Ruler's Melancholy: avoiding video remux due to burned subtitle stream
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - MDE: E1 - A Ruler's Melancholy: no remuxable profile found, so video stream will be transcoded
Mar 16, 2020 01:39:58.370 [0x7f2fde7fc700] DEBUG - Codecs: testing h264_nvenc (encoder)
Mar 16, 2020 01:39:58.371 [0x7f2fde7fc700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Mar 16, 2020 01:39:58.372 [0x7f2fde7fc700] DEBUG - [FFMPEG] - Loaded lib: libcuda.so.1
Mar 16, 2020 01:39:58.372 [0x7f2fde7fc700] DEBUG - [FFMPEG] - Loaded sym: cuInit

Regarding the subtitles and Chrome not directplay. Are the subtitles PGS, VOBSUB, or DVDRIP (Image based)? If so, they will never DirectPlay. Chrome doesn’t support it.

What does that leave?

23

And yes, it halts here, because I stopped the playback manually after a few seconds.

Terminated session 0x7f2f989720a0:42wayp3ftpgxlc8qn6u44t9i with reason Client stopped playback.

Normally it’s supposed to start nearly instantly. And I did wait a good few minutes on some tests I ran earlier, and playback never started on the client.
Even tho it does look like it works from the Plex Dashboard…

24

No I dont, only one Nvidia Quadro P1000.

Yes I know that. I tried PGS which makes the CPU burn the subs but like I said I also tried regular SRT or even no subtitles at all. And same results. I dont think those tests appear in these logs tho, but I can’t run additionnal tests without any subtitles or different subtitles formats, if you want!

25

Next question:

the IP addresses involved.

Mar 16, 2020 01:39:59.825 [0x7f2fde7fc700] DEBUG - Request: [10.40.0.23:45276 (WAN)] PUT

vs

Mar 16, 2020 01:35:33.259 [0x7f3036ffd700] DEBUG - Auth: authenticated user 1 as Kyhze
Mar 16, 2020 01:35:33.259 [0x7f2fdcff9700] DEBUG - Request: [10.40.0.35:49927 (Subnet)] GET /:/websockets/notifications (4 live) TLS GZIP Signed-in Token (Kyhze)

Which adapter is defined as the default for the machine?
You have both devices on the same subnet but might you be crossing subnets accidentally coming into the VM ?

PMS is declaring as a WAN connection when it should be LAN.

26

10.40.0.23 (eth0) → Server main adapter.

10.40.0.35 is my Windows 10 client. Same subnet as the server, yes.

Just to make things clear, Plex does not run in a VM. The server (the entire machine I mean) runs VMs alongside other services. It is not a purely dedicated Plex machine, I use it for several other things. So the Vmnet adapters are not to be taken into consideration here. And Plex does not run in a Docker container either, if you’re wondering.

I noticed this too, that’s strange indeed because 10.40.0.0 is LAN.

But again, I didn’t change anything since last week and it was working perfectly fine then. No change to the subnet, no change to the server, no change on the client. I really have no idea what could be causing this issue…

27

So you have a VMhost with several VM guests running. ESXi?

Something I’ve had happen when setting up VMs (and easily bumped too),
a Bridged connection gets bumped to NAT but still keeps the same IP addresses.

Can you check that please? Bridge vs NAT will change those flags in VMware

28

No no it’s just VMware Workstation and is running a Windows XP VM for various stuff I need. Nothing more. The host is a debian 10 OS on which Plex is also installed. That VM and Plex have been co-existing for a while now tho… The VM does use NAT. But I don’t see how it could interfere with Plex because Plex is running on the host. Not in a VM.

29

NAT makes it a separate network even if the numbers are the same.

You want Bridged. It makes it a peer , on the same subnet by definition.

You’ve managed all the IPs correctly.

PMS is very sensitive to this and maybe what you’re seeing now with the underpinnings of PMS being cleaned up for full IPv6 support.

30

What happens (or did you say that and I can’t find it), playing in FireFox?

Also, with javascript blockers disabled ?

The new Web player is a bit different than it has been. It’s using the new API into Chrome.

31

I just tried to change the VM to use Bridged instead of NAT (confirmed on the VM itself, it did change to bridged, it gets an IP address from my “real” DHCP server and I can see the VM on my router) but no change for the Plex issue. Could disable IPv6 support in Plex settings work then? I’ll test it at least.

I did not try FireFox because I don’t use it so I don’t even have it installed. But I did try with Edge, and the Android app, along with the Windows app, and I get the issue on all of these clients. And I only use uBlock Origin, but it’s disabled.

32

The last error I see in your logs is this

The files are there, but they aren’t.

Mar 16, 2020 01:42:27.861 [0x7f30377fe700] DEBUG - Auth: authenticated user 1 as Kyhze
Mar 16, 2020 01:42:27.861 [0x7f2fd57fa700] DEBUG - Request: [10.40.0.35:50013 (Subnet)] GET /statistics/bandwidth?timespan=6 (9 live) TLS GZIP Signed-in Token (Kyhze)
Mar 16, 2020 01:42:27.868 [0x7f30377fe700] DEBUG - Completed: [10.40.0.35:50013] 200 GET /statistics/bandwidth?timespan=6 (9 live) TLS GZIP 7ms 2959 bytes (pipelined: 122)
Mar 16, 2020 01:42:28.197 [0x7f3036ffd700] DEBUG - Auth: authenticated user 1 as Kyhze
Mar 16, 2020 01:42:28.197 [0x7f2fd67fc700] DEBUG - Request: [10.40.0.35:50013 (Subnet)] GET /statistics/bandwidth?timespan=6 (9 live) TLS GZIP Signed-in Token (Kyhze)
Mar 16, 2020 01:42:28.205 [0x7f3036ffd700] DEBUG - Completed: [10.40.0.35:50013] 200 GET /statistics/bandwidth?timespan=6 (9 live) TLS GZIP 7ms 2959 bytes (pipelined: 123)
Mar 16, 2020 01:42:28.606 [0x7f2f717fe700] DEBUG - Request: [10.40.0.35:50013 (Subnet)] GET /video/:/transcode/universal/dash/t709wqrc4x40l98dsibf7s70/0/0.m4s (9 live) TLS GZIP Signed-in
Mar 16, 2020 01:42:28.606 [0x7f30377fe700] DEBUG - Completed: [10.40.0.35:50013] 404 GET /video/:/transcode/universal/dash/t709wqrc4x40l98dsibf7s70/0/0.m4s (9 live) TLS GZIP 0ms 458 bytes (pipelined: 124)
Mar 16, 2020 01:42:28.753 [0x7f30377fe700] DEBUG - Completed: [10.40.0.35:49988] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (9 live) TLS GZIP 20000ms 5 bytes (pipelined: 18)
Mar 16, 2020 01:42:28.762 [0x7f3036ffd700] DEBUG - Auth: authenticated user 1 as Kyhze
Mar 16, 2020 01:42:28.762 [0x7f2fdcff9700] DEBUG - Request: [10.40.0.35:49988 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (9 live) TLS GZIP Signed-in Token (Kyhze)
Mar 16, 2020 01:42:28.762 [0x7f2fdcff9700] DEBUG - Content-Length is -1 (of total: -1).
Mar 16, 2020 01:42:28.870 [0x7f2fd77fe700] DEBUG - Request: [10.40.0.35:50013 (Subnet)] GET /video/:/transcode/universal/dash/t709wqrc4x40l98dsibf7s70/1/initial.mp4 (9 live) TLS GZIP Signed-in
Mar 16, 2020 01:42:28.870 [0x7f30377fe700] DEBUG - Completed: [10.40.0.35:50013] 404 GET /video/:/transcode/universal/dash/t709wqrc4x40l98dsibf7s70/1/initial.mp4 (9 live) TLS GZIP 0ms 458 bytes (pipelined: 125)
Mar 16, 2020 01:42:29.153 [0x7f2fde7fc700] DEBUG - Request: [10.40.0.35:50013 (Subnet)] GET /video/:/transcode/universal/dash/w0pdljkb8xenirkkvknzoqq7/1/0.m4s (9 live) TLS GZIP Signed-in
Mar 16, 2020 01:42:29.153 [0x7f3036ffd700] DEBUG - Completed: [10.40.0.35:50013] 404 GET /video/:/transcode/universal/dash/w0pdljkb8xenirkkvknzoqq7/1/0.m4s (9 live) TLS GZIP 0ms 458 bytes (pipelined: 126)
Mar 16, 2020 01:42:29.202 [0x7f30377fe700] DEBUG - Auth: authenticated user 1 as Kyhze
Mar 16, 2020 01:42:29.202 [0x7f2fd67fc700] DEBUG - Request: [10.40.0.35:50013 (Subnet)] GET /statistics/bandwidth?timespan=6 (9 live) TLS GZIP Signed-in Token (Kyhze)
Mar 16, 2020 01:42:29.210 [0x7f30377fe700] DEBUG - Completed: [10.40.0.35:50013] 200 GET /statistics/bandwidth?timespan=6 (9 live) TLS GZIP 7ms 2974 bytes (pipelined: 127)
Mar 16, 2020 01:42:29.397 [0x7f2fd57fa700] DEBUG - Request: [10.40.0.35:50013 (Subnet)] GET /video/:/transcode/universal/dash/t709wqrc4x40l98dsibf7s70/0/initial.mp4 (9 live) TLS GZIP Signed-in

As you know, “404” = not found (HTTP)

You did say 30GB is free on that transcoder_temp partition?
Can you please verify the transcoder temp actually goes there?

33

Yep, I did notice this too, as mentioned in a few posts ago.

I already did. It does write to the partition with no issues. When I start a stream I can see it grow, and I can see all the chunks being created.

Like I mentioned earlier too, I even tried to change the transcoding directory to /dev/shm just to test, and same thing, I could see the files being created in there too. But same issue.

To me it does look like the root cause of the issue is around the fact that the client gets a 404 whenever it tries to access the transcoded data. But that’s very odd. I don’t see why. I just tried with IPv6 disabled in the Plex settings btw, but no change either.

34

At this point I am very close to try restoring an old (1 month old) backup of the entire server and see if I still experience the issue haha :sweat_smile:

35

which is easier?

36

I don’t think it’s the server. I think it’s external

37

I guess it depends on whether you have a lead on the 404 error or not. But if I’m gonna restore the server I’ll do it tomorrow, it’s pretty late here!

38

Totally understand.

Go the path of least resistance.

I’d keep this server off to the side just in case. Do a hot-swap.

the 404 implies file locking isn’t being respected. The player is going for the file before it’s ready to be read.

39

crap… how is that mount performed?

Standard EXT / host based? (think I asked)

40

Sorry for the late reply, I got locked out of the thread because I exceeded the maximum limit of posts for my first day of use apparently… I tried to PM you to inform you of this but it seems you’ve turned PMs off :stuck_out_tongue:

Anyways, in the meantime I tried to revert to a full backup of the server (quite recent one from last week) and… it worked. I have no idea why… And no idea what could have been causing this issue. So case closed, but it kinda bothers me not knowing what exactly happened… Oh well!

Thanks a lot for your help tho! :slight_smile: