1 Topic by cheeseandcereal (edited by cheeseandcereal 21-03-2017 19:41:03)

Topic: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

So I have been using SVP for a while, but I've always had a problem with SVP playback with PlexMediaPlayer.

I've set up everything appropriately, and it works like 70% of the time, but after usually an hour or so, Plex will start buffering and the video will fail to load. Disabling SVP by resetting Plex's config files and restoring mvp-1.dll will fix the issue, and I will never have buffering problems without SVP. Note that my Plex media server is on the same local network, and both my client and server have a 1Gb/s ethernet connection to the router, so bandwidth should not be the issue. Also note that my plex server seems to be doing directplay with the content I'm watching, so it's a not an issue with the server not being able to keep up. Sometimes this issue will occur when first starting to initialize playback, and other times (like here), it will randomly start having issues in the middle of playback, even though it was working fine before.

Anyways, the logs from SVP don't tell me much, but here they are anyways:

10:52:32.155 [i]: Main: starting up SVP 4 Pro [4.1.0.105]... 
10:52:32.155 [i]: Main: args: none
10:52:32.155 [i]: Main: working dir is C:\Program Files (x86)\SVP 4\
10:52:32.155 [i]: Main: data dir set to C:\Users\Adam\AppData\Roaming\SVP4\
10:52:32.161 [i]: Settings: loading main.cfg OK
10:52:32.166 [i]: Settings: loading ui.cfg OK
10:52:32.172 [i]: Settings: loading frc.cfg OK
10:52:32.177 [i]: Settings: loading profiles.cfg OK
10:52:32.182 [i]: Settings: loading custom.cfg OK
10:52:32.197 [i]: Settings: loading lights.cfg OK
10:52:32.197 [i]: Main: using Qt 5.7.1 (i386-little_endian-ilp32 shared (dynamic) release build; by GCC 5.3.0)
10:52:32.197 [i]: Main: device scale is 1, user defined scale is 0
10:52:32.197 [i]: Main: system locale is [en]
10:52:32.197 [i]: Main: preferred language is [en-us]
10:52:32.198 [i]: Main: setting language file to en.qm...
10:52:32.225 [i]: Main: module 'plugins/svpflow1.dll': 4.0.0.132
10:52:32.249 [i]: Main: module 'plugins/svpflow2.dll': 4.0.0.136
10:52:32.273 [i]: Main: module 'plugins64/svpflow1.dll': 4.0.0.132
10:52:32.293 [i]: Main: module 'plugins64/svpflow2.dll': 4.0.0.136
10:52:32.311 [i]: Main: module 'plugins64/svpflow1_vs.dll': 4.0.0.132
10:52:32.336 [i]: Main: module 'plugins64/svpflow2_vs.dll': 4.1.0.140
10:52:32.336 [i]: Main: PYTHONPATH is C:\Program Files (x86)\SVP 4\mpv64
10:52:32.337 [i]: Main: running OpenCL info...
10:52:32.352 [i]: Main: collecting system information...
10:52:32.352 [i]: OS: Windows 10 [10.0.14393]
10:52:32.358 [i]: CPU: Intel Core i7-4790K [base frequency 4701 MHz, 8 threads]
10:52:32.358 [i]: Video: registry info - NVIDIA GeForce GTX 980 Ti
10:52:32.578 [i]: Video: 2 GPU OpenCL device(s) on NVIDIA CUDA [OpenCL 1.2 CUDA 8.0.0] (NVIDIA Corporation)
10:52:32.578 [i]: Video 1: device name 'GeForce GTX 980 Ti' (NVIDIA Corporation, ver.378.92) [gpuID=11]: OK
10:52:32.579 [i]: Video 2: device name 'GeForce GTX 980 Ti' (NVIDIA Corporation, ver.378.92) [gpuID=12]: OK
10:52:32.579 [i]: Memory:  32715  MB total,  29374 MB free
10:52:32.579 [i]: System: initializing network...
10:52:33.787 [i]: Screens: updating information, 3 screen(s) found
10:52:33.787 [i]: Power: AC is ON [1]
10:52:35.057 [i]: Main: preparing FRC profiles...
10:52:35.258 [i]: Main: preparing performance graphs...
10:52:35.298 [W]: Control: failed to register shortcut Meta+Ctrl+E
10:52:35.373 [i]: Main: preparing ffdshow...
10:52:35.421 [i]: FFDShow: found version 1.3.4533.0
10:52:35.433 [i]: Main: preparing mpv...
10:52:35.433 [i]: Main: preparing remote control...
10:52:35.434 [i]: RemoteControl: started
10:52:35.434 [i]: Main: preparing main menu...
10:52:35.449 [i]: Main: loading extensions...
10:52:35.460 [i]: Main: initialization completed in 3108 ms, but still waiting for the screens measurement...
10:52:35.469 [i]: Updates: checking now...
10:52:40.671 [i]: Screens: screen 0 - 2560x1440 @144.139 Hz [measured], x1.0 [108 DPI]
10:52:40.672 [i]: Screens: screen 1 - 1440x2560 @60.070 Hz [measured], x1.0 [117 DPI]
10:52:40.689 [i]: Screens: screen 2 - 2560x1440 @59.992 Hz [measured], x1.0 [135 DPI]
10:52:40.689 [i]: Screens: primary screen is 0
10:52:45.806 [i]: Performance: quick estimation = 425 (previous value was 410)
10:54:46.508 [i]: Screens: updating information, 3 screen(s) found
10:54:47.441 [i]: Screens: screen 0 - 2560x1440 @144.139 Hz [using OS refresh rate], x1.0 [108 DPI]
10:54:47.441 [i]: Screens: primary screen is 0
10:54:47.441 [i]: Screens: screen 1 - 1440x2560 @59.000 Hz [using OS refresh rate], x1.0 [117 DPI]
10:54:47.441 [i]: Screens: primary screen is 0
10:54:47.461 [i]: Screens: screen 2 - 2560x1440 @59.992 Hz [using OS refresh rate], x1.0 [135 DPI]
10:54:47.461 [i]: Screens: primary screen is 0
11:51:47.373 [i]: Screens: updating information, 3 screen(s) found
11:51:52.000 [i]: Screens: screen 1 - 1440x2560 @59.944 Hz [measured], x1.0 [117 DPI]
11:51:52.001 [i]: Screens: primary screen is 0
11:51:52.001 [i]: Screens: screen 2 - 2560x1440 @59.963 Hz [measured], x1.0 [135 DPI]
11:51:52.001 [i]: Screens: primary screen is 0
11:51:52.016 [i]: Screens: screen 0 - 2560x1440 @143.758 Hz [measured], x1.0 [108 DPI]
11:51:52.016 [i]: Screens: primary screen is 0
11:51:54.171 [i]: VideoPlayer: mpv connected, waiting for the video info...
11:52:04.171 [i]: VideoPlayer: mpv 0.24.0-git-0f1afc6
11:52:10.178 [i]: Media: video looks like some kind of stream
11:52:10.178 [i]: Media: video 1920x1080 [PAR 1.000] at 24.015 fps [constant] (via video player)
11:52:10.178 [i]: Media: codec type is h264 (H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10), NV12
11:52:10.196 [i]: Playback: starting up...
11:52:10.199 [i]: Playback [99245c1b]: Frame server (64-bit) C:\Program Files (x86)\SVP 4\mpv64\vapoursynth.dll
11:52:10.199 [i]: Playback [99245c1b]: resulting video frame 1920x1080
11:52:10.200 [i]: Playback [99245c1b]: 1 acceptible profiles, best is 'Automatic' [0]
11:52:10.218 [i]: Playback [99245c1b]: enabled while video is playing
11:52:10.219 [i]: Profile: using auto values [1]
11:52:10.236 [i]: Playback [99245c1b]: playing at 144.091 [24.0152 *6/1] 
11:54:44.569 [i]: Playback [99245c1b]: disabled while video is paused
11:54:44.575 [i]: Playback [99245c1b]: deleted

Note that the video started buffering around 11:54:21

Here are the relevant logs from Plex Media Player:

