I’ve been having trouble playing some 4K videos, but I feel that my server should be powerful enough, and I’m not running much else on it. So I looked into it a bit, and came on a Plex support document that led me to check the logs for speed, which showed me this seemingly strange pattern. As I understand it, the server only throttles a transcode when it’s running faster than necessary, which, at almost 4x, makes sense. But it appears to be throttling all the way down to 0.0, leading to a buffering problem.
My server has a slightly older FX 4100 chip (4 cores, 3.6 GHz) and 12GB DDR3 RAM with a 4GB RX 480 discreet GPU.
Server Version#: 1.14.1.5488
Player Version#: Plex for LG 3.80.1 / webOS 4.1.0
NOTE: I had to turn on verbose logging to see transcode speeds, but just including a small sample of logs below:
Dec 31, 2018 06:19:20.437 [4504] VERBOSE - * speed => 3.9
Dec 31, 2018 06:19:20.437 [4504] VERBOSE - * vdec_hw_status => 0
Dec 31, 2018 06:19:20.438 [4504] VERBOSE - It took 0.0 sec to serialize a list with 0 elements.
Dec 31, 2018 06:19:20.438 [12180] DEBUG - Completed: [127.0.0.1:62094] 206 PUT /video/:/transcode/session/bif/e5f992cf-bd32-4669-b2bb-dadee9e4482d/progress?progress=81.8&size=-22&remaining=269&vdec_packets=109898&vdec_sw_ok=109893&speed=3.9&vdec_hw_status=0 (14 live) 3ms 355 bytes (pipelined: 1860) (range: bytes=0-)
Dec 31, 2018 06:19:20.605 [12184] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Dec 31, 2018 06:19:20.605 [12184] VERBOSE - Auth: Came in with the master token, authorization succeeded.
Dec 31, 2018 06:19:20.607 [9728] DEBUG - Request: [127.0.0.1:51994 (Loopback)] PUT /video/:/transcode/session/9nagdpwkkmq2b7btlvlo4eqi/738ce64b-0ce8-4ef2-a14d-778a42b29120/progress?progress=2.4&size=-22&remaining=-1&vdec_packets=1494&vdec_hw_ok=1487&speed=0.0&vdec_hw_status=1 (14 live) Signed-in Token (BlaineKyle)
Dec 31, 2018 06:19:20.607 [9728] VERBOSE - * User-Agent => Lavf/58.9.100
Dec 31, 2018 06:19:20.607 [9728] VERBOSE - * Accept => /
Dec 31, 2018 06:19:20.608 [9728] VERBOSE - * Range => bytes=0-
Dec 31, 2018 06:19:20.608 [9728] VERBOSE - * Connection => keep-alive
Dec 31, 2018 06:19:20.608 [9728] VERBOSE - * Host => 127.0.0.1:32400
Dec 31, 2018 06:19:20.609 [9728] VERBOSE - * Icy-MetaData => 1
Dec 31, 2018 06:19:20.610 [9728] VERBOSE - * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Dec 31, 2018 06:19:20.610 [9728] VERBOSE - * progress => 2.4
Dec 31, 2018 06:19:20.611 [9728] VERBOSE - * size => -22
Dec 31, 2018 06:19:20.611 [9728] VERBOSE - * remaining => -1
Dec 31, 2018 06:19:20.611 [9728] VERBOSE - * vdec_packets => 1494
Dec 31, 2018 06:19:20.611 [9728] VERBOSE - * vdec_hw_ok => 1487
Dec 31, 2018 06:19:20.612 [9728] VERBOSE - * speed => 0.0
Dec 31, 2018 06:19:20.612 [9728] VERBOSE - * vdec_hw_status => 1
Dec 31, 2018 06:19:20.613 [9728] VERBOSE - We want 60 seconds ahead, last returned was 93.009678 and max is 118.034700.
Dec 31, 2018 06:19:20.613 [9728] VERBOSE - It took 0.0 sec to serialize a list with 0 elements.
Dec 31, 2018 06:19:20.614 [12180] DEBUG - Completed: [127.0.0.1:51994] 206 PUT /video/:/transcode/session/9nagdpwkkmq2b7btlvlo4eqi/738ce64b-0ce8-4ef2-a14d-778a42b29120/progress?progress=2.4&size=-22&remaining=-1&vdec_packets=1494&vdec_hw_ok=1487&speed=0.0&vdec_hw_status=1 (14 live) 8ms 355 bytes (pipelined: 327) (range: bytes=0-)
Dec 31, 2018 06:19:20.942 [12180] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Dec 31, 2018 06:19:20.942 [12180] VERBOSE - Auth: Came in with the master token, authorization succeeded.
Dec 31, 2018 06:19:20.943 [2200] DEBUG - Request: [127.0.0.1:62094 (Loopback)] PUT /video/:/transcode/session/bif/e5f992cf-bd32-4669-b2bb-dadee9e4482d/progress?progress=81.9&size=-22&remaining=260&vdec_packets=109925&vdec_sw_ok=109920&speed=3.9&vdec_hw_status=0 (13 live) Signed-in Token (BlaineKyle)
Dec 31, 2018 06:19:20.943 [2200] VERBOSE - * User-Agent => Lavf/58.9.100
Dec 31, 2018 06:19:20.943 [2200] VERBOSE - * Accept => /
Dec 31, 2018 06:19:20.943 [2200] VERBOSE - * Range => bytes=0-
Dec 31, 2018 06:19:20.944 [2200] VERBOSE - * Connection => keep-alive
Dec 31, 2018 06:19:20.945 [2200] VERBOSE - * Host => 127.0.0.1:32400
Dec 31, 2018 06:19:20.945 [2200] VERBOSE - * Icy-MetaData => 1
Dec 31, 2018 06:19:20.945 [2200] VERBOSE - * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Dec 31, 2018 06:19:20.945 [2200] VERBOSE - * progress => 81.9
Dec 31, 2018 06:19:20.945 [2200] VERBOSE - * size => -22
Dec 31, 2018 06:19:20.946 [2200] VERBOSE - * remaining => 260
Dec 31, 2018 06:19:20.946 [2200] VERBOSE - * vdec_packets => 109925
Dec 31, 2018 06:19:20.946 [2200] VERBOSE - * vdec_sw_ok => 109920
Dec 31, 2018 06:19:20.946 [2200] VERBOSE - * speed => 3.9
Dec 31, 2018 06:19:20.946 [2200] VERBOSE - * vdec_hw_status => 0
Dec 31, 2018 06:19:20.947 [2200] VERBOSE - It took 0.0 sec to serialize a list with 0 elements.
Dec 31, 2018 06:19:20.947 [12184] DEBUG - Completed: [127.0.0.1:62094] 206 PUT /video/:/transcode/session/bif/e5f992cf-bd32-4669-b2bb-dadee9e4482d/progress?progress=81.9&size=-22&remaining=260&vdec_packets=109925&vdec_sw_ok=109920&speed=3.9&vdec_hw_status=0 (13 live) 4ms 355 bytes (pipelined: 1861) (range: bytes=0-)
Dec 31, 2018 06:19:21.149 [12180] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Dec 31, 2018 06:19:21.149 [12180] VERBOSE - Auth: Came in with the master token, authorization succeeded.
Dec 31, 2018 06:19:21.150 [10576] DEBUG - Request: [127.0.0.1:51994 (Loopback)] PUT /video/:/transcode/session/9nagdpwkkmq2b7btlvlo4eqi/738ce64b-0ce8-4ef2-a14d-778a42b29120/progress?progress=2.4&size=-22&remaining=-1&vdec_packets=1499&vdec_hw_ok=1492&speed=0.0&vdec_hw_status=1 (13 live) Signed-in Token (BlaineKyle)
Dec 31, 2018 06:19:21.150 [10576] VERBOSE - * User-Agent => Lavf/58.9.100
Dec 31, 2018 06:19:21.150 [10576] VERBOSE - * Accept => /
Dec 31, 2018 06:19:21.150 [10576] VERBOSE - * Range => bytes=0-
Dec 31, 2018 06:19:21.150 [10576] VERBOSE - * Connection => keep-alive
Dec 31, 2018 06:19:21.151 [10576] VERBOSE - * Host => 127.0.0.1:32400
Dec 31, 2018 06:19:21.151 [10576] VERBOSE - * Icy-MetaData => 1
Dec 31, 2018 06:19:21.151 [10576] VERBOSE - * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Dec 31, 2018 06:19:21.151 [10576] VERBOSE - * progress => 2.4
Dec 31, 2018 06:19:21.152 [10576] VERBOSE - * size => -22
Dec 31, 2018 06:19:21.152 [10576] VERBOSE - * remaining => -1
Dec 31, 2018 06:19:21.152 [10576] VERBOSE - * vdec_packets => 1499
Dec 31, 2018 06:19:21.152 [10576] VERBOSE - * vdec_hw_ok => 1492
Dec 31, 2018 06:19:21.152 [10576] VERBOSE - * speed => 0.0
Dec 31, 2018 06:19:21.153 [10576] VERBOSE - * vdec_hw_status => 1
Dec 31, 2018 06:19:21.153 [10576] VERBOSE - We want 60 seconds ahead, last returned was 93.009678 and max is 118.034700.
Dec 31, 2018 06:19:21.154 [10576] VERBOSE - It took 0.0 sec to serialize a list with 0 elements.
Dec 31, 2018 06:19:21.155 [12184] DEBUG - Completed: [127.0.0.1:51994] 206 PUT /video/:/transcode/session/9nagdpwkkmq2b7btlvlo4eqi/738ce64b-0ce8-4ef2-a14d-778a42b29120/progress?progress=2.4&size=-22&remaining=-1&vdec_packets=1499&vdec_hw_ok=1492&speed=0.0&vdec_hw_status=1 (13 live) 5ms 355 bytes (pipelined: 328) (range: bytes=0-)
Dec 31, 2018 06:19:21.498 [12184] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Dec 31, 2018 06:19:21.498 [12184] VERBOSE - Auth: Came in with the master token, authorization succeeded.
Dec 31, 2018 06:19:21.499 [3200] DEBUG - Request: [127.0.0.1:62094 (Loopback)] PUT /video/:/transcode/session/bif/e5f992cf-bd32-4669-b2bb-dadee9e4482d/progress?progress=81.9&size=-22&remaining=270&vdec_packets=109975&vdec_sw_ok=109970&speed=3.6&vdec_hw_status=0 (13 live) Signed-in Token (BlaineKyle)
Dec 31, 2018 06:19:21.499 [3200] VERBOSE - * User-Agent => Lavf/58.9.100
Dec 31, 2018 06:19:21.499 [3200] VERBOSE - * Accept => /
Dec 31, 2018 06:19:21.500 [3200] VERBOSE - * Range => bytes=0-
Dec 31, 2018 06:19:21.500 [3200] VERBOSE - * Connection => keep-alive
Dec 31, 2018 06:19:21.500 [3200] VERBOSE - * Host => 127.0.0.1:32400
Dec 31, 2018 06:19:21.500 [3200] VERBOSE - * Icy-MetaData => 1
Dec 31, 2018 06:19:21.500 [3200] VERBOSE - * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Dec 31, 2018 06:19:21.500 [3200] VERBOSE - * progress => 81.9
Dec 31, 2018 06:19:21.501 [3200] VERBOSE - * size => -22
Dec 31, 2018 06:19:21.501 [3200] VERBOSE - * remaining => 270
Dec 31, 2018 06:19:21.501 [3200] VERBOSE - * vdec_packets => 109975
Dec 31, 2018 06:19:21.501 [3200] VERBOSE - * vdec_sw_ok => 109970
Dec 31, 2018 06:19:21.501 [3200] VERBOSE - * speed => 3.6
Dec 31, 2018 06:19:21.501 [3200] VERBOSE - * vdec_hw_status => 0
Dec 31, 2018 06:19:21.502 [3200] VERBOSE - It took 0.0 sec to serialize a list with 0 elements.
Dec 31, 2018 06:19:21.502 [12180] DEBUG - Completed: [127.0.0.1:62094] 206 PUT /video/:/transcode/session/bif/e5f992cf-bd32-4669-b2bb-dadee9e4482d/progress?progress=81.9&size=-22&remaining=270&vdec_packets=109975&vdec_sw_ok=109970&speed=3.6&vdec_hw_status=0 (13 live) 4ms 355 bytes (pipelined: 1862) (range: bytes=0-)
Dec 31, 2018 06:19:21.578 [12184] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Dec 31, 2018 06:19:21.578 [12184] VERBOSE - Auth: Came in with the master token, authorization succeeded.
Dec 31, 2018 06:19:21.578 [8692] DEBUG - Request: [127.0.0.1:51994 (Loopback)] PUT /video/:/transcode/session/9nagdpwkkmq2b7btlvlo4eqi/738ce64b-0ce8-4ef2-a14d-778a42b29120/progress?progress=2.4&size=-22&remaining=-1&vdec_packets=1503&vdec_hw_ok=1496&speed=0.0&vdec_hw_status=1 (12 live) Signed-in Token (BlaineKyle)
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * User-Agent => Lavf/58.9.100
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * Accept => /
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * Range => bytes=0-
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * Connection => keep-alive
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * Host => 127.0.0.1:32400
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * Icy-MetaData => 1
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Dec 31, 2018 06:19:21.579 [8692] VERBOSE - * progress => 2.4
Dec 31, 2018 06:19:21.580 [8692] VERBOSE - * size => -22
Dec 31, 2018 06:19:21.580 [8692] VERBOSE - * remaining => -1
Dec 31, 2018 06:19:21.580 [8692] VERBOSE - * vdec_packets => 1503
Dec 31, 2018 06:19:21.580 [8692] VERBOSE - * vdec_hw_ok => 1496
Dec 31, 2018 06:19:21.580 [8692] VERBOSE - * speed => 0.0
Dec 31, 2018 06:19:21.580 [8692] VERBOSE - * vdec_hw_status => 1
Dec 31, 2018 06:19:21.581 [8692] VERBOSE - We want 60 seconds ahead, last returned was 93.009678 and max is 118.034700.
Dec 31, 2018 06:19:21.581 [8692] VERBOSE - It took 0.0 sec to serialize a list with 0 elements.
Dec 31, 2018 06:19:21.582 [12180] DEBUG - Completed: [127.0.0.1:51994] 206 PUT /video/:/transcode/session/9nagdpwkkmq2b7btlvlo4eqi/738ce64b-0ce8-4ef2-a14d-778a42b29120/progress?progress=2.4&size=-22&remaining=-1&vdec_packets=1503&vdec_hw_ok=1496&speed=0.0&vdec_hw_status=1 (12 live) 3ms 355 bytes (pipelined: 329) (range: bytes=0-)