Hi everyone o/
I have a really weird bug I’m looking for help with…
Basically, whenever I play a video, it will play flawlessly for a few minutes, and then start buffering indefinitely.
Of course, the first thing to look at is a connection error, so I’m trying it on localhost.
The second thing would be a transcode error, but the transcode speed for this file is >26, and the transcode is is in the throttling state when the buffering happens.
This started happening when I swapped to a new storage pool (from storage spaces to snapraid), so I also took a look to see if there might be a disk spinning down, but even when I continuously transfer a file to/from the disk, the same problem occurs.
The problem persists through reboots, when attempting to play a library on a different drive (such as my SSD boot drive), and it even persisted through a re-install. Though closing the playback and re-starting it always solves the issue (until the next few minute mark).
The logs indicate that the transcode gets throttled, and then never unthrottles
All in all, I’m way out of my depths on this one.
Server Version#: 1.25.1.5286
Player Version#: 1.25.1.5286 (web player of version 1.25.1.5286)
Some logs incase you’re able to get more out of it than I am:
Logs
Dec 07, 2021 23:10:21.195 [12372] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=209268&playQueueItemID=83&state=playing&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=918000&duration=3014000 (15 live) TLS GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:21.196 [12372] DEBUG - Client [cr9tbaadb3p10sdyfiajqo2h] reporting timeline state playing, progress of 918000/3014000ms for guid=, playbackTime=209268ms ratingKey=60 url=, key=/library/metadata/60, containerKey=, metadataId=60, source=
Dec 07, 2021 23:10:21.197 [12372] DEBUG - Play progress on 60 'The Road Not Taken' - got played 918000 ms by account 1!
Dec 07, 2021 23:10:21.198 [12372] DEBUG - [Now] User is blahblah@gmail.com (ID: 1)
Dec 07, 2021 23:10:21.198 [12372] DEBUG - [Now] Device is Chrome (Chrome).
Dec 07, 2021 23:10:21.198 [12372] DEBUG - [Now] Profile is Web
Dec 07, 2021 23:10:21.198 [12372] DEBUG - [Now] Updated play state for /library/metadata/60.
Dec 07, 2021 23:10:21.199 [12372] DEBUG - Statistics: (vxre0af3yhscy3smepqh2m4s) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Dec 07, 2021 23:10:21.200 [10084] DEBUG - Completed: [192.168.1.101:14281] 200 GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=209268&playQueueItemID=83&state=playing&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=918000&duration=3014000 (15 live) TLS GZIP 4ms 892 bytes (pipelined: 109)
Dec 07, 2021 23:10:21.210 [12372] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/1/187.m4s (15 live) TLS GZIP Signed-in
Dec 07, 2021 23:10:21.210 [12372] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Asked for segment 187 from session.
Dec 07, 2021 23:10:21.210 [12372] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Returning segment 187 from session
Dec 07, 2021 23:10:21.211 [12372] DEBUG - Content-Length of V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\init-stream1.m4s,V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\chunk-stream1-00188.m4s is 124300 (of total: 124300).
Dec 07, 2021 23:10:21.213 [9732] DEBUG - Completed: [192.168.1.101:14281] 200 GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/1/187.m4s (15 live) TLS GZIP 3ms 124300 bytes (pipelined: 110)
Dec 07, 2021 23:10:21.315 [12372] DEBUG - Request: [192.168.1.101:7319 (Subnet)] GET /status/sessions (16 live) GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:21.315 [12372] DEBUG - [Now] Adding 2 sessions.
Dec 07, 2021 23:10:21.316 [10084] DEBUG - Completed: [192.168.1.101:7319] 200 GET /status/sessions (16 live) GZIP 1ms 2619 bytes (pipelined: 1)
Dec 07, 2021 23:10:21.627 [18548] DEBUG - [Transcode] Session hhsj50xi57tlu026swjpnc4l (4) is unthrottling
Dec 07, 2021 23:10:21.627 [18548] DEBUG - [Transcoder] Throttle - Getting back to work.
Dec 07, 2021 23:10:21.706 [18548] DEBUG - [Transcode] Transcoder segment range: 141 - 210 (210)
Dec 07, 2021 23:10:21.814 [24752] DEBUG - [Transcode] Transcoder segment range: 141 - 211 (211)
Dec 07, 2021 23:10:21.851 [24752] DEBUG - [Transcode] Transcoder segment range: 141 - 211 (211)
Dec 07, 2021 23:10:21.921 [24752] DEBUG - [Transcode] Transcoder segment range: 141 - 212 (212)
Dec 07, 2021 23:10:21.981 [5108] DEBUG - [Transcode] Transcoder segment range: 141 - 212 (212)
Dec 07, 2021 23:10:22.018 [5108] DEBUG - [Transcode] Session hhsj50xi57tlu026swjpnc4l (4) is throttling
Dec 07, 2021 23:10:22.018 [5108] DEBUG - [Transcoder] Throttle - Going into sloth mode.
Dec 07, 2021 23:10:23.578 [9732] DEBUG - Completed: [[::1]:12207] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (18 live) GZIP 20015ms 5 bytes (pipelined: 186)
Dec 07, 2021 23:10:23.588 [5108] DEBUG - Request: [[::1]:12207 (Loopback)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (18 live) GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:23.588 [5108] DEBUG - Content-Length is -1 (of total: -1).
Dec 07, 2021 23:10:26.364 [12372] DEBUG - [Transcode] Transcoder segment range: 0 - 257 (257)
Dec 07, 2021 23:10:30.589 [5108] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/0/186.m4s (16 live) TLS GZIP Signed-in
Dec 07, 2021 23:10:30.589 [5108] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Asked for segment 186 from session.
Dec 07, 2021 23:10:30.589 [5108] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Returning segment 186 from session
Dec 07, 2021 23:10:30.590 [5108] DEBUG - Content-Length of V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\init-stream0.m4s,V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\chunk-stream0-00187.m4s is 5431102 (of total: 5431102).
Dec 07, 2021 23:10:30.623 [10084] DEBUG - Completed: [192.168.1.101:14281] 200 GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/0/186.m4s (16 live) TLS GZIP 34ms 5431102 bytes (pipelined: 111)
Dec 07, 2021 23:10:30.921 [9732] DEBUG - Completed: [192.168.1.101:4753] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (16 live) TLS GZIP 20007ms 5 bytes (pipelined: 28)
Dec 07, 2021 23:10:30.931 [18548] DEBUG - Request: [192.168.1.101:4753 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (16 live) TLS GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:30.931 [18548] DEBUG - Content-Length is -1 (of total: -1).
Dec 07, 2021 23:10:31.196 [18548] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=219272&playQueueItemID=83&state=playing&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=928000&duration=3014000 (16 live) TLS GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:31.196 [18548] DEBUG - Client [cr9tbaadb3p10sdyfiajqo2h] reporting timeline state playing, progress of 928000/3014000ms for guid=, playbackTime=219272ms ratingKey=60 url=, key=/library/metadata/60, containerKey=, metadataId=60, source=
Dec 07, 2021 23:10:31.197 [18548] DEBUG - Play progress on 60 'The Road Not Taken' - got played 928000 ms by account 1!
Dec 07, 2021 23:10:31.199 [18548] DEBUG - [Now] User is blahblah@gmail.com (ID: 1)
Dec 07, 2021 23:10:31.199 [18548] DEBUG - [Now] Device is Chrome (Chrome).
Dec 07, 2021 23:10:31.199 [18548] DEBUG - [Now] Profile is Web
Dec 07, 2021 23:10:31.199 [18548] DEBUG - [Now] Updated play state for /library/metadata/60.
Dec 07, 2021 23:10:31.199 [18548] DEBUG - Statistics: (vxre0af3yhscy3smepqh2m4s) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Dec 07, 2021 23:10:31.201 [9732] DEBUG - Completed: [192.168.1.101:14281] 200 GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=219272&playQueueItemID=83&state=playing&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=928000&duration=3014000 (16 live) TLS GZIP 5ms 893 bytes (pipelined: 112)
Dec 07, 2021 23:10:31.250 [18548] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/1/188.m4s (16 live) TLS GZIP Signed-in
Dec 07, 2021 23:10:31.250 [18548] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Asked for segment 188 from session.
Dec 07, 2021 23:10:31.250 [18548] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Returning segment 188 from session
Dec 07, 2021 23:10:31.252 [18548] DEBUG - Content-Length of V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\init-stream1.m4s,V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\chunk-stream1-00189.m4s is 123525 (of total: 123525).
Dec 07, 2021 23:10:31.254 [10084] DEBUG - Completed: [192.168.1.101:14281] 200 GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/1/188.m4s (16 live) TLS GZIP 3ms 123525 bytes (pipelined: 113)
Dec 07, 2021 23:10:35.308 [12372] DEBUG - Request: [127.0.0.1:7341 (Loopback)] GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=710196&playQueueItemID=1&state=buffering&hasMDE=1&context=home%3Ahub.tv.recentlyadded&row=0&col=4&time=709000&duration=3014000 (17 live) GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:35.309 [12372] DEBUG - Client [s5ad7rqsxdr16g7mp7d23763] reporting timeline state buffering, progress of 709000/3014000ms for guid=, playbackTime=710196ms ratingKey=60 url=, key=/library/metadata/60, containerKey=, metadataId=60, source=
Dec 07, 2021 23:10:35.310 [12372] DEBUG - Play progress on 60 'The Road Not Taken' - got played 709000 ms by account 1!
Dec 07, 2021 23:10:35.312 [12372] DEBUG - [Now] User is blahblah@gmail.com (ID: 1)
Dec 07, 2021 23:10:35.312 [12372] DEBUG - [Now] Device is Chrome (Chrome).
Dec 07, 2021 23:10:35.312 [12372] DEBUG - [Now] Profile is Web
Dec 07, 2021 23:10:35.312 [12372] DEBUG - [Now] Updated play state for /library/metadata/60.
Dec 07, 2021 23:10:35.312 [12372] DEBUG - Statistics: (3ca7lcq3nq2i5wlvozmw6dzv) Reporting active playback in state 2 of type 4 (scrobble: 0) for account 1
Dec 07, 2021 23:10:35.313 [10084] DEBUG - Completed: [127.0.0.1:7341] 200 GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=710196&playQueueItemID=1&state=buffering&hasMDE=1&context=home%3Ahub.tv.recentlyadded&row=0&col=4&time=709000&duration=3014000 (17 live) GZIP 4ms 755 bytes (pipelined: 1)
Dec 07, 2021 23:10:35.440 [12372] DEBUG - Request: [192.168.1.101:7319 (Subnet)] GET /status/sessions (17 live) GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:35.440 [12372] DEBUG - [Now] Adding 2 sessions.
Dec 07, 2021 23:10:35.442 [9732] DEBUG - Completed: [192.168.1.101:7319] 200 GET /status/sessions (17 live) GZIP 1ms 2619 bytes (pipelined: 2)
Dec 07, 2021 23:10:38.348 [18548] DEBUG - [Transcode] Transcoder segment range: 141 - 212 (212)
Dec 07, 2021 23:10:38.776 [9732] DEBUG - Completed: [127.0.0.1:12524] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) GZIP 20013ms 5 bytes (pipelined: 217)
Dec 07, 2021 23:10:38.789 [12372] DEBUG - Request: [127.0.0.1:12524 (Loopback)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:38.789 [12372] DEBUG - Content-Length is -1 (of total: -1).
Dec 07, 2021 23:10:39.709 [5108] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/0/187.m4s (17 live) TLS GZIP Signed-in
Dec 07, 2021 23:10:39.709 [5108] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Asked for segment 187 from session.
Dec 07, 2021 23:10:39.709 [5108] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Returning segment 187 from session
Dec 07, 2021 23:10:39.710 [5108] DEBUG - Content-Length of V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\init-stream0.m4s,V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\chunk-stream0-00188.m4s is 8671769 (of total: 8671769).
Dec 07, 2021 23:10:39.763 [10084] DEBUG - Completed: [192.168.1.101:14281] 200 GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/0/187.m4s (17 live) TLS GZIP 53ms 8671769 bytes (pipelined: 114)
Dec 07, 2021 23:10:40.271 [12372] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/1/189.m4s (17 live) TLS GZIP Signed-in
Dec 07, 2021 23:10:40.271 [12372] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Asked for segment 189 from session.
Dec 07, 2021 23:10:40.271 [12372] DEBUG - [Transcode/hhsj50xi57tlu026swjpnc4l] Returning segment 189 from session
Dec 07, 2021 23:10:40.273 [12372] DEBUG - Content-Length of V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\init-stream1.m4s,V:\.plex\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-hhsj50xi57tlu026swjpnc4l-7bc67da9-5f84-44ed-91de-db30ef7e9996\chunk-stream1-00190.m4s is 124319 (of total: 124319).
Dec 07, 2021 23:10:40.275 [10084] DEBUG - Completed: [192.168.1.101:14281] 200 GET /video/:/transcode/universal/session/hhsj50xi57tlu026swjpnc4l/1/189.m4s (17 live) TLS GZIP 4ms 124319 bytes (pipelined: 115)
Dec 07, 2021 23:10:40.627 [24752] DEBUG - [Transcode] Session hhsj50xi57tlu026swjpnc4l (4) is unthrottling
Dec 07, 2021 23:10:40.627 [24752] DEBUG - [Transcoder] Throttle - Getting back to work.
Dec 07, 2021 23:10:40.720 [18548] DEBUG - [Transcode] Transcoder segment range: 141 - 213 (213)
Dec 07, 2021 23:10:40.777 [18548] DEBUG - [Transcode] Transcoder segment range: 141 - 214 (214)
Dec 07, 2021 23:10:40.826 [18548] DEBUG - [Transcode] Transcoder segment range: 141 - 214 (214)
Dec 07, 2021 23:10:40.938 [18548] DEBUG - [Transcode] Transcoder segment range: 141 - 214 (214)
Dec 07, 2021 23:10:41.046 [18548] DEBUG - [Transcode] Transcoder segment range: 141 - 215 (215)
Dec 07, 2021 23:10:41.047 [24752] DEBUG - [Transcode] Session hhsj50xi57tlu026swjpnc4l (4) is throttling
Dec 07, 2021 23:10:41.047 [24752] DEBUG - [Transcoder] Throttle - Going into sloth mode.
Dec 07, 2021 23:10:41.203 [5108] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=229283&playQueueItemID=83&state=playing&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=938000&duration=3014000 (18 live) TLS GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:41.204 [5108] DEBUG - Client [cr9tbaadb3p10sdyfiajqo2h] reporting timeline state playing, progress of 938000/3014000ms for guid=, playbackTime=229283ms ratingKey=60 url=, key=/library/metadata/60, containerKey=, metadataId=60, source=
Dec 07, 2021 23:10:41.205 [5108] DEBUG - Play progress on 60 'The Road Not Taken' - got played 938000 ms by account 1!
Dec 07, 2021 23:10:41.206 [5108] DEBUG - [Now] User is blahblah@gmail.com (ID: 1)
Dec 07, 2021 23:10:41.206 [5108] DEBUG - [Now] Device is Chrome (Chrome).
Dec 07, 2021 23:10:41.206 [5108] DEBUG - [Now] Profile is Web
Dec 07, 2021 23:10:41.206 [5108] DEBUG - [Now] Updated play state for /library/metadata/60.
Dec 07, 2021 23:10:41.206 [5108] DEBUG - Statistics: (vxre0af3yhscy3smepqh2m4s) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Dec 07, 2021 23:10:41.208 [9732] DEBUG - Completed: [192.168.1.101:14281] 200 GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=229283&playQueueItemID=83&state=playing&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=938000&duration=3014000 (18 live) TLS GZIP 4ms 902 bytes (pipelined: 116)
Dec 07, 2021 23:10:41.385 [12372] DEBUG - [Transcode] Transcoder segment range: 0 - 258 (258)
Dec 07, 2021 23:10:42.491 [5108] DEBUG - [Transcode] Transcoder segment range: 141 - 215 (215)
Dec 07, 2021 23:10:43.591 [9732] DEBUG - Completed: [[::1]:12207] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (19 live) GZIP 20003ms 5 bytes (pipelined: 187)
Dec 07, 2021 23:10:43.600 [24752] DEBUG - Request: [[::1]:12207 (Loopback)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (19 live) GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:43.601 [24752] DEBUG - Content-Length is -1 (of total: -1).
Dec 07, 2021 23:10:49.685 [18548] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=238304&playQueueItemID=83&state=buffering&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=946000&duration=3014000 (17 live) TLS GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:49.686 [18548] DEBUG - Client [cr9tbaadb3p10sdyfiajqo2h] reporting timeline state buffering, progress of 946000/3014000ms for guid=, playbackTime=238304ms ratingKey=60 url=, key=/library/metadata/60, containerKey=, metadataId=60, source=
Dec 07, 2021 23:10:49.687 [18548] DEBUG - Play progress on 60 'The Road Not Taken' - got played 946000 ms by account 1!
Dec 07, 2021 23:10:49.688 [18548] DEBUG - [Now] User is blahblah@gmail.com (ID: 1)
Dec 07, 2021 23:10:49.688 [18548] DEBUG - [Now] Device is Chrome (Chrome).
Dec 07, 2021 23:10:49.688 [18548] DEBUG - [Now] Profile is Web
Dec 07, 2021 23:10:49.688 [18548] DEBUG - [Now] Updated play state for /library/metadata/60.
Dec 07, 2021 23:10:49.688 [18548] DEBUG - Statistics: (vxre0af3yhscy3smepqh2m4s) Reporting active playback in state 2 of type 4 (scrobble: 0) for account 1
Dec 07, 2021 23:10:49.690 [10084] DEBUG - Completed: [192.168.1.101:14281] 200 GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=238304&playQueueItemID=83&state=buffering&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=946000&duration=3014000 (17 live) TLS GZIP 5ms 901 bytes (pipelined: 117)
Dec 07, 2021 23:10:49.838 [24752] DEBUG - Request: [192.168.1.101:7319 (Subnet)] GET /status/sessions (17 live) GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:49.838 [24752] DEBUG - [Now] Adding 2 sessions.
Dec 07, 2021 23:10:49.840 [9732] DEBUG - Completed: [192.168.1.101:7319] 200 GET /status/sessions (17 live) GZIP 1ms 2625 bytes (pipelined: 3)
Dec 07, 2021 23:10:50.934 [10084] DEBUG - Completed: [192.168.1.101:4753] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) TLS GZIP 20003ms 5 bytes (pipelined: 29)
Dec 07, 2021 23:10:50.940 [24752] DEBUG - Request: [192.168.1.101:4753 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) TLS GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:50.940 [24752] DEBUG - Content-Length is -1 (of total: -1).
Dec 07, 2021 23:10:51.197 [5108] DEBUG - Request: [192.168.1.101:14281 (Subnet)] GET /:/timeline?ratingKey=60&key=%2Flibrary%2Fmetadata%2F60&playbackTime=238342&playQueueItemID=83&state=buffering&hasMDE=1&context=home%3Ahub.continueWatching&row=0&col=0&time=946000&duration=3014000 (17 live) TLS GZIP Signed-in Token (blahblah@gmail.com)
Dec 07, 2021 23:10:51.197 [5108] DEBUG - Client [cr9tbaadb3p10sdyfiajqo2h] reporting timeline state buffering, progress of 946000/3014000ms for guid=, playbackTime=238342ms ratingKey=60 url=, key=/library/metadata/60, containerKey=, metadataId=60, source=
Dec 07, 2021 23:10:51.199 [5108] DEBUG - Play progress on 60 'The Road Not Taken' - got played 946000 ms by account 1!
Dec 07, 2021 23:10:51.200 [5108] DEBUG - [Now] User is blahblah@gmail.com (ID: 1)
Dec 07, 2021 23:10:51.200 [5108] DEBUG - [Now] Device is Chrome (Chrome).
Dec 07, 2021 23:10:51.200 [5108] DEBUG - [Now] Profile is Web
Dec 07, 2021 23:10:51.200 [5108] DEBUG - [Now] Updated play state for /library/metadata/60.