2017-03-21 11:53:54 [ INFO  ] JS: %c[Timeline] playing, 103652/1453786 
2017-03-21 11:53:54 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:53:55 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:53:56 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:53:57 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:53:58 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:53:59 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:00 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:01 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:02 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:03 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:04 [ INFO  ] JS: %c[Timeline] playing, 113648/1453786 
2017-03-21 11:54:04 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:05 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:06 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:07 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:08 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:09 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:10 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:11 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:12 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:13 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:14 [ INFO  ] JS: %c[Timeline] playing, 123651/1453786 
2017-03-21 11:54:14 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:15 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:16 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:17 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:18 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:19 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:20 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:21 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-03-21 11:54:21 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:22 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:23 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Timeline] playing, 133654/1453786 
2017-03-21 11:54:24 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Enter buffering. 
2017-03-21 11:54:24 [ INFO  ] PlayerComponent.cpp @ 394 - Entering state: buffering 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Player] 4% buffered 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Timeline] buffering, 133695/1453786 
2017-03-21 11:54:24 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-03-21 11:54:24 [ INFO  ] JS: %c[PlayerController] State change buffering 
2017-03-21 11:54:24 [ DEBUG ] PowerComponent.cpp @ 53 - Enabling OS screensaver 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Player] 15% buffered 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Player] 16% buffered 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:24 [ INFO  ] JS: %c[Player] 41% buffered 
2017-03-21 11:54:25 [ INFO  ] JS: %c[Player] 66% buffered 
2017-03-21 11:54:26 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-03-21 11:54:26 [ INFO  ] JS: %c[Player] 79% buffered 
2017-03-21 11:54:26 [ INFO  ] JS: %c[Player] 85% buffered 
2017-03-21 11:54:27 [ INFO  ] JS: %c[Player] 87% buffered 
2017-03-21 11:54:28 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: End buffering (waited 4.059097 secs). 
2017-03-21 11:54:28 [ INFO  ] PlayerComponent.cpp @ 386 - Entering state: playing 
2017-03-21 11:54:28 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:28 [ INFO  ] JS: %c[Timeline] playing, 133695/1453786 
2017-03-21 11:54:28 [ INFO  ] JS: %c[PlayerController] State change playing 
2017-03-21 11:54:28 [ DEBUG ] PowerComponent.cpp @ 58 - Disabling OS screensaver 
2017-03-21 11:54:28 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:29 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:29 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Enter buffering. 
2017-03-21 11:54:29 [ INFO  ] PlayerComponent.cpp @ 394 - Entering state: buffering 
2017-03-21 11:54:29 [ INFO  ] JS: %c[Player] 2% buffered 
2017-03-21 11:54:29 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:29 [ INFO  ] JS: %c[Timeline] buffering, 134822/1453786 
2017-03-21 11:54:29 [ INFO  ] JS: %c[PlayerController] State change buffering 
2017-03-21 11:54:29 [ DEBUG ] PowerComponent.cpp @ 53 - Enabling OS screensaver 
2017-03-21 11:54:30 [ INFO  ] JS: %c[Player] 14% buffered 
2017-03-21 11:54:30 [ INFO  ] JS: %c[Player] 15% buffered 
2017-03-21 11:54:30 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:30 [ INFO  ] JS: %c[Player] 23% buffered 
2017-03-21 11:54:30 [ INFO  ] JS: %c[Player] 26% buffered 
2017-03-21 11:54:30 [ INFO  ] JS: %c[Player] 36% buffered 
2017-03-21 11:54:30 [ INFO  ] JS: %c[Player] 44% buffered 
2017-03-21 11:54:31 [ INFO  ] JS: %c[Player] 52% buffered 
2017-03-21 11:54:32 [ INFO  ] JS: %c[Player] 59% buffered 
2017-03-21 11:54:32 [ INFO  ] JS: %c[Player] 67% buffered 
2017-03-21 11:54:32 [ INFO  ] JS: %c[Player] 78% buffered 
2017-03-21 11:54:33 [ INFO  ] JS: %c[Player] 86% buffered 
2017-03-21 11:54:34 [ INFO  ] JS: %c[Timeline] buffering, 134822/1453786 
2017-03-21 11:54:34 [ INFO  ] JS: %c[Player] 93% buffered 
2017-03-21 11:54:34 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: End buffering (waited 5.492868 secs). 
2017-03-21 11:54:34 [ INFO  ] PlayerComponent.cpp @ 386 - Entering state: playing 
2017-03-21 11:54:34 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:34 [ INFO  ] JS: %c[Timeline] playing, 134822/1453786 
2017-03-21 11:54:34 [ INFO  ] JS: %c[PlayerController] State change playing 
2017-03-21 11:54:34 [ DEBUG ] PowerComponent.cpp @ 58 - Disabling OS screensaver 
2017-03-21 11:54:34 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:35 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:36 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Enter buffering. 
2017-03-21 11:54:36 [ INFO  ] PlayerComponent.cpp @ 394 - Entering state: buffering 
2017-03-21 11:54:36 [ INFO  ] JS: %c[Player] 1% buffered 
2017-03-21 11:54:36 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:36 [ INFO  ] JS: %c[Timeline] buffering, 136664/1453786 
2017-03-21 11:54:36 [ INFO  ] JS: %c[PlayerController] State change buffering 
2017-03-21 11:54:36 [ DEBUG ] PowerComponent.cpp @ 53 - Enabling OS screensaver 
2017-03-21 11:54:36 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:36 [ INFO  ] JS: %c[Player] 6% buffered 
2017-03-21 11:54:37 [ INFO  ] JS: %c[Player] 15% buffered 
2017-03-21 11:54:37 [ INFO  ] JS: %c[Player] 16% buffered 
2017-03-21 11:54:37 [ INFO  ] JS: %c[Player] 20% buffered 
2017-03-21 11:54:38 [ INFO  ] JS: %c[Player] 21% buffered 
2017-03-21 11:54:38 [ INFO  ] JS: %c[Player] 27% buffered 
2017-03-21 11:54:38 [ INFO  ] JS: %c[Player] 33% buffered 
2017-03-21 11:54:39 [ INFO  ] JS: %c[Player] 34% buffered 
2017-03-21 11:54:39 [ INFO  ] JS: %c[Player] 40% buffered 
2017-03-21 11:54:40 [ INFO  ] JS: %c[Player] 46% buffered 
2017-03-21 11:54:40 [ INFO  ] JS: %c[Player] 47% buffered 
2017-03-21 11:54:40 [ INFO  ] JS: %c[Player] 57% buffered 
2017-03-21 11:54:41 [ INFO  ] JS: %c[Player] 63% buffered 
2017-03-21 11:54:41 [ INFO  ] JS: %c[Player] 68% buffered 
2017-03-21 11:54:42 [ INFO  ] JS: %c[Player] 74% buffered 
2017-03-21 11:54:43 [ INFO  ] JS: %c[Player] 81% buffered 
2017-03-21 11:54:43 [ DEBUG ] PowerComponent.cpp @ 53 - Enabling OS screensaver 
2017-03-21 11:54:43 [ INFO  ] JS: %c[Player] stopping playback 
2017-03-21 11:54:43 [ INFO  ] JS: %c[PlayerController] Stopping playback 
2017-03-21 11:54:43 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-03-21 11:54:43 [ INFO  ] JS: %c[Timeline] stopped, 136664/1453786 
2017-03-21 11:54:43 [ INFO  ] JS: %c[PlayerController] State change stopped

Note I manually stopped the stream at the end of that log.

Also logs from Plex Media Server at this time:

