Server Version#: 1.16.3.1402
Player Version#: 3.104.2
I’ve tried debugging this myself, and have found the following suspect entries in my logs. It appears that the client goes into buffering state, then requests a specific chunk for playback. The response from the server is 404 file not found. Stopping playback and resuming playback(not pause/unpause) works as if there was no problem.
Users also report this only happens if they are using the plex web client. I have never experienced this issue myself.
Relevant Log Entries:
Aug 12, 2019 17:04:31.372 [3664] DEBUG - Client [oxv26e5t8lo8krayqksc0pwn] reporting timeline state buffering, progress of 867000/8398000ms for guid=, ratingKey=10844 url=, key=/library/metadata/10844, containerKey=, metadataId=10844, source=
Aug 12, 2019 17:04:31.379 [5580] DEBUG - Completed: [:50882] 200 GET /:/timeline?ratingKey=10844&key=%2Flibrary%2Fmetadata%2F10844&playbackTime=867373&playQueueItemID=11665&state=buffering&hasMDE=1&time=867000&duration=8398000 (13 live) TLS GZIP 10ms 536 bytes (pipelined: 3)
Aug 12, 2019 17:04:31.887 [1984] DEBUG - Request: [:50882 (WAN)] GET /:/timeline?ratingKey=10844&key=%2Flibrary%2Fmetadata%2F10844&playbackTime=867427&playQueueItemID=11665&state=playing&hasMDE=1&time=867000&duration=8398000 (13 live) TLS GZIP Signed-in Token ()
Aug 12, 2019 17:04:31.891 [1984] DEBUG - Client [oxv26e5t8lo8krayqksc0pwn] reporting timeline state playing, progress of 867000/8398000ms for guid=, ratingKey=10844 url=, key=/library/metadata/10844, containerKey=, metadataId=10844, source=
Aug 12, 2019 17:04:31.897 [1984] DEBUG - Statistics: (4x3h5ggokx8m4k8ws1tt8ehi) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 23322569
Aug 12, 2019 17:04:31.899 [6084] DEBUG - Completed: [:50882] 200 GET /:/timeline?ratingKey=10844&key=%2Flibrary%2Fmetadata%2F10844&playbackTime=867427&playQueueItemID=11665&state=playing&hasMDE=1&time=867000&duration=8398000 (13 live) TLS GZIP 11ms 536 bytes (pipelined: 4)
Aug 12, 2019 17:04:32.099 [3664] DEBUG - Request: [:50883 (WAN)] GET /video/:/transcode/universal/dash/yqjyt7vkw6cylw0z1uvbp89b/0/112.m4s (13 live) TLS GZIP Signed-in
Aug 12, 2019 17:04:32.099 [1984] DEBUG - Request: [:50882 (WAN)] GET /video/:/transcode/universal/dash/yqjyt7vkw6cylw0z1uvbp89b/1/112.m4s (13 live) TLS GZIP Signed-in
Aug 12, 2019 17:04:32.101 [5580] DEBUG - Completed: [:50883] 404 GET /video/:/transcode/universal/dash/yqjyt7vkw6cylw0z1uvbp89b/0/112.m4s (13 live) TLS GZIP 1ms 458 bytes (pipelined: 1)
Aug 12, 2019 17:04:32.101 [6084] DEBUG - Completed: [:50882] 404 GET /video/:/transcode/universal/dash/yqjyt7vkw6cylw0z1uvbp89b/1/112.m4s (13 live) TLS GZIP 1ms 458 bytes (pipelined: 5)
These messages requesting 112.m4s repeat until the user hits pause or stops play. If the user unpauses, these messages continue. If the user stops playback entirely and then resumes, the media picks up where it left off as if nothing happened.
Edit: I should probably mention hardware acceleration for transcoding is enabled to offload transcoding to my RTX 2080. However, it should also be noted that the users in question always get Direct Streams for video, and the user was getting a Direct Stream in the shown logs. I don’t understand why it’s showing a ‘transcode’ path.
Any insight for correcting this is much appreciated.