Mar 21, 2017 11:54:12.706 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 21526kbps with most recent 19746kbps (491520)
Mar 21, 2017 11:54:13.679 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 21132kbps with most recent 18849kbps (311296)
Mar 21, 2017 11:54:15.073 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 21747kbps with most recent 28596kbps (344064)
Mar 21, 2017 11:54:17.255 [13212] DEBUG - Streaming Resource: Updating client bandwidth to 22423kbps with most recent 24354kbps (638976)
Mar 21, 2017 11:54:18.803 [13212] DEBUG - Streaming Resource: Updating client bandwidth to 22040kbps with most recent 20522kbps (327680)
Mar 21, 2017 11:54:19.743 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 22203kbps with most recent 18393kbps (311296)
Mar 21, 2017 11:54:20.675 [11784] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:20.675 [11784] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:20.675 [11784] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:20.676 [11324] DEBUG - Request: [::ffff:192.168.1.20:2735 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=123651&duration=1453786 (4 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:20.676 [11324] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state playing, progress of 123651/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:20.680 [11324] DEBUG - Play progress on 11453 'Brace for Impact' - got played 123651 ms by account 1!
Mar 21, 2017 11:54:20.682 [11324] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:20.682 [11324] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:20.683 [11324] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:20.683 [11324] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:20.683 [11324] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:20.684 [11324] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:20.685 [5080] DEBUG - Completed: [::ffff:192.168.1.20:2735] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=123651&duration=1453786 (4 live) TLS GZIP 10ms 423 bytes (pipelined: 22)
Mar 21, 2017 11:54:21.489 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 22310kbps with most recent 27311kbps (344064)
Mar 21, 2017 11:54:22.599 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 22534kbps with most recent 24670kbps (327680)
Mar 21, 2017 11:54:24.038 [13212] DEBUG - Streaming Resource: Updating client bandwidth to 22694kbps with most recent 21361kbps (311296)
Mar 21, 2017 11:54:25.859 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 22779kbps with most recent 22901kbps (606208)
Mar 21, 2017 11:54:27.661 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22590kbps with most recent 15668kbps (311296)
Mar 21, 2017 11:54:29.277 [13212] DEBUG - Streaming Resource: Updating client bandwidth to 23442kbps with most recent 28774kbps (344064)
Mar 21, 2017 11:54:30.675 [11784] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:30.675 [11784] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:30.676 [11784] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:30.676 [10092] DEBUG - Request: [::ffff:192.168.1.20:2735 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=133654&duration=1453786 (4 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:30.676 [10092] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state playing, progress of 133654/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:30.678 [10092] DEBUG - Play progress on 11453 'Brace for Impact' - got played 133654 ms by account 1!
Mar 21, 2017 11:54:30.686 [10092] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:30.686 [10092] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:30.687 [10092] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:30.687 [10092] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:30.687 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 23551kbps with most recent 30484kbps (311296)
Mar 21, 2017 11:54:30.687 [10092] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:30.688 [10092] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:30.689 [11784] DEBUG - Completed: [::ffff:192.168.1.20:2735] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=133654&duration=1453786 (5 live) TLS GZIP 14ms 423 bytes (pipelined: 23)
Mar 21, 2017 11:54:30.699 [11784] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:30.699 [11784] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:30.699 [11784] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:30.700 [11324] DEBUG - Request: [::ffff:192.168.1.20:2791 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=133695&duration=1453786 (5 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:30.700 [11324] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state buffering, progress of 133695/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:30.705 [11324] DEBUG - Play progress on 11453 'Brace for Impact' - got played 133695 ms by account 1!
Mar 21, 2017 11:54:30.708 [11324] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:30.708 [11324] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:30.708 [11324] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:30.708 [11324] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:30.709 [11324] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 2 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:30.709 [11324] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:30.710 [11784] DEBUG - Completed: [::ffff:192.168.1.20:2791] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=133695&duration=1453786 (5 live) TLS GZIP 10ms 423 bytes (pipelined: 1)
Mar 21, 2017 11:54:32.820 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22591kbps with most recent 17027kbps (458752)
Mar 21, 2017 11:54:34.270 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22996kbps with most recent 24932kbps (344064)
Mar 21, 2017 11:54:34.654 [5080] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:34.654 [5080] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:34.655 [5080] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:34.655 [10092] DEBUG - Request: [::ffff:192.168.1.20:2791 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=133695&duration=1453786 (5 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:34.655 [10092] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state playing, progress of 133695/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:34.658 [10092] DEBUG - Play progress on 11453 'Brace for Impact' - got played 133695 ms by account 1!
Mar 21, 2017 11:54:34.660 [10092] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:34.660 [10092] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:34.660 [10092] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:34.660 [10092] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:34.661 [10092] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:34.661 [10092] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:34.662 [11784] DEBUG - Completed: [::ffff:192.168.1.20:2791] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=133695&duration=1453786 (5 live) TLS GZIP 7ms 423 bytes (pipelined: 2)
Mar 21, 2017 11:54:35.725 [5080] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:35.725 [5080] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:35.725 [5080] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:35.725 [11324] DEBUG - Request: [::ffff:192.168.1.20:2791 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=134822&duration=1453786 (5 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:35.726 [11324] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state buffering, progress of 134822/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:35.729 [11324] DEBUG - Play progress on 11453 'Brace for Impact' - got played 134822 ms by account 1!
Mar 21, 2017 11:54:35.731 [11324] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:35.732 [11324] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:35.732 [11324] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:35.732 [11324] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:35.732 [11324] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 2 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:35.733 [11324] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:35.734 [11784] DEBUG - Completed: [::ffff:192.168.1.20:2791] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=134822&duration=1453786 (5 live) TLS GZIP 8ms 423 bytes (pipelined: 3)
Mar 21, 2017 11:54:36.075 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 23284kbps with most recent 22395kbps (524288)
Mar 21, 2017 11:54:37.008 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22552kbps with most recent 18685kbps (311296)
Mar 21, 2017 11:54:38.099 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22820kbps with most recent 27822kbps (327680)
Mar 21, 2017 11:54:39.077 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 22692kbps with most recent 19918kbps (327680)
Mar 21, 2017 11:54:40.531 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22784kbps with most recent 24161kbps (311296)
Mar 21, 2017 11:54:40.672 [11784] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:40.672 [11784] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:40.673 [11784] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:40.673 [10092] DEBUG - Request: [::ffff:192.168.1.20:2791 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=134822&duration=1453786 (5 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:40.673 [10092] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state buffering, progress of 134822/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:40.676 [10092] DEBUG - Play progress on 11453 'Brace for Impact' - got played 134822 ms by account 1!
Mar 21, 2017 11:54:40.679 [10092] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:40.679 [10092] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:40.679 [10092] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:40.679 [10092] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:40.680 [10092] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 2 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:40.680 [10092] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:40.681 [5080] DEBUG - Completed: [::ffff:192.168.1.20:2791] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=134822&duration=1453786 (5 live) TLS GZIP 8ms 423 bytes (pipelined: 4)
Mar 21, 2017 11:54:41.220 [5080] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:41.220 [5080] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:41.221 [5080] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:41.221 [11324] DEBUG - Request: [::ffff:192.168.1.20:2791 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=134822&duration=1453786 (5 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:41.221 [11324] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state playing, progress of 134822/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:41.228 [11324] DEBUG - Play progress on 11453 'Brace for Impact' - got played 134822 ms by account 1!
Mar 21, 2017 11:54:41.231 [11324] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:41.231 [11324] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:41.232 [11324] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:41.232 [11324] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:41.232 [11324] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:41.232 [11324] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:41.233 [5080] DEBUG - Completed: [::ffff:192.168.1.20:2791] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=playing&playQueueItemID=41111&time=134822&duration=1453786 (5 live) TLS GZIP 12ms 423 bytes (pipelined: 5)
Mar 21, 2017 11:54:42.375 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 23195kbps with most recent 20516kbps (327680)
Mar 21, 2017 11:54:43.016 [11784] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 21, 2017 11:54:43.017 [11784] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Mar 21, 2017 11:54:43.017 [11784] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Mar 21, 2017 11:54:43.017 [10092] DEBUG - Request: [::ffff:192.168.1.20:2791 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=136664&duration=1453786 (5 live) TLS GZIP Signed-in Token (cheeseandcereal)
Mar 21, 2017 11:54:43.017 [10092] DEBUG - Client [xmd2rukswgh4tj1avbpm0a4i] reporting timeline state buffering, progress of 136664/1453786ms for guid=, ratingKey=11453 url=, key=/library/metadata/11453, containerKey=, metadataId=11453
Mar 21, 2017 11:54:43.020 [10092] DEBUG - Play progress on 11453 'Brace for Impact' - got played 136664 ms by account 1!
Mar 21, 2017 11:54:43.025 [10092] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Mar 21, 2017 11:54:43.026 [10092] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Mar 21, 2017 11:54:43.026 [10092] DEBUG - [Now] Profile is Konvergo
Mar 21, 2017 11:54:43.026 [10092] DEBUG - [Now] Updated play state for /library/metadata/11453.
Mar 21, 2017 11:54:43.026 [10092] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 2 of type 4 (scrobble: 0) for account 1
Mar 21, 2017 11:54:43.027 [10092] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Mar 21, 2017 11:54:43.028 [5080] DEBUG - Completed: [::ffff:192.168.1.20:2791] 200 GET /:/timeline?hasMDE=1&ratingKey=11453&key=%2Flibrary%2Fmetadata%2F11453&state=buffering&playQueueItemID=41111&time=136664&duration=1453786 (5 live) TLS GZIP 11ms 423 bytes (pipelined: 6)
Mar 21, 2017 11:54:43.388 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22157kbps with most recent 17737kbps (327680)
Mar 21, 2017 11:54:44.749 [13212] DEBUG - Streaming Resource: Updating client bandwidth to 22086kbps with most recent 29291kbps (327680)
Mar 21, 2017 11:54:46.623 [13212] DEBUG - Streaming Resource: Updating client bandwidth to 22503kbps with most recent 20569kbps (524288)
Mar 21, 2017 11:54:47.605 [4092] DEBUG - Streaming Resource: Updating client bandwidth to 21968kbps with most recent 18962kbps (311296)
Mar 21, 2017 11:54:48.381 [12432] DEBUG - Streaming Resource: Updating client bandwidth to 22596kbps with most recent 28901kbps (344064)

So it seems to be an issue with the cache not being properly filled.

I also notice that sometimes when starting the playback of media on Plex Media Player, it will buffer for a long time (10 or 20+ seconds), and then SVP will completely ignore the playback and give me this warning in the log:

11:56:13.811 [W]: VideoPlayer: media file doesn't look like video, ignoring...

Has anyone else had this issue, or have any suggestions? As I said before, this buffering/cache issue ONLY occur when SVP is enabled, so I'm not sure it might be occurring. Any help would be appreciated!

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

mpv log?

log-file=<path>

3 Reply by cheeseandcereal (edited by cheeseandcereal 21-03-2017 20:08:11)

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

How do I enable mpv logs for Plex Media Player? I edited the mpv.conf in "C:\Program Files (x86)\SVP 4\mpv64" as well as "%localappdata%\PlexMediaPlayer" adding the line: "log-file=C:\mpv.log" but no log files are produced when playing through Plex Media Player.

Launching a local video via cmd (mpv somevideo.avi) will produce a log file, but I can't seem to get playing through Plex Media Player to produce an mpv log. Is there some other config file somewhere that I need to set?

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

%localappdata%\PlexMediaPlayer\mpv.conf works

it probably just don't have write access to c:\

5 Reply by cheeseandcereal (edited by cheeseandcereal 01-04-2017 08:54:03)

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

Yup, looks like it did not have write access to C:\
Switched it up the location and got the mvp log.


Here's a relevant snippet from the mvp log from when I tried launching a video, then SVP did not initialize because "media file doesn't look like video, ignoring...".
Upon initially launching this in plex media player, it took over 30 seconds to initialize/buffer, then it had a bunch of buffering after starting playback.

[1919.626][v][sub/ass] Setting up fonts...
[1919.628][v][sub/ass] Using font provider directwrite
[1919.628][v][sub/ass] Done.
[1919.628][v][cplayer] Starting playback...
[1919.628][v][mkv] queuing seek to 1479.790000
[1919.628][v][mkv] execute seek (to 1479.790000 flags 40)
[1919.628][v][mkv] Seeking to 9571352678 to read header element 0x1c53bb6b.
[1919.628][v][cplayer] hr-seek, skipping to 1479.790000 (no framedrop)
[1920.011][v][cache] Dropping cache at pos 9571352678, cached range: 0-630784.
[1920.011][v][cache] Seeking underlying stream: 630784 -> 9571352678
[1920.106][v][mkv] Parsing cues...
[1920.153][v][ffmpeg] tls: Server closed the connection
[1920.153][v][cache] EOF reached.
[1920.179][v][cache] Dropping cache at pos 2444668629, cached range: 9571352678-9571540664.
[1920.179][v][cache] Seeking underlying stream: 9571540664 -> 2444668629
[1927.798][v][cache] Cache is not responding - slow/stuck network connection?
[1929.465][v][mkv] seek done
[1929.465][v][vd] Pixel formats supported by decoder: dxva2_vld d3d11va_vld yuv420p
[1929.465][v][vd] Codec profile: High (0x64)
[1929.465][v][dxva2] 16 decoder devices:
[1929.465][v][dxva2] {86695f12-340e-4f04-9fd3-9253dd327460} MPEG2and1_VLD  NV12
[1929.465][v][dxva2] {ee27417f-5e28-4e65-beea-1d26b508adc9} MPEG2_VLD  NV12
[1929.465][v][dxva2] {6f3ec719-3735-42cc-8063-65cc3cb36616} <unknown>  NV12
[1929.465][v][dxva2] {1b81bea4-a0c7-11d3-b984-00c04f2e73c5} VC1_D2010  NV12
[1929.465][v][dxva2] {1b81bea3-a0c7-11d3-b984-00c04f2e73c5} VC1_D  NV12
[1929.465][v][dxva2] {32fcfe3f-de46-4a49-861b-ac71110649d5} <unknown>  NV12
[1929.465][v][dxva2] {d79be8da-0cf1-4c81-b82a-69a4e236f43d} <unknown>  NV12
[1929.465][v][dxva2] {f9aaccbb-c2b6-4cfc-8779-5707b1760552} <unknown>  NV12
[1929.465][v][dxva2] {1b81be68-a0c7-11d3-b984-00c04f2e73c5} H264_E  NV12
[1929.465][v][dxva2] {5b11d51b-2f4c-4452-bcc3-09f2a1160cc0} HEVC_VLD_Main  NV12
[1929.465][v][dxva2] {efd64d74-c9e8-41d7-a5e9-e9b0e39fa319} <unknown>  NV12
[1929.465][v][dxva2] {ed418a9f-010d-4eda-9ae3-9a65358d8d2e} <unknown>  NV12
[1929.465][v][dxva2] {9947ec6f-689b-11dc-a320-0019dbbc4184} <unknown>  NV12
[1929.465][v][dxva2] {33fcfe41-de46-4a49-861b-ac71110649d5} <unknown>  YUY2 NV12
[1929.465][v][dxva2] {6affd11e-1d96-42b1-a215-93a31f09a53d} <unknown>  NV12
[1929.465][v][dxva2] {914c84a3-4078-4fa9-984c-e2f262cb5c9c} <unknown>  NV12
[1929.465][v][vd] Selecting {1b81be68-a0c7-11d3-b984-00c04f2e73c5} H264_E NV12
[1929.478][v][ffmpeg/video] h264: Reinit context to 1920x816, pix_fmt: dxva2_vld
[1929.490][v][af] Adding filter lavrresample 
[1929.490][v][af] Setting option 'normalize' = 'yes' (flags = 0)
[1929.490][v][af] Setting option 'o' = 'surround_mix_level=1' (flags = 0)
[1929.490][v][lavrresample] Remix: 5.1(side) -> stereo
[1929.490][v][af] Audio filter chain:
[1929.490][v][af]   [in] 48000Hz 5.1(side) 6ch floatp
[1929.490][v][af]   [lavrresample] 48000Hz stereo 2ch floatp [a]
[1929.490][v][af]   [out] 48000Hz stereo 2ch floatp
[1929.490][v][af]   [ao] 48000Hz stereo 2ch floatp
[1929.490][v][ao] Trying audio driver 'wasapi'
[1929.490][v][ao/wasapi] requested format: 48000 Hz, stereo channels, floatp
[1929.491][v][ao/wasapi] No device specified. Selecting default.
[1929.492][v][ao/wasapi] Selecting device '{2b4db603-7d2b-4341-9bb7-a88fc13954bf}' (Speakers (2- ODAC-revB USB DAC))
[1929.492][v][ao/wasapi] Monitoring changes in device {0.0.0.00000000}.{2b4db603-7d2b-4341-9bb7-a88fc13954bf}
[1929.494][v][ao/wasapi] Trying stereo float @ 48000hz (shared) -> ok
[1929.494][v][ao/wasapi] Closest match is stereo float @ 44100hz
[1929.494][v][ao/wasapi] Accepted as stereo float @ 44100hz (shared)
[1929.494][v][ao/wasapi] Device period: 10 ms
[1929.497][v][ao/wasapi] Buffer frame count: 2205 (50 ms)
[1929.497][v][ao/wasapi] IAudioClock::GetFrequency gave a frequency of 352800.
[1929.497][v][ao/wasapi] device buffer: 2205 samples.
[1929.497][v][ao/wasapi] using soft-buffer of 8820 samples.
[1929.497][i][cplayer] AO: [wasapi] 44100Hz stereo 2ch float
[1929.497][v][cplayer] AO: Description: Windows WASAPI audio output (event mode)
[1929.497][v][af] Removing filter lavrresample 
[1929.497][v][af] Adding filter lavrresample 
[1929.497][v][af] Setting option 'normalize' = 'yes' (flags = 0)
[1929.497][v][af] Setting option 'o' = 'surround_mix_level=1' (flags = 0)
[1929.497][v][lavrresample] Remix: 5.1(side) -> stereo
[1929.498][v][af] Audio filter chain:
[1929.498][v][af]   [in] 48000Hz 5.1(side) 6ch floatp
[1929.498][v][af]   [lavrresample] 44100Hz stereo 2ch float [a]
[1929.498][v][af]   [out] 44100Hz stereo 2ch float
[1929.498][v][af]   [ao] 44100Hz stereo 2ch float
[1929.648][i][vd] Using hardware decoding (dxva2-copy).
[1929.648][v][vd] Decoder format: 1920x804 [0:1] nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264
[1929.648][v][vd] Using container aspect ratio.
[1929.648][v][vf] Video filter chain:
[1929.648][v][vf]   [in] 1920x804 nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264
[1929.648][v][vf]   [out] 1920x804 nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264
[1929.648][v][opengl-cb] Window size: 2560x1440
[1929.649][v][opengl-cb] Video source: 0x0 (0:0)
[1929.649][v][opengl-cb] Video display: (0, 0) 1x1 -> (0, 0) 2560x1440
[1929.649][v][opengl-cb] Video scale: 2560.000000/1440.000000
[1929.649][v][opengl-cb] OSD borders: l=-1073740544 t=0 r=-1073740544 b=0
[1929.649][v][opengl-cb] Video borders: l=0 t=0 r=0 b=0
[1929.649][v][cplayer] Set property: video-unscaled=false -> 1
[1929.649][v][cplayer] Set property: video-aspect="-1" -> 1
[1929.649][v][cplayer] Set property: keepaspect=true -> 1
[1929.649][v][cplayer] Set property: panscan=0.000000 -> 1
[1929.649][v][opengl-cb] Window size: 2560x1440
[1929.649][v][opengl-cb] Video source: 0x0 (0:0)
[1929.649][v][opengl-cb] Video display: (0, 0) 1x1 -> (0, 0) 2560x1440
[1929.649][v][opengl-cb] Video scale: 2560.000000/1440.000000
[1929.649][v][opengl-cb] OSD borders: l=-1073740544 t=0 r=-1073740544 b=0
[1929.649][v][opengl-cb] Video borders: l=0 t=0 r=0 b=0
[1930.681][v][cache] Cache is not responding - slow/stuck network connection?
[1930.896][v][vd] Decoder format: 1920x804 [0:1] nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264
[1930.896][v][vd] Using container aspect ratio.
[1936.344][v][cache] Cache is not responding - slow/stuck network connection?
[1950.810][v][cache] Cache is not responding - slow/stuck network connection?
[1957.250][v][cache] Cache is not responding - slow/stuck network connection?
[1970.136][i][cplayer] VO: [opengl-cb] 1920x804 nv12
[1970.136][v][cplayer] VO: Description: OpenGL Callbacks for libmpv
[1970.136][v][cplayer] set video colors output-levels=0 
[1970.136][v][opengl-cb] Window size: 2560x1440
[1970.136][v][opengl-cb] Video source: 1920x804 (1:1)
[1970.136][v][opengl-cb] Video display: (0, 0) 1920x804 -> (0, 184) 2560x1072
[1970.136][v][opengl-cb] Video scale: 1.333333/1.333333
[1970.136][v][opengl-cb] OSD borders: l=0 t=184 r=0 b=184
[1970.136][v][opengl-cb] Video borders: l=0 t=184 r=0 b=184
[1970.136][v][opengl-cb] Testing FBO format 0x805b
[1970.136][v][opengl-cb] Create FBO: 16x16 (16x16)
[1970.142][v][opengl-cb] Using FBO format 0x805b.
[1970.142][v][opengl-cb] No advanced processing required. Enabling dumb mode.
[1970.142][v][opengl-cb] Texture for plane 0: 1920x804
[1970.142][v][opengl-cb] Texture for plane 1: 960x402
[1970.142][v][cplayer] first video frame after restart shown
[1970.176][v][cplayer] starting audio playback
[1970.176][v][cplayer] playback restart complete
[1970.177][v][cplayer] Enter buffering.
[1971.396][v][cache] Cache is not responding - slow/stuck network connection?
[1976.202][v][cplayer] End buffering (waited 6.024617 secs).
[1977.626][v][cplayer] Enter buffering.
[1978.124][v][cache] Cache is not responding - slow/stuck network connection?
[1980.239][v][cache] Cache is not responding - slow/stuck network connection?
[1986.561][v][cache] Cache is not responding - slow/stuck network connection?
[1986.708][v][cplayer] End buffering (waited 9.122979 secs).
[1988.741][v][cplayer] Enter buffering.
[1996.234][v][cache] Cache is not responding - slow/stuck network connection?
[1998.465][v][cache] Cache is not responding - slow/stuck network connection?
[2001.269][v][cplayer] End buffering (waited 12.569756 secs).
[2004.266][v][cplayer] Enter buffering.
[2005.765][v][cache] Cache is not responding - slow/stuck network connection?
[2012.046][v][cache] Cache is not responding - slow/stuck network connection?
[2013.477][v][cache] Cache is not responding - slow/stuck network connection?
[2015.591][v][cache] Cache is not responding - slow/stuck network connection?
[2017.748][v][cache] Cache is not responding - slow/stuck network connection?
[2019.872][v][cache] Cache is not responding - slow/stuck network connection?
[2020.254][v][cplayer] End buffering (waited 16.030287 secs).
[2022.020][v][cache] Cache is not responding - slow/stuck network connection?
[2025.499][v][cache] Cache is not responding - slow/stuck network connection?

Relevant Plex Server logs from this time:

Apr 01, 2017 00:23:55.166 [5948] DEBUG - Request came in with unrecognized domain / IP 'file' in header Origin; treating as non-local
Apr 01, 2017 00:23:55.166 [5948] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:23:55.166 [5948] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:23:55.166 [5948] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:23:55.166 [11028] DEBUG - Request: [::ffff:192.168.1.20:4598 (Allowed Network)] POST /playQueues?type=video&uri=library%3A%2F%2F6d0094b8-5934-4303-a16d-80a4672daca7%2Fitem%2F%252Flibrary%252Fmetadata%252F12162&shuffle=0&repeat=0&includeChapters=1 (18 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:23:55.167 [11028] DEBUG - PlayQueue: 0 generated IDs compressed down to a 2 byte blob.
Apr 01, 2017 00:23:55.170 [11028] DEBUG - PlayQueue: Start index: 0 End index: 0 Count: 1
Apr 01, 2017 00:23:55.170 [11028] DEBUG - PlayQueue: 1 generated IDs compressed down to a 24 byte blob.
Apr 01, 2017 00:23:55.172 [11028] DEBUG - PlayQueue: Added 1 items in 0.0 sec.
Apr 01, 2017 00:23:55.175 [11028] DEBUG - We're going to try to auto-select an audio stream for account 1.
Apr 01, 2017 00:23:55.175 [11028] DEBUG - Selecting best audio stream for part ID 11820 (autoselect: 1 language: ja)
Apr 01, 2017 00:23:55.176 [11028] DEBUG - Audio Stream: 43149, Subtitle Stream: 43151
Apr 01, 2017 00:23:55.176 [11028] DEBUG - It took 0.0 sec to serialize a list with 1 elements.
Apr 01, 2017 00:23:55.178 [6428] DEBUG - Completed: [::ffff:192.168.1.20:4598] 200 POST /playQueues?type=video&uri=library%3A%2F%2F6d0094b8-5934-4303-a16d-80a4672daca7%2Fitem%2F%252Flibrary%252Fmetadata%252F12162&shuffle=0&repeat=0&includeChapters=1 (18 live) TLS GZIP 11ms 2964 bytes (pipelined: 12)
Apr 01, 2017 00:23:56.720 [6428] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:23:56.720 [6428] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:23:56.720 [6428] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:23:56.720 [3864] DEBUG - Request: [::ffff:192.168.1.20:4598 (Allowed Network)] GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F12162&mediaIndex=0&partIndex=0&protocol=http&fastSeek=1&directPlay=1&directStream=1&subtitleSize=100&audioBoost=100&location=lan&session=2ksumaad4uhyb2h2bv2zh93s&offset=1479.792&subtitles=none&copyts=1&Accept-Language=en (18 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:23:56.721 [3864] DEBUG - Found session GUID of 2ksumaad4uhyb2h2bv2zh93s in session start.
Apr 01, 2017 00:23:56.721 [3864] DEBUG - TranscodeUniversalRequest: using profile Konvergo
Apr 01, 2017 00:23:56.721 [3864] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/12162?includeBandwidths=1&X-Plex-Client-Capabilities=protocols%3Dshoutcast%2Chttp-video;videoDecoders%3Dh264{profile%3Ahigh%26resolution%3A2160%26level%3A52};audioDecoders%3Dmp3%2Caac%2Cdts{bitrate%3A800000%26channels%3A2}%2Cac3{bitrate%3A800000%26channels%3A2}
Apr 01, 2017 00:23:56.722 [3864] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:23:56.722 [3864] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:23:56.722 [3864] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:23:56.724 [3864] DEBUG - We're going to try to auto-select an audio stream for account 1.
Apr 01, 2017 00:23:56.725 [3864] DEBUG - Selecting best audio stream for part ID 11820 (autoselect: 1 language: ja)
Apr 01, 2017 00:23:56.725 [3864] DEBUG - Audio Stream: 43149, Subtitle Stream: 43151
Apr 01, 2017 00:23:56.725 [3864] DEBUG - It took 0.0 sec to serialize a list with 1 elements.
Apr 01, 2017 00:23:56.726 [3864] DEBUG - Streaming Resource: Added session 04F477C0:9ovsonn6jpctfgekfqzgs0pb
Apr 01, 2017 00:23:56.726 [3864] DEBUG - Streaming Resource: Reached Decision id=12162 codes=(MDE=1000,Direct play OK.) media=(id=11815 part=(id=11820 decision=direct play protocol=http streams=(Video=(id=43148 decision= width=0 height=0) Audio=(id=43149 decision= channels=0 rate=0) Subtitle=(id=43151 decision=ignore languageCode=eng location=embedded))))
Apr 01, 2017 00:23:56.726 [3864] DEBUG - It took 0.0 sec to serialize a list with 1 elements.
Apr 01, 2017 00:23:56.728 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4598] 200 GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F12162&mediaIndex=0&partIndex=0&protocol=http&fastSeek=1&directPlay=1&directStream=1&subtitleSize=100&audioBoost=100&location=lan&session=2ksumaad4uhyb2h2bv2zh93s&offset=1479.792&subtitles=none&copyts=1&Accept-Language=en (18 live) TLS GZIP 7ms 2431 bytes (pipelined: 13)
Apr 01, 2017 00:23:56.790 [5948] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:23:56.790 [5948] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:23:56.790 [5948] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:23:56.790 [13232] DEBUG - Request: [::ffff:192.168.1.20:4603 (Allowed Network)] GET /library/parts/11820/1490520472/file.mkv (19 live) TLS Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:23:56.791 [13232] DEBUG - Content-Length of D:\Videos\Movies\Moana\Moana.mkv is 9571540664.
Apr 01, 2017 00:23:57.702 [9628] DEBUG - Streaming Resource: Updating client bandwidth to 36588kbps with most recent 36588kbps (212992)
Apr 01, 2017 00:23:57.773 [5948] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:23:57.773 [5948] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:23:57.773 [5948] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:23:57.773 [12920] DEBUG - Request: [::ffff:192.168.1.20:4604 (Allowed Network)] GET /library/parts/11820/1490520472/file.mkv (20 live) TLS Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:23:57.773 [12920] DEBUG - Request range: 9571352678 to 0
Apr 01, 2017 00:23:57.775 [12920] DEBUG - Content-Length of D:\Videos\Movies\Moana\Moana.mkv is 9571540664.
Apr 01, 2017 00:23:57.784 [5948] DEBUG - Failed to stream media, client probably disconnected: 10054 - An existing connection was forcibly closed by the remote host
Apr 01, 2017 00:23:57.784 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4603] 200 GET /library/parts/11820/1490520472/file.mkv (19 live) TLS 994ms 1212416 bytes
Apr 01, 2017 00:23:57.821 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4604] 200 GET /library/parts/11820/1490520472/file.mkv (19 live) TLS 47ms 187986 bytes
Apr 01, 2017 00:23:58.041 [5948] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:23:58.041 [5948] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:23:58.041 [5948] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:23:58.041 [12644] DEBUG - Request: [::ffff:192.168.1.20:4605 (Allowed Network)] GET /library/parts/11820/1490520472/file.mkv (20 live) TLS Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:23:58.041 [12644] DEBUG - Request range: 2444668629 to 0
Apr 01, 2017 00:23:58.043 [12644] DEBUG - Content-Length of D:\Videos\Movies\Moana\Moana.mkv is 9571540664.
Apr 01, 2017 00:23:59.127 [9628] DEBUG - Streaming Resource: Updating client bandwidth to 24911kbps with most recent 15911kbps (276372)
Apr 01, 2017 00:24:00.129 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 33935kbps with most recent 63884kbps (147456)
Apr 01, 2017 00:24:01.316 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 33224kbps with most recent 30462kbps (163840)
Apr 01, 2017 00:24:02.030 [5004] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.150 (http://192.168.1.150:2869/upnphost/udhisapi.dll?content=uuid:7e5e7978-ec72-4551-821f-1a7511643d22)
Apr 01, 2017 00:24:02.030 [12176] DEBUG - HTTP requesting GET http://192.168.1.150:2869/upnphost/udhisapi.dll?content=uuid:7e5e7978-ec72-4551-821f-1a7511643d22
Apr 01, 2017 00:24:02.045 [12176] DEBUG - HTTP 200 response from GET http://192.168.1.150:2869/upnphost/udhisapi.dll?content=uuid:7e5e7978-ec72-4551-821f-1a7511643d22
Apr 01, 2017 00:24:02.556 [12176] DEBUG - Streaming Resource: Updating client bandwidth to 31434kbps with most recent 22683kbps (163840)
Apr 01, 2017 00:24:03.626 [5004] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.40 (192.168.1.40)
Apr 01, 2017 00:24:03.626 [12176] DEBUG - HTTP requesting GET 192.168.1.40
Apr 01, 2017 00:24:03.945 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 28919kbps with most recent 12474kbps (147456)
Apr 01, 2017 00:24:05.651 [9628] DEBUG - Streaming Resource: Updating client bandwidth to 26618kbps with most recent 18396kbps (311296)
Apr 01, 2017 00:24:06.744 [6428] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:24:06.744 [6428] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:24:06.744 [6428] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:24:06.744 [11028] DEBUG - Request: [::ffff:192.168.1.20:4598 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=12162&key=%2Flibrary%2Fmetadata%2F12162&state=buffering&playQueueItemID=41895&time=1479792&duration=6432832 (20 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:24:06.745 [11028] DEBUG - Client [9ovsonn6jpctfgekfqzgs0pb] reporting timeline state buffering, progress of 1479792/6432832ms for guid=, ratingKey=12162 url=, key=/library/metadata/12162, containerKey=, metadataId=12162
Apr 01, 2017 00:24:06.747 [11028] DEBUG - Play progress on 12162 'Moana' - got played 1479792 ms by account 1!
Apr 01, 2017 00:24:06.751 [11028] DEBUG - We're going to try to auto-select an audio stream for account 1.
Apr 01, 2017 00:24:06.751 [11028] DEBUG - Selecting best audio stream for part ID 11820 (autoselect: 1 language: ja)
Apr 01, 2017 00:24:06.751 [11028] DEBUG - Audio Stream: 43149, Subtitle Stream: 43151
Apr 01, 2017 00:24:06.752 [11028] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Apr 01, 2017 00:24:06.752 [11028] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Apr 01, 2017 00:24:06.753 [11028] DEBUG - [Now] Profile is Konvergo
Apr 01, 2017 00:24:06.753 [11028] DEBUG - [Now] Updated play state for /library/metadata/12162.
Apr 01, 2017 00:24:06.753 [11028] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Apr 01, 2017 00:24:06.754 [11028] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Apr 01, 2017 00:24:06.755 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4598] 200 GET /:/timeline?hasMDE=1&ratingKey=12162&key=%2Flibrary%2Fmetadata%2F12162&state=buffering&playQueueItemID=41895&time=1479792&duration=6432832 (20 live) TLS GZIP 10ms 423 bytes (pipelined: 14)
Apr 01, 2017 00:24:06.761 [5948] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:24:06.761 [5948] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:24:06.761 [5948] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:24:06.761 [12644] DEBUG - Request: [::ffff:192.168.1.20:4600 (Allowed Network)] GET /status/sessions (19 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:24:06.762 [9628] DEBUG - Streaming Resource: Updating client bandwidth to 25267kbps with most recent 15038kbps (187986)
Apr 01, 2017 00:24:06.762 [6428] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:24:06.762 [6428] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:24:06.762 [6428] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:24:06.762 [12920] DEBUG - Request: [::ffff:192.168.1.20:4595 (Allowed Network)] GET /status/sessions (18 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:24:06.762 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 18753kbps with most recent 9856kbps (1179648)
Apr 01, 2017 00:24:06.762 [12644] DEBUG - [Now] Adding 1 sessions.
Apr 01, 2017 00:24:06.762 [12644] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Apr 01, 2017 00:24:06.763 [12920] DEBUG - [Now] Adding 1 sessions.
Apr 01, 2017 00:24:06.763 [12920] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Apr 01, 2017 00:24:06.763 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4600] 200 GET /status/sessions (18 live) TLS GZIP 2ms 397 bytes (pipelined: 13)
Apr 01, 2017 00:24:06.763 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4595] 200 GET /status/sessions (18 live) TLS GZIP 1ms 470 bytes (pipelined: 2)
Apr 01, 2017 00:24:06.950 [12756] DEBUG - Streaming Resource: Updating client bandwidth to 18790kbps with most recent 19416kbps (163840)
Apr 01, 2017 00:24:08.564 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 17126kbps with most recent 11889kbps (147456)
Apr 01, 2017 00:24:09.909 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 17359kbps with most recent 18885kbps (180224)
Apr 01, 2017 00:24:10.696 [12148] DEBUG - Streaming Resource: Updating client bandwidth to 14746kbps with most recent 14390kbps (147456)
Apr 01, 2017 00:24:11.969 [12148] DEBUG - Streaming Resource: Updating client bandwidth to 14088kbps with most recent 19236kbps (163840)
Apr 01, 2017 00:24:12.732 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 13534kbps with most recent 13219kbps (147456)
Apr 01, 2017 00:24:14.111 [12756] DEBUG - Streaming Resource: Updating client bandwidth to 13946kbps with most recent 19089kbps (180224)
Apr 01, 2017 00:24:14.901 [12148] DEBUG - Streaming Resource: Updating client bandwidth to 13417kbps with most recent 13845kbps (147456)
Apr 01, 2017 00:24:15.689 [12148] DEBUG - Streaming Resource: Updating client bandwidth to 13449kbps with most recent 15792kbps (163840)
Apr 01, 2017 00:24:16.770 [6428] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:24:16.770 [6428] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:24:16.770 [6428] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:24:16.771 [13232] DEBUG - Request: [::ffff:192.168.1.20:4600 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=12162&key=%2Flibrary%2Fmetadata%2F12162&state=buffering&playQueueItemID=41895&time=1479792&duration=6432832 (14 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:24:16.771 [13232] DEBUG - Client [9ovsonn6jpctfgekfqzgs0pb] reporting timeline state buffering, progress of 1479792/6432832ms for guid=, ratingKey=12162 url=, key=/library/metadata/12162, containerKey=, metadataId=12162
Apr 01, 2017 00:24:16.774 [13232] DEBUG - Play progress on 12162 'Moana' - got played 1479792 ms by account 1!
Apr 01, 2017 00:24:16.774 [13232] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Apr 01, 2017 00:24:16.774 [13232] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Apr 01, 2017 00:24:16.774 [13232] DEBUG - [Now] Profile is Konvergo
Apr 01, 2017 00:24:16.774 [13232] DEBUG - [Now] Updated play state for /library/metadata/12162.
Apr 01, 2017 00:24:16.775 [13232] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Apr 01, 2017 00:24:16.775 [13232] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Apr 01, 2017 00:24:16.776 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4600] 200 GET /:/timeline?hasMDE=1&ratingKey=12162&key=%2Flibrary%2Fmetadata%2F12162&state=buffering&playQueueItemID=41895&time=1479792&duration=6432832 (14 live) TLS GZIP 6ms 423 bytes (pipelined: 14)
Apr 01, 2017 00:24:16.786 [5948] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:24:16.786 [5948] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:24:16.786 [5948] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:24:16.787 [13136] DEBUG - Request: [::ffff:192.168.1.20:4598 (Allowed Network)] GET /status/sessions (10 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:24:16.787 [13136] DEBUG - [Now] Adding 1 sessions.
Apr 01, 2017 00:24:16.787 [13136] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Apr 01, 2017 00:24:16.787 [6428] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:24:16.787 [6428] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:24:16.787 [6428] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:24:16.788 [13232] DEBUG - Request: [::ffff:192.168.1.20:4595 (Allowed Network)] GET /status/sessions (10 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:24:16.788 [13232] DEBUG - [Now] Adding 1 sessions.
Apr 01, 2017 00:24:16.788 [13232] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Apr 01, 2017 00:24:16.789 [6428] DEBUG - Completed: [::ffff:192.168.1.20:4598] 200 GET /status/sessions (10 live) TLS GZIP 1ms 397 bytes (pipelined: 15)
Apr 01, 2017 00:24:16.789 [5948] DEBUG - Completed: [::ffff:192.168.1.20:4595] 200 GET /status/sessions (10 live) TLS GZIP 1ms 470 bytes (pipelined: 3)
Apr 01, 2017 00:24:17.024 [12756] DEBUG - Streaming Resource: Updating client bandwidth to 16454kbps with most recent 17022kbps (163840)
Apr 01, 2017 00:24:17.750 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 16179kbps with most recent 16782kbps (147456)
Apr 01, 2017 00:24:18.629 [12176] ERROR - Error issuing curl_easy_perform(handle): 28
Apr 01, 2017 00:24:18.629 [12176] DEBUG - HTTP simulating 408 after curl timeout
Apr 01, 2017 00:24:18.968 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 15591kbps with most recent 6556kbps (163840)
Apr 01, 2017 00:24:20.262 [12176] DEBUG - Streaming Resource: Updating client bandwidth to 15718kbps with most recent 20444kbps (163840)
Apr 01, 2017 00:24:21.100 [12176] DEBUG - Streaming Resource: Updating client bandwidth to 15504kbps with most recent 12090kbps (147456)
Apr 01, 2017 00:24:22.485 [11376] DEBUG - Streaming Resource: Updating client bandwidth to 15610kbps with most recent 19843kbps (180224)
Apr 01, 2017 00:24:23.214 [12756] DEBUG - Streaming Resource: Updating client bandwidth to 15759kbps with most recent 14833kbps (147456)
Apr 01, 2017 00:24:24.458 [12176] DEBUG - Streaming Resource: Updating client bandwidth to 15812kbps with most recent 19939kbps (163840)
Apr 01, 2017 00:24:25.193 [12176] DEBUG - Streaming Resource: Updating client bandwidth to 16139kbps with most recent 17251kbps (163840)
Apr 01, 2017 00:24:26.438 [12176] DEBUG - Streaming Resource: Updating client bandwidth to 16586kbps with most recent 20173kbps (163840)
Apr 01, 2017 00:24:26.771 [6428] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Apr 01, 2017 00:24:26.771 [6428] DEBUG - Auth: authenticated user 1 as cheeseandcereal
Apr 01, 2017 00:24:26.771 [6428] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Apr 01, 2017 00:24:26.771 [11944] DEBUG - Request: [::ffff:192.168.1.20:4598 (Allowed Network)] GET /:/timeline?hasMDE=1&ratingKey=12162&key=%2Flibrary%2Fmetadata%2F12162&state=buffering&playQueueItemID=41895&time=1479792&duration=6432832 (10 live) TLS GZIP Signed-in Token (cheeseandcereal)
Apr 01, 2017 00:24:26.772 [11944] DEBUG - Client [9ovsonn6jpctfgekfqzgs0pb] reporting timeline state buffering, progress of 1479792/6432832ms for guid=, ratingKey=12162 url=, key=/library/metadata/12162, containerKey=, metadataId=12162
Apr 01, 2017 00:24:26.775 [11944] DEBUG - Play progress on 12162 'Moana' - got played 1479792 ms by account 1!
Apr 01, 2017 00:24:26.775 [11944] DEBUG - [Now] User is cheeseandcereal (ID: 1)
Apr 01, 2017 00:24:26.775 [11944] DEBUG - [Now] Device is Konvergo (AdamsDesktop).
Apr 01, 2017 00:24:26.775 [11944] DEBUG - [Now] Profile is Konvergo
Apr 01, 2017 00:24:26.775 [11944] DEBUG - [Now] Updated play state for /library/metadata/12162.
Apr 01, 2017 00:24:26.776 [11944] DEBUG - Statistics: (vua8mqft4vx6r) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Apr 01, 2017 00:24:26.776 [11944] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Apr 01, 2017 00:24:26.777 [6428] DEBUG - Completed: [::ffff:192.168.1.20:4598] 200 GET /:/timeline?hasMDE=1&ratingKey=12162&key=%2Flibrary%2Fmetadata%2F12162&state=buffering&playQueueItemID=41895&time=1479792&duration=6432832 (10 live) TLS GZIP 5ms 423 bytes (pipelined: 16)
Apr 01, 2017 00:24:26.788 [5948] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.

And Plex Media Player Logs:

2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Starting playback... 
2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - mkv: queuing seek to 1479.790000 
2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - mkv: execute seek (to 1479.790000 flags 40) 
2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - mkv: Seeking to 9571352678 to read header element 0x1c53bb6b. 
2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: hr-seek, skipping to 1479.790000 (no framedrop) 
2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Dropping cache at pos 9571352678, cached range: 0-630784. 
2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Seeking underlying stream: 630784 -> 9571352678 
2017-04-01 00:23:56 [ DEBUG ] PlayerComponent.cpp @ 500 - mkv: Parsing cues... 
2017-04-01 00:23:57 [ DEBUG ] PlayerComponent.cpp @ 500 - ffmpeg: tls: Server closed the connection 
2017-04-01 00:23:57 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: EOF reached. 
2017-04-01 00:23:57 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Dropping cache at pos 2444668629, cached range: 9571352678-9571540664. 
2017-04-01 00:23:57 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Seeking underlying stream: 9571540664 -> 2444668629 
2017-04-01 00:24:04 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-04-01 00:24:05 [ INFO  ] JS: %c[Timeline] buffering, 1479792/6432832 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - mkv: seek done 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vd: Pixel formats supported by decoder: dxva2_vld d3d11va_vld yuv420p 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vd: Codec profile: High (0x64) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: 16 decoder devices: 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {86695f12-340e-4f04-9fd3-9253dd327460} MPEG2and1_VLD  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {ee27417f-5e28-4e65-beea-1d26b508adc9} MPEG2_VLD  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {6f3ec719-3735-42cc-8063-65cc3cb36616} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {1b81bea4-a0c7-11d3-b984-00c04f2e73c5} VC1_D2010  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {1b81bea3-a0c7-11d3-b984-00c04f2e73c5} VC1_D  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {32fcfe3f-de46-4a49-861b-ac71110649d5} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {d79be8da-0cf1-4c81-b82a-69a4e236f43d} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {f9aaccbb-c2b6-4cfc-8779-5707b1760552} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {1b81be68-a0c7-11d3-b984-00c04f2e73c5} H264_E  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {5b11d51b-2f4c-4452-bcc3-09f2a1160cc0} HEVC_VLD_Main  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {efd64d74-c9e8-41d7-a5e9-e9b0e39fa319} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {ed418a9f-010d-4eda-9ae3-9a65358d8d2e} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {9947ec6f-689b-11dc-a320-0019dbbc4184} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {33fcfe41-de46-4a49-861b-ac71110649d5} <unknown>  YUY2 NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {6affd11e-1d96-42b1-a215-93a31f09a53d} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - dxva2: {914c84a3-4078-4fa9-984c-e2f262cb5c9c} <unknown>  NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vd: Selecting {1b81be68-a0c7-11d3-b984-00c04f2e73c5} H264_E NV12 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ffmpeg/video: h264: Reinit context to 1920x816, pix_fmt: dxva2_vld 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Adding filter lavrresample  
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Setting option 'normalize' = 'yes' (flags = 0) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Setting option 'o' = 'surround_mix_level=1' (flags = 0) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - lavrresample: Remix: 5.1(side) -> stereo 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Audio filter chain: 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [in] 48000Hz 5.1(side) 6ch floatp 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [lavrresample] 48000Hz stereo 2ch floatp [a] 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [out] 48000Hz stereo 2ch floatp 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [ao] 48000Hz stereo 2ch floatp 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao: Trying audio driver 'wasapi' 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: requested format: 48000 Hz, stereo channels, floatp 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: No device specified. Selecting default. 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: Selecting device '{2b4db603-7d2b-4341-9bb7-a88fc13954bf}' (Speakers (2- ODAC-revB USB DAC)) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: Monitoring changes in device {0.0.0.00000000}.{2b4db603-7d2b-4341-9bb7-a88fc13954bf} 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: Trying stereo float @ 48000hz (shared) -> ok 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: Closest match is stereo float @ 44100hz 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: Accepted as stereo float @ 44100hz (shared) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: Device period: 10 ms 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: Buffer frame count: 2205 (50 ms) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: IAudioClock::GetFrequency gave a frequency of 352800. 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: device buffer: 2205 samples. 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - ao/wasapi: using soft-buffer of 8820 samples. 
2017-04-01 00:24:06 [ INFO  ] PlayerComponent.cpp @ 502 - cplayer: AO: [wasapi] 44100Hz stereo 2ch float 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: AO: Description: Windows WASAPI audio output (event mode) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Removing filter lavrresample  
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Adding filter lavrresample  
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Setting option 'normalize' = 'yes' (flags = 0) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Setting option 'o' = 'surround_mix_level=1' (flags = 0) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - lavrresample: Remix: 5.1(side) -> stereo 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af: Audio filter chain: 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [in] 48000Hz 5.1(side) 6ch floatp 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [lavrresample] 44100Hz stereo 2ch float [a] 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [out] 44100Hz stereo 2ch float 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - af:   [ao] 44100Hz stereo 2ch float 
2017-04-01 00:24:06 [ INFO  ] PlayerComponent.cpp @ 502 - vd: Using hardware decoding (dxva2-copy). 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vd: Decoder format: 1920x804 [0:1] nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vd: Using container aspect ratio. 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vf: Video filter chain: 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vf:   [in] 1920x804 nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - vf:   [out] 1920x804 nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Window size: 2560x1440 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video source: 0x0 (0:0) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video display: (0, 0) 1x1 -> (0, 0) 2560x1440 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video scale: 2560.000000/1440.000000 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: OSD borders: l=-1073740544 t=0 r=-1073740544 b=0 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video borders: l=0 t=0 r=0 b=0 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Set property: video-unscaled=false -> 1 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Set property: video-aspect="-1" -> 1 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Set property: keepaspect=true -> 1 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Set property: panscan=0.000000 -> 1 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Window size: 2560x1440 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video source: 0x0 (0:0) 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video display: (0, 0) 1x1 -> (0, 0) 2560x1440 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video scale: 2560.000000/1440.000000 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: OSD borders: l=-1073740544 t=0 r=-1073740544 b=0 
2017-04-01 00:24:06 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video borders: l=0 t=0 r=0 b=0 
2017-04-01 00:24:07 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-04-01 00:24:07 [ DEBUG ] PlayerComponent.cpp @ 500 - vd: Decoder format: 1920x804 [0:1] nv12 bt.709/bt.709/bt.1886/limited CL=mpeg2/4/h264 
2017-04-01 00:24:07 [ DEBUG ] PlayerComponent.cpp @ 500 - vd: Using container aspect ratio. 
2017-04-01 00:24:13 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-04-01 00:24:15 [ INFO  ] JS: %c[Timeline] buffering, 1479792/6432832 
2017-04-01 00:24:25 [ INFO  ] JS: %c[Timeline] buffering, 1479792/6432832 
2017-04-01 00:24:27 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-04-01 00:24:34 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-04-01 00:24:35 [ INFO  ] JS: %c[Timeline] buffering, 1479792/6432832 
2017-04-01 00:24:45 [ INFO  ] JS: %c[Timeline] buffering, 1479792/6432832 
2017-04-01 00:24:47 [ INFO  ] PlayerComponent.cpp @ 502 - cplayer: VO: [opengl-cb] 1920x804 nv12 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: VO: Description: OpenGL Callbacks for libmpv 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: set video colors output-levels=0  
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Window size: 2560x1440 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video source: 1920x804 (1:1) 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video display: (0, 0) 1920x804 -> (0, 184) 2560x1072 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video scale: 1.333333/1.333333 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: OSD borders: l=0 t=184 r=0 b=184 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Video borders: l=0 t=184 r=0 b=184 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Testing FBO format 0x805b 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Create FBO: 16x16 (16x16) 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Using FBO format 0x805b. 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: No advanced processing required. Enabling dumb mode. 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Texture for plane 0: 1920x804 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - opengl-cb: Texture for plane 1: 960x402 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: first video frame after restart shown 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: starting audio playback 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: playback restart complete 
2017-04-01 00:24:47 [ INFO  ] PlayerComponent.cpp @ 386 - Entering state: playing 
2017-04-01 00:24:47 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-04-01 00:24:47 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: Enter buffering. 
2017-04-01 00:24:47 [ INFO  ] PlayerComponent.cpp @ 394 - Entering state: buffering 
2017-04-01 00:24:47 [ INFO  ] JS: %c[Timeline] playing, 1479792/6432832 
2017-04-01 00:24:47 [ INFO  ] JS: %c[PlayerController] State change playing 
2017-04-01 00:24:47 [ DEBUG ] PowerComponent.cpp @ 58 - Disabling OS screensaver 
2017-04-01 00:24:47 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-04-01 00:24:47 [ INFO  ] JS: %c[Player] 0% buffered 
2017-04-01 00:24:47 [ INFO  ] JS: %c[Commands] Executing persistPlayQueue 
2017-04-01 00:24:47 [ INFO  ] JS: %c[Timeline] buffering, 1479812/6432832 
2017-04-01 00:24:47 [ INFO  ] JS: %c[PlayerController] State change buffering 
2017-04-01 00:24:47 [ DEBUG ] PowerComponent.cpp @ 53 - Enabling OS screensaver 
2017-04-01 00:24:47 [ INFO  ] JS: %c[Player] 13% buffered 
2017-04-01 00:24:48 [ DEBUG ] PlayerComponent.cpp @ 500 - cache: Cache is not responding - slow/stuck network connection? 
2017-04-01 00:24:48 [ INFO  ] JS: %c[Player] 30% buffered 
2017-04-01 00:24:49 [ INFO  ] JS: %c[Player] 46% buffered 
2017-04-01 00:24:49 [ INFO  ] JS: %c[Player] 63% buffered 
2017-04-01 00:24:50 [ INFO  ] JS: %c[Player] 79% buffered 
2017-04-01 00:24:51 [ INFO  ] JS: %c[Player] 80% buffered 
2017-04-01 00:24:51 [ INFO  ] JS: %c[Player] 96% buffered 
2017-04-01 00:24:53 [ DEBUG ] PlayerComponent.cpp @ 500 - cplayer: End buffering (waited 6.024617 secs). 
2017-04-01 00:24:53 [ INFO  ] PlayerComponent.cpp @ 386 - Entering state: playing

I can't seem to find anything indicating an issue besides network. Any ideas?

Also, is there a timeout or something with SVP for detecting media files? Because whenever launching a video takes a bit of time to buffer, I noticed SVP will just ignore it, saying it doesn't look like a media file. Is this timeout something I can change in the settings somewhere?



Edit: Also, just tried re-installing Plex Media Player with default settings, and I didn't get any buffering/issues until I installed the custom mpv64 from SVP again, so the issue definitely has something to do with the custom MPV.

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

>  I didn't get any buffering/issues until I installed the custom mpv64 from SVP again, so the issue definitely has something to do with the custom MVP

still you don't get "buffering issue" with SVP's libmpv when SVP is actually off, right?

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

Never actually tried that.

Just turned off SVP, and yeah, I still get the buffering issues even while SVP is off (only when using SVP's libmpv).

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

this's interesting

probably Plex made their own optimizations to the mpv?

what if take the "official" mpv release from there? (you need the "Dev" package)

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

I got it to act up once in testing with that mpv release, but it seems to act up less often? Could just need more testing though, but it definitely still does have similar issues.

Re: SVP Will Randomly Stop Working in the Middle of Playback (Plex)

Chiming in here to say that I am encountering very similar issues. Plex gets stuck at some point when using SVP. However, disabling SVP drastically reduces the occurrence of this issue. Reinstalling plex or replacing with the prepackaged MPV stops the issue from occurring. The latest server update has also reduced it, but not eliminated it completely.

Will follow the instructions on getting the log for MPV once I am back home Monday. Just wanted to let you guys know that cheese is not having a one-off issue.