jhadmin@JH-SRV-PLEX:~$ tail -f /var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Logs/Plex\ Media\ Server.log*
Dec 05, 2018 15:03:05.577 [0x7f4adcffe700] DEBUG - HTTP requesting GET https://plex.tv/servers/03c53037a5be085271fe13ecf333fea7718846f1/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Dec 05, 2018 15:03:05.578 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:05.579 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.8:49897 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (7 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:05.580 [0x7f4ad97fc700] DEBUG - Beginning read from two-way stream.
Dec 05, 2018 15:03:06.383 [0x7f4adcffe700] DEBUG - HTTP 200 response from GET https://plex.tv/servers/03c53037a5be085271fe13ecf333fea7718846f1/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Dec 05, 2018 15:03:06.386 [0x7f4adcffe700] DEBUG - MyPlex: updating with 31 access tokens
Dec 05, 2018 15:03:06.389 [0x7f4ae13ff700] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Dec 05, 2018 15:03:07.068 [0x7f4ae13ff700] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Dec 05, 2018 15:03:07.731 [0x7f4af67ff700] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Dec 05, 2018 15:03:08.320 [0x7f4af67ff700] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Dec 05, 2018 15:03:16.069 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:16.070 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33863 (Allowed Network)] POST /playQueues?uri=library%3A%2F%2Fc9c8533b-fe6d-4ddd-a143-114aedfdee37%2Fitem%2F%252Flibrary%252Fmetadata%252F29304&type=video&key=%2Flibrary%2Fmetadata%2F29304&includeChapters=1 (7 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:16.081 [0x7f4ae77fe700] DEBUG - PlayQueue: 0 generated IDs compressed down to a 2 byte blob.
Dec 05, 2018 15:03:16.090 [0x7f4ae77fe700] DEBUG - PlayQueue: Start index: 0 End index: 0 Count: 1
Dec 05, 2018 15:03:16.090 [0x7f4ae77fe700] DEBUG - PlayQueue: 1 generated IDs compressed down to a 24 byte blob.
Dec 05, 2018 15:03:16.095 [0x7f4ae77fe700] DEBUG - PlayQueue: Added 1 items in 0.0 sec.
Dec 05, 2018 15:03:16.110 [0x7f4ae77fe700] DEBUG - It took 0.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:16.113 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:16.113 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 61681 (autoselect: 1 language: en)
Dec 05, 2018 15:03:16.113 [0x7f4ae77fe700] DEBUG - Audio Stream: 94018, Subtitle Stream: 0
Dec 05, 2018 15:03:16.118 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33863] 200 POST /playQueues?uri=library%3A%2F%2Fc9c8533b-fe6d-4ddd-a143-114aedfdee37%2Fitem%2F%252Flibrary%252Fmetadata%252F29304&type=video&key=%2Flibrary%2Fmetadata%2F29304&includeChapters=1 (7 live) TLS GZIP 49ms 6439 bytes (pipelined: 1)
Dec 05, 2018 15:03:16.204 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:16.205 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /video/:/transcode/universal/decision (8 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:16.205 [0x7f4ae77fe700] DEBUG - Found session GUID of 963479ace4f3a64bd7777d8f574320bf in session start.
Dec 05, 2018 15:03:16.208 [0x7f4ae77fe700] DEBUG - TranscodeUniversalRequest: using augmented profile Roku-7.x
Dec 05, 2018 15:03:16.209 [0x7f4ae77fe700] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/29304?includeBandwidths=1&offset=2695&X-Plex-Client-Capabilities=videoDecoders%3Dh264%7Bprofile%3Ahigh%26resolution%3A1080%26level%3D41%7D;audioDecoders%3Daac%7Bchannels%3A2%7D%2Cac3%7Bchannels%3A6%7D%2Ceac3%7Bchannels%3A8%7D&X-Plex-Session-Identifier=963479ace4f3a64bd7777d8f574320bf
Dec 05, 2018 15:03:16.210 [0x7f4ae77fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:16.221 [0x7f4ae77fe700] DEBUG - It took 0.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:16.224 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:16.224 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 61681 (autoselect: 1 language: en)
Dec 05, 2018 15:03:16.224 [0x7f4ae77fe700] DEBUG - Audio Stream: 94018, Subtitle Stream: 0
Dec 05, 2018 15:03:16.228 [0x7f4ae77fe700] DEBUG - Scaled up video bitrate to 25384Kbps based on 1.500000x fudge factor.
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Selected protocol hls; container: mpegts
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: analyzing media item 27036
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): Direct Play is disabled
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): media must be transcoded in order to use the hls protocol
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): no direct play video profile exists for http/mkv/vc1
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): no direct play video profile exists for http/mkv/vc1/ac3
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): no direct play video profile exists for http/mkv/vc1/truehd
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): no direct play video profile exists for http/mkv/vc1/ac3
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): no remuxable profile found, so video stream will be transcoded
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Cannot direct stream video stream due to profile or setting limitations
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - Scaled up video bitrate to 25384Kbps based on 1.500000x fudge factor.
Dec 05, 2018 15:03:16.229 [0x7f4ae77fe700] DEBUG - MDE: Harry Potter and the Chamber of Secrets (2002): selected media 0 / 27036
Dec 05, 2018 15:03:16.230 [0x7f4ae77fe700] DEBUG - Streaming Resource: Adding session 0x7f4af28386e0:963479ace4f3a64bd7777d8f574320bf which is using transcoder slot.  Used slots is now 1
Dec 05, 2018 15:03:16.230 [0x7f4ae77fe700] DEBUG - Streaming Resource: Added session 0x7f4af28386e0:963479ace4f3a64bd7777d8f574320bf
Dec 05, 2018 15:03:16.230 [0x7f4ae77fe700] DEBUG - Streaming Resource: Reached Decision id=29304 codes=(General=1001,Direct play not available; Conversion OK. Direct Play=3000,App cannot direct play this item. Direct play is disabled. Transcode=1001,Direct play not available; Conversion OK.) media=(id=27036 part=(id=61681 decision=transcode container=mpegts protocol=hls streams=(Video=(id=94017 decision=transcode bitrate=25384 encoder=libx264 width=1920 height=1080) Audio=(id=94018 decision=copy channels=6 rate=48000))))
Dec 05, 2018 15:03:16.234 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /video/:/transcode/universal/decision (8 live) TLS GZIP 29ms 5248 bytes (pipelined: 1)
Dec 05, 2018 15:03:16.734 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:16.735 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33863 (Allowed Network)] GET /:/timeline?playbackTime=0&time=2695000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=buffering&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (8 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:16.737 [0x7f4ae77fe700] DEBUG - Client [963479ace4f3a64bd7777d8f574320bf] reporting timeline state buffering, progress of 2695000/9656188ms for guid=com.plexapp.agents.imdb://tt0295297?lang=en, ratingKey=29304 url=, key=/library/metadata/29304, containerKey=, metadataId=29304, source=
Dec 05, 2018 15:03:16.745 [0x7f4ae77fe700] DEBUG - Play progress on 29304 'Harry Potter and the Chamber of Secrets' - got played 2695000 ms by account 1!
Dec 05, 2018 15:03:16.754 [0x7f4ae77fe700] DEBUG - It took 10.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:16.801 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:16.801 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 61681 (autoselect: 1 language: en)
Dec 05, 2018 15:03:16.801 [0x7f4ae77fe700] DEBUG - Audio Stream: 94018, Subtitle Stream: 0
Dec 05, 2018 15:03:16.805 [0x7f4ae77fe700] DEBUG - [Now] User is jhadmin1 (ID: 1)
Dec 05, 2018 15:03:16.805 [0x7f4ae77fe700] DEBUG - [Now] Device is Roku (3810X - 4K - David Office).
Dec 05, 2018 15:03:16.805 [0x7f4ae77fe700] DEBUG - [Now] Profile is Roku-7.x
Dec 05, 2018 15:03:16.805 [0x7f4ae77fe700] DEBUG - [Now] Updated play state for /library/metadata/29304.
Dec 05, 2018 15:03:16.806 [0x7f4ae77fe700] DEBUG - Statistics: (963479ace4f3a64bd7777d8f574320bf) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Dec 05, 2018 15:03:16.810 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33863] 200 GET /:/timeline?playbackTime=0&time=2695000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=buffering&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (8 live) TLS GZIP 75ms 499 bytes (pipelined: 2)
Dec 05, 2018 15:03:16.855 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:16.855 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49910 (Allowed Network)] GET /status/sessions (10 live) TLS GZIP Signed-in
Dec 05, 2018 15:03:16.856 [0x7f4ae77fe700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:16.856 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.8:49909 (Allowed Network)] GET /status/sessions (10 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:16.856 [0x7f4ad97fc700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:16.857 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49910] 200 GET /status/sessions (10 live) TLS GZIP 2ms 397 bytes (pipelined: 1)
Dec 05, 2018 15:03:16.858 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49909] 200 GET /status/sessions (10 live) TLS GZIP 2ms 470 bytes (pipelined: 1)
Dec 05, 2018 15:03:17.138 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:17.139 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.224:33865 (Allowed Network)] PUT /library/parts/61681?subtitleStreamID=0&allParts=1 (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.145 [0x7f4af4ffe700] DEBUG - Selecting subtitle stream 0 for part 61681
Dec 05, 2018 15:03:17.152 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33865] 200 PUT /library/parts/61681?subtitleStreamID=0&allParts=1 (11 live) TLS GZIP 12ms 195 bytes (pipelined: 1)
Dec 05, 2018 15:03:17.218 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:17.219 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33863 (Allowed Network)] GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (12 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.220 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33863] 404 GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (12 live) TLS GZIP 1ms 379 bytes (pipelined: 3)
Dec 05, 2018 15:03:17.251 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:17.252 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33867 (Allowed Network)] GET /video/:/transcode/universal/start.m3u8 (12 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.252 [0x7f4ad97fc700] DEBUG - Found session GUID of 963479ace4f3a64bd7777d8f574320bf in session start.
Dec 05, 2018 15:03:17.254 [0x7f4ad97fc700] DEBUG - TranscodeUniversalRequest: using augmented profile Roku-7.x
Dec 05, 2018 15:03:17.256 [0x7f4ad97fc700] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/29304?checkFiles=1&includeBandwidths=1&offset=2695&X-Plex-Client-Capabilities=videoDecoders%3Dh264%7Bprofile%3Ahigh%26resolution%3A1080%26level%3D41%7D;audioDecoders%3Daac%7Bchannels%3A2%7D%2Cac3%7Bchannels%3A6%7D%2Ceac3%7Bchannels%3A8%7D&X-Plex-Session-Identifier=963479ace4f3a64bd7777d8f574320bf
Dec 05, 2018 15:03:17.257 [0x7f4ad97fc700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:17.271 [0x7f4ad97fc700] DEBUG - It took 0.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:17.278 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:17.278 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 61681 (autoselect: 1 language: en)
Dec 05, 2018 15:03:17.278 [0x7f4ad97fc700] DEBUG - Audio Stream: 94018, Subtitle Stream: 0
Dec 05, 2018 15:03:17.282 [0x7f4ad97fc700] DEBUG - Found session GUID of 963479ace4f3a64bd7777d8f574320bf in session start.
Dec 05, 2018 15:03:17.282 [0x7f4ad97fc700] DEBUG - Using session GUID 963479ace4f3a64bd7777d8f574320bf for new transcode session.
Dec 05, 2018 15:03:17.283 [0x7f4ad97fc700] DEBUG - Cleaning directory for session 963479ace4f3a64bd7777d8f574320bf ()
Dec 05, 2018 15:03:17.285 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33867] 200 GET /video/:/transcode/universal/start.m3u8 (12 live) TLS GZIP 33ms 480 bytes (pipelined: 1)
Dec 05, 2018 15:03:17.301 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:17.301 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.224:33867 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/index.m3u8 (12 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.302 [0x7f4af4ffe700] DEBUG - Found session GUID of 963479ace4f3a64bd7777d8f574320bf in session start.
Dec 05, 2018 15:03:17.302 [0x7f4af4ffe700] DEBUG - Starting a transcode session 963479ace4f3a64bd7777d8f574320bf at offset -1.0 (state=3)
Dec 05, 2018 15:03:17.304 [0x7f4af4ffe700] DEBUG - [Universal] Using local file path instead of URL: /media/plex/Movies - BluRay/Harry Potter and the Chamber of Secrets (2002)/Harry Potter and the Chamber of Secrets (2002).mkv
Dec 05, 2018 15:03:17.304 [0x7f4af4ffe700] DEBUG - TPU: hardware transcoding: zero-copy support not present
Dec 05, 2018 15:03:17.306 [0x7f4af4ffe700] DEBUG - Job running: EAE_ROOT='/tmp/pms-083ce9a5-2029-4310-a4ea-79a792be8d12/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/531e313-1328-linux-ubuntu-x86_64/' XDG_CACHE_HOME='/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache' XDG_DATA_HOME='/usr/lib/plexmediaserver/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:0' 'vc1' '-ss' '2695' '-probesize' '10000000' '-i' '/media/plex/Movies - BluRay/Harry Potter and the Chamber of Secrets (2002)/Harry Potter and the Chamber of Secrets (2002).mkv' '-filter_complex' '[0:0]scale=w=1920:h=1080[0];[0]format=pix_fmts=yuv420p|nv12[1]' '-map' '[1]' '-metadata:s:0' 'language=eng' '-codec:0' 'libx264' '-crf:0' '16' '-maxrate:0' '25384k' '-bufsize:0' '50768k' '-r:0' '23.975999999999999' '-preset:0' 'veryfast' '-level:0' '4.1' '-x264opts:0' 'subme=0:me_range=4:rc_lookahead=10:me=dia:no_chroma_me:8x8dct=0:partitions=none' '-force_key_frames:0' 'expr:gte(t,2695+n_forced*1)' '-map' '0:1' '-metadata:s:1' 'language=eng' '-codec:1' 'copy' '-copypriorss:1' '0' '-segment_format' 'mpegts' '-f' 'ssegment' '-individual_header_trailer' '0' '-segment_time' '1' '-segment_start_number' '2695' '-segment_copyts' '1' '-segment_time_delta' '0.0625' '-segment_list' 'http://127.0.0.1:32400/video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/seglist' '-segment_list_type' 'csv' '-segment_list_size' '2147483647' '-segment_list_separate_stream_times' '1' '-max_delay' '5000000' '-avoid_negative_ts' 'disabled' '-map_metadata' '-1' '-map_chapters' '-1' 'media-%05d.ts' '-start_at_zero' '-copyts' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress'
Dec 05, 2018 15:03:17.532 [0x7f4af4ffe700] DEBUG - Jobs: Starting child process with pid 2193
Dec 05, 2018 15:03:17.703 [0x7f4ae77fe700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?status=startup (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.705 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 204 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?status=startup (12 live) 2ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Dec 05, 2018 15:03:17.705 [0x7f4ae77fe700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?status=opening (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.706 [0x7f4af8fff700] DEBUG - Completed: [127.0.0.1:48110] 204 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?status=opening (12 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Dec 05, 2018 15:03:17.710 [0x7f4ad97fc700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?status=opened (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.710 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 204 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?status=opened (12 live) 0ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Dec 05, 2018 15:03:17.711 [0x7f4ad97fc700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=0&id=0&codec=vc1&type=video (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.711 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=0&id=0&codec=vc1&type=video (12 live) 0ms 256 bytes (pipelined: 4) (range: bytes=0-) 
Dec 05, 2018 15:03:17.712 [0x7f4ad97fc700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=1&id=0&codec=ac3&type=audio (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.713 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=1&id=0&codec=ac3&type=audio (12 live) 0ms 256 bytes (pipelined: 5) (range: bytes=0-) 
Dec 05, 2018 15:03:17.713 [0x7f4ae77fe700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=2&id=0&codec=truehd&type=audio (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.714 [0x7f4af8fff700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=2&id=0&codec=truehd&type=audio (12 live) 0ms 256 bytes (pipelined: 6) (range: bytes=0-) 
Dec 05, 2018 15:03:17.714 [0x7f4ae77fe700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=3&id=0&codec=ac3&type=audio (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.714 [0x7f4af8fff700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/stream?index=3&id=0&codec=ac3&type=audio (12 live) 0ms 256 bytes (pipelined: 7) (range: bytes=0-) 
Dec 05, 2018 15:03:17.809 [0x7f4ae77fe700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=0&id=0&codec=vc1&type=video&profile=Advanced&language=eng&width=1920&height=1080&interlaced=0&sar=1:1&level=3&frameRate=23.976 (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.812 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=0&id=0&codec=vc1&type=video&profile=Advanced&language=eng&width=1920&height=1080&interlaced=0&sar=1:1&level=3&frameRate=23.976 (12 live) 2ms 256 bytes (pipelined: 8) (range: bytes=0-) 
Dec 05, 2018 15:03:17.812 [0x7f4ad97fc700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=640000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&disp_default=1 (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.813 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=640000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&disp_default=1 (12 live) 1ms 256 bytes (pipelined: 9) (range: bytes=0-) 
Dec 05, 2018 15:03:17.814 [0x7f4ad97fc700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=2&id=0&codec=truehd&type=audio&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&bitDepth=24 (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.814 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=2&id=0&codec=truehd&type=audio&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&bitDepth=24 (12 live) 0ms 256 bytes (pipelined: 10) (range: bytes=0-) 
Dec 05, 2018 15:03:17.814 [0x7f4ad97fc700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=3&id=0&codec=ac3&type=audio&bitrate=640000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000 (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.815 [0x7f4af8fff700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=3&id=0&codec=ac3&type=audio&bitrate=640000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000 (12 live) 0ms 256 bytes (pipelined: 11) (range: bytes=0-) 
Dec 05, 2018 15:03:17.816 [0x7f4ad97fc700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=4&id=0&codec=hdmv_pgs_subtitle&type=subtitle&language=eng (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.816 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 206 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress/streamDetail?index=4&id=0&codec=hdmv_pgs_subtitle&type=subtitle&language=eng (12 live) 0ms 256 bytes (pipelined: 12) (range: bytes=0-) 
Dec 05, 2018 15:03:17.835 [0x7f4ae77fe700] DEBUG - Request: [127.0.0.1:48110 (Loopback)] PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?duration=9656.188000 (12 live) Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.835 [0x7f4af4ffe700] DEBUG - Started session successfully: 963479ace4f3a64bd7777d8f574320bf
Dec 05, 2018 15:03:17.837 [0x7f4af87fe700] DEBUG - Completed: [127.0.0.1:48110] 204 PUT /video/:/transcode/session/963479ace4f3a64bd7777d8f574320bf/00ad7f36-9ca4-45ba-89a1-29c8e1211d40/progress?duration=9656.188000 (12 live) 1ms 203 bytes (pipelined: 13) (range: bytes=0-) 
Dec 05, 2018 15:03:17.837 [0x7f4af4ffe700] DEBUG - Waiting for 1 segment(s) before returning M3U8
Dec 05, 2018 15:03:17.849 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:17.849 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49909 (Allowed Network)] GET /status/sessions (12 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:17.849 [0x7f4ae77fe700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:17.852 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49909] 200 GET /status/sessions (12 live) TLS GZIP 3ms 470 bytes (pipelined: 2)
Dec 05, 2018 15:03:17.855 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.8:49910 (Allowed Network)] GET /status/sessions (12 live) TLS GZIP Signed-in
Dec 05, 2018 15:03:17.855 [0x7f4ad97fc700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:17.857 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49910] 200 GET /status/sessions (12 live) TLS GZIP 2ms 397 bytes (pipelined: 2)
Dec 05, 2018 15:03:18.371 [0x7f4ae77fe700] DEBUG - Transcoder: session 963479ace4f3a64bd7777d8f574320bf indicated fallback to software decoding
Dec 05, 2018 15:03:22.272 [0x7f4ad97fc700] DEBUG - Transcoder segment range: 2695 - 2695
Dec 05, 2018 15:03:22.361 [0x7f4af4ffe700] DEBUG - Finished waiting for 1 segment(s): 1
Dec 05, 2018 15:03:22.362 [0x7f4af4ffe700] DEBUG - HLS: Building an M3U8 for 9657 total seconds with 1 seconds/segment, target duration of 1.
Dec 05, 2018 15:03:22.407 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33867] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/index.m3u8 (13 live) TLS GZIP 5105ms 25376 bytes (pipelined: 2)
Dec 05, 2018 15:03:22.805 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:22.809 [0x7f4af27ff700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02695.ts (14 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:22.812 [0x7f4af27ff700] DEBUG - Asked for segment 2695 from session.
Dec 05, 2018 15:03:22.812 [0x7f4af27ff700] DEBUG - Returning segment 2695 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02695.ts"
Dec 05, 2018 15:03:22.813 [0x7f4af27ff700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02695.ts is 2284764.
Dec 05, 2018 15:03:23.028 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02695.ts (13 live) TLS 221ms 2284764 bytes (pipelined: 1)
Dec 05, 2018 15:03:23.194 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:23.199 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02696.ts (13 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:23.202 [0x7f4ad97fc700] DEBUG - Asked for segment 2696 from session.
Dec 05, 2018 15:03:24.906 [0x7f4af4ffe700] DEBUG - Transcoder segment range: 2695 - 2696
Dec 05, 2018 15:03:24.910 [0x7f4ad97fc700] DEBUG - Returning segment 2696 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02696.ts"
Dec 05, 2018 15:03:24.911 [0x7f4ad97fc700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02696.ts is 1337056.
Dec 05, 2018 15:03:25.092 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02696.ts (14 live) TLS 1894ms 1337056 bytes (pipelined: 2)
Dec 05, 2018 15:03:25.104 [0x7f4af87fe700] DEBUG - handleStreamRead code 335544539: short read
Dec 05, 2018 15:03:25.141 [0x7f4af27ff700] DEBUG - Request: [172.31.101.8:49910 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (13 live) TLS GZIP Signed-in
Dec 05, 2018 15:03:25.143 [0x7f4af27ff700] DEBUG - Beginning read from two-way stream.
Dec 05, 2018 15:03:25.203 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:25.204 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02697.ts (13 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:25.205 [0x7f4ad97fc700] DEBUG - Asked for segment 2697 from session.
Dec 05, 2018 15:03:25.587 [0x7f4af87fe700] DEBUG - handleStreamRead code 335544539: short read
Dec 05, 2018 15:03:25.611 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:25.612 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.8:49909 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:25.613 [0x7f4af4ffe700] DEBUG - Beginning read from two-way stream.
Dec 05, 2018 15:03:27.507 [0x7f4af4ffe700] DEBUG - Transcoder segment range: 2695 - 2697
Dec 05, 2018 15:03:27.515 [0x7f4ad97fc700] DEBUG - Returning segment 2697 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02697.ts"
Dec 05, 2018 15:03:27.515 [0x7f4ad97fc700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02697.ts is 1229708.
Dec 05, 2018 15:03:27.536 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02697.ts (12 live) TLS 2332ms 1229708 bytes (pipelined: 3)
Dec 05, 2018 15:03:27.695 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:27.696 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02698.ts (12 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:27.698 [0x7f4ae77fe700] DEBUG - Asked for segment 2698 from session.
Dec 05, 2018 15:03:30.046 [0x7f4af4ffe700] DEBUG - Transcoder segment range: 2695 - 2698
Dec 05, 2018 15:03:30.110 [0x7f4ae77fe700] DEBUG - Returning segment 2698 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02698.ts"
Dec 05, 2018 15:03:30.111 [0x7f4ae77fe700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02698.ts is 1538780.
Dec 05, 2018 15:03:30.208 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02698.ts (12 live) TLS 2512ms 1538780 bytes (pipelined: 4)
Dec 05, 2018 15:03:30.334 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:30.336 [0x7f4af27ff700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02699.ts (12 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:30.338 [0x7f4af27ff700] DEBUG - Asked for segment 2699 from session.
Dec 05, 2018 15:03:32.223 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:32.225 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /:/timeline?playbackTime=0&time=2695000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=buffering&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:32.233 [0x7f4ad97fc700] DEBUG - Client [963479ace4f3a64bd7777d8f574320bf] reporting timeline state buffering, progress of 2695000/9656188ms for guid=com.plexapp.agents.imdb://tt0295297?lang=en, ratingKey=29304 url=, key=/library/metadata/29304, containerKey=, metadataId=29304, source=
Dec 05, 2018 15:03:32.249 [0x7f4ad97fc700] DEBUG - Play progress on 29304 'Harry Potter and the Chamber of Secrets' - got played 2695000 ms by account 1!
Dec 05, 2018 15:03:32.250 [0x7f4ad97fc700] DEBUG - [Now] User is jhadmin1 (ID: 1)
Dec 05, 2018 15:03:32.250 [0x7f4ad97fc700] DEBUG - [Now] Device is Roku (3810X - 4K - David Office).
Dec 05, 2018 15:03:32.250 [0x7f4ad97fc700] DEBUG - [Now] Profile is Roku-7.x
Dec 05, 2018 15:03:32.250 [0x7f4ad97fc700] DEBUG - [Now] Updated play state for /library/metadata/29304.
Dec 05, 2018 15:03:32.253 [0x7f4ad97fc700] DEBUG - Statistics: (963479ace4f3a64bd7777d8f574320bf) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Dec 05, 2018 15:03:32.258 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /:/timeline?playbackTime=0&time=2695000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=buffering&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (11 live) TLS GZIP 34ms 756 bytes (pipelined: 2)
Dec 05, 2018 15:03:32.293 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:32.294 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.8:49921 (Allowed Network)] GET /status/sessions (12 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:32.296 [0x7f4af4ffe700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:32.310 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49921] 200 GET /status/sessions (13 live) TLS GZIP 16ms 5637 bytes (pipelined: 1)
Dec 05, 2018 15:03:32.314 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49923 (Allowed Network)] GET /status/sessions (13 live) TLS GZIP Signed-in
Dec 05, 2018 15:03:32.314 [0x7f4ae77fe700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:32.319 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49923] 200 GET /status/sessions (13 live) TLS GZIP 5ms 5564 bytes (pipelined: 1)
Dec 05, 2018 15:03:32.643 [0x7f4af4ffe700] DEBUG - Transcoder segment range: 2695 - 2699
Dec 05, 2018 15:03:32.647 [0x7f4af27ff700] DEBUG - Returning segment 2699 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02699.ts"
Dec 05, 2018 15:03:32.648 [0x7f4af27ff700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02699.ts is 1519228.
Dec 05, 2018 15:03:32.787 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02699.ts (14 live) TLS 2451ms 1519228 bytes (pipelined: 5)
Dec 05, 2018 15:03:32.897 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:32.898 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02700.ts (14 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:32.898 [0x7f4ae77fe700] DEBUG - Asked for segment 2700 from session.
Dec 05, 2018 15:03:35.209 [0x7f4ad97fc700] DEBUG - Transcoder segment range: 2695 - 2700
Dec 05, 2018 15:03:35.310 [0x7f4ae77fe700] DEBUG - Returning segment 2700 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02700.ts"
Dec 05, 2018 15:03:35.313 [0x7f4ae77fe700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02700.ts is 1243996.
Dec 05, 2018 15:03:35.358 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02700.ts (14 live) TLS 2459ms 1243996 bytes (pipelined: 6)
Dec 05, 2018 15:03:35.542 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:35.543 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02701.ts (13 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:35.544 [0x7f4ad97fc700] DEBUG - Asked for segment 2701 from session.
Dec 05, 2018 15:03:35.909 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:35.910 [0x7f4af27ff700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /:/timeline?playbackTime=0&time=2695000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=playing&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (13 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:35.917 [0x7f4af27ff700] DEBUG - Client [963479ace4f3a64bd7777d8f574320bf] reporting timeline state playing, progress of 2695000/9656188ms for guid=com.plexapp.agents.imdb://tt0295297?lang=en, ratingKey=29304 url=, key=/library/metadata/29304, containerKey=, metadataId=29304, source=
Dec 05, 2018 15:03:35.920 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:35.920 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33865 (Allowed Network)] GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (13 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:35.925 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33865] 200 GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (13 live) TLS GZIP 4ms 681 bytes (pipelined: 2)
Dec 05, 2018 15:03:35.929 [0x7f4af27ff700] DEBUG - Play progress on 29304 'Harry Potter and the Chamber of Secrets' - got played 2695000 ms by account 1!
Dec 05, 2018 15:03:35.944 [0x7f4af27ff700] DEBUG - It took 0.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:36.055 [0x7f4af27ff700] DEBUG - [Now] User is jhadmin1 (ID: 1)
Dec 05, 2018 15:03:36.056 [0x7f4af27ff700] DEBUG - [Now] Device is Roku (3810X - 4K - David Office).
Dec 05, 2018 15:03:36.057 [0x7f4af27ff700] DEBUG - [Now] Profile is Roku-7.x
Dec 05, 2018 15:03:36.057 [0x7f4af27ff700] DEBUG - [Now] Updated play state for /library/metadata/29304.
Dec 05, 2018 15:03:36.063 [0x7f4af27ff700] DEBUG - Statistics: (963479ace4f3a64bd7777d8f574320bf) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Dec 05, 2018 15:03:36.069 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /:/timeline?playbackTime=0&time=2695000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=playing&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (13 live) TLS GZIP 160ms 764 bytes (pipelined: 3)
Dec 05, 2018 15:03:37.753 [0x7f4af4ffe700] DEBUG - Transcoder segment range: 2695 - 2701
Dec 05, 2018 15:03:37.757 [0x7f4ad97fc700] DEBUG - Returning segment 2701 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02701.ts"
Dec 05, 2018 15:03:37.759 [0x7f4ad97fc700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02701.ts is 1295884.
Dec 05, 2018 15:03:37.802 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02701.ts (14 live) TLS 2260ms 1295884 bytes (pipelined: 7)
Dec 05, 2018 15:03:37.997 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:38.000 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02702.ts (14 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:38.004 [0x7f4ae77fe700] DEBUG - Asked for segment 2702 from session.
Dec 05, 2018 15:03:38.118 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:38.120 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.8:49921 (Allowed Network)] GET /status/sessions (14 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:38.122 [0x7f4ad97fc700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:38.133 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49921] 200 GET /status/sessions (14 live) TLS GZIP 14ms 5641 bytes (pipelined: 2)
Dec 05, 2018 15:03:40.203 [0x7f4af27ff700] DEBUG - Transcoder segment range: 2695 - 2702
Dec 05, 2018 15:03:40.215 [0x7f4ae77fe700] DEBUG - Returning segment 2702 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02702.ts"
Dec 05, 2018 15:03:40.216 [0x7f4ae77fe700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02702.ts is 1256968.
Dec 05, 2018 15:03:40.346 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02702.ts (14 live) TLS 2346ms 1256968 bytes (pipelined: 8)
Dec 05, 2018 15:03:40.439 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:40.441 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02703.ts (14 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:40.444 [0x7f4ad97fc700] DEBUG - Asked for segment 2703 from session.
Dec 05, 2018 15:03:42.740 [0x7f4af27ff700] DEBUG - Transcoder segment range: 2695 - 2703
Dec 05, 2018 15:03:42.761 [0x7f4ad97fc700] DEBUG - Returning segment 2703 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02703.ts"
Dec 05, 2018 15:03:42.762 [0x7f4ad97fc700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02703.ts is 1343260.
Dec 05, 2018 15:03:42.845 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02703.ts (14 live) TLS 2404ms 1343260 bytes (pipelined: 9)
Dec 05, 2018 15:03:42.963 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:42.967 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02704.ts (14 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:42.969 [0x7f4af4ffe700] DEBUG - Asked for segment 2704 from session.
Dec 05, 2018 15:03:44.873 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:44.875 [0x7f4af27ff700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /:/timeline?playbackTime=8945&time=2703000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=buffering&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (13 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:44.878 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:44.879 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33865 (Allowed Network)] GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (13 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:44.885 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33865] 200 GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (13 live) TLS GZIP 6ms 679 bytes (pipelined: 3)
Dec 05, 2018 15:03:44.887 [0x7f4af27ff700] DEBUG - Client [963479ace4f3a64bd7777d8f574320bf] reporting timeline state buffering, progress of 2703000/9656188ms for guid=com.plexapp.agents.imdb://tt0295297?lang=en, ratingKey=29304 url=, key=/library/metadata/29304, containerKey=, metadataId=29304, source=
Dec 05, 2018 15:03:44.899 [0x7f4af27ff700] DEBUG - Play progress on 29304 'Harry Potter and the Chamber of Secrets' - got played 2703000 ms by account 1!
Dec 05, 2018 15:03:44.900 [0x7f4af27ff700] DEBUG - [Now] User is jhadmin1 (ID: 1)
Dec 05, 2018 15:03:44.900 [0x7f4af27ff700] DEBUG - [Now] Device is Roku (3810X - 4K - David Office).
Dec 05, 2018 15:03:44.900 [0x7f4af27ff700] DEBUG - [Now] Profile is Roku-7.x
Dec 05, 2018 15:03:44.900 [0x7f4af27ff700] DEBUG - [Now] Updated play state for /library/metadata/29304.
Dec 05, 2018 15:03:44.903 [0x7f4af27ff700] DEBUG - Statistics: (963479ace4f3a64bd7777d8f574320bf) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Dec 05, 2018 15:03:44.906 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /:/timeline?playbackTime=8945&time=2703000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=buffering&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (13 live) TLS GZIP 32ms 760 bytes (pipelined: 4)
Dec 05, 2018 15:03:45.146 [0x7f4af87fe700] DEBUG - handleStreamRead code 335544539: short read
Dec 05, 2018 15:03:45.147 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:45.148 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49921 (Allowed Network)] GET /status/sessions (12 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:45.150 [0x7f4ae77fe700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:45.165 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49921] 200 GET /status/sessions (12 live) TLS GZIP 17ms 5644 bytes (pipelined: 3)
Dec 05, 2018 15:03:45.180 [0x7f4af27ff700] DEBUG - Request: [172.31.101.8:49923 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (12 live) TLS GZIP Signed-in
Dec 05, 2018 15:03:45.181 [0x7f4af27ff700] DEBUG - Beginning read from two-way stream.
Dec 05, 2018 15:03:45.313 [0x7f4ad97fc700] DEBUG - Transcoder segment range: 2695 - 2704
Dec 05, 2018 15:03:45.381 [0x7f4af4ffe700] DEBUG - Returning segment 2704 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02704.ts"
Dec 05, 2018 15:03:45.383 [0x7f4af4ffe700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02704.ts is 1463016.
Dec 05, 2018 15:03:45.480 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02704.ts (12 live) TLS 2513ms 1463016 bytes (pipelined: 10)
Dec 05, 2018 15:03:45.614 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:45.614 [0x7f4af27ff700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02705.ts (12 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:45.616 [0x7f4af27ff700] DEBUG - Asked for segment 2705 from session.
Dec 05, 2018 15:03:45.616 [0x7f4af87fe700] DEBUG - handleStreamRead code 335544539: short read
Dec 05, 2018 15:03:45.641 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:45.642 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49921 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:45.644 [0x7f4ae77fe700] DEBUG - Beginning read from two-way stream.
Dec 05, 2018 15:03:46.332 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:46.336 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /video/:/transcode/universal/ping?session=963479ace4f3a64bd7777d8f574320bf (10 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:46.338 [0x7f4ad97fc700] DEBUG - Found session GUID of 963479ace4f3a64bd7777d8f574320bf in session start.
Dec 05, 2018 15:03:46.338 [0x7f4ad97fc700] DEBUG - [Now] Freshening session based on ping for 963479ace4f3a64bd7777d8f574320bf_Video
Dec 05, 2018 15:03:46.338 [0x7f4ad97fc700] DEBUG - Received transcode session ping for session 963479ace4f3a64bd7777d8f574320bf.
Dec 05, 2018 15:03:46.340 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /video/:/transcode/universal/ping?session=963479ace4f3a64bd7777d8f574320bf (10 live) TLS GZIP 5ms 195 bytes (pipelined: 5)
Dec 05, 2018 15:03:46.342 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:46.342 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33865 (Allowed Network)] GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (10 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:46.347 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33865] 200 GET /transcode/sessions/963479ace4f3a64bd7777d8f574320bf (10 live) TLS GZIP 4ms 681 bytes (pipelined: 4)
Dec 05, 2018 15:03:47.910 [0x7f4ad97fc700] DEBUG - Transcoder segment range: 2695 - 2705
Dec 05, 2018 15:03:47.923 [0x7f4af27ff700] DEBUG - Returning segment 2705 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02705.ts"
Dec 05, 2018 15:03:47.924 [0x7f4af27ff700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02705.ts is 1530508.
Dec 05, 2018 15:03:48.035 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02705.ts (11 live) TLS 2420ms 1530508 bytes (pipelined: 11)
Dec 05, 2018 15:03:48.184 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:48.185 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02706.ts (11 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:48.187 [0x7f4af4ffe700] DEBUG - Asked for segment 2706 from session.
Dec 05, 2018 15:03:50.482 [0x7f4af27ff700] DEBUG - Transcoder segment range: 2695 - 2706
Dec 05, 2018 15:03:50.499 [0x7f4af4ffe700] DEBUG - Returning segment 2706 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02706.ts"
Dec 05, 2018 15:03:50.500 [0x7f4af4ffe700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02706.ts is 1686924.
Dec 05, 2018 15:03:50.642 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02706.ts (11 live) TLS 2457ms 1686924 bytes (pipelined: 12)
Dec 05, 2018 15:03:50.788 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:50.790 [0x7f4af27ff700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02707.ts (10 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:50.791 [0x7f4af27ff700] DEBUG - Asked for segment 2707 from session.
Dec 05, 2018 15:03:52.140 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:52.141 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.8:49931 (Allowed Network)] GET /status/sessions (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:52.143 [0x7f4ad97fc700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:52.154 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49931] 200 GET /status/sessions (11 live) TLS GZIP 13ms 5645 bytes (pipelined: 1)
Dec 05, 2018 15:03:53.149 [0x7f4ae77fe700] DEBUG - Transcoder segment range: 2695 - 2707
Dec 05, 2018 15:03:53.203 [0x7f4af27ff700] DEBUG - Returning segment 2707 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02707.ts"
Dec 05, 2018 15:03:53.205 [0x7f4af27ff700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02707.ts is 1891280.
Dec 05, 2018 15:03:53.344 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02707.ts (12 live) TLS 2555ms 1891280 bytes (pipelined: 13)
Dec 05, 2018 15:03:53.489 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:53.490 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02708.ts (12 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:53.491 [0x7f4af4ffe700] DEBUG - Asked for segment 2708 from session.
Dec 05, 2018 15:03:55.599 [0x7f4af27ff700] DEBUG - Transcoder segment range: 2695 - 2708
Dec 05, 2018 15:03:55.601 [0x7f4af4ffe700] DEBUG - Returning segment 2708 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02708.ts"
Dec 05, 2018 15:03:55.601 [0x7f4af4ffe700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02708.ts is 1834880.
Dec 05, 2018 15:03:55.757 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02708.ts (12 live) TLS 2267ms 1834880 bytes (pipelined: 14)
Dec 05, 2018 15:03:55.911 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:55.915 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02709.ts (12 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:55.916 [0x7f4ae77fe700] DEBUG - Asked for segment 2709 from session.
Dec 05, 2018 15:03:58.190 [0x7f4ad97fc700] DEBUG - Transcoder segment range: 2695 - 2709
Dec 05, 2018 15:03:58.224 [0x7f4ae77fe700] DEBUG - Returning segment 2709 from session: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02709.ts"
Dec 05, 2018 15:03:58.225 [0x7f4ae77fe700] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40/media-02709.ts is 1569612.
Dec 05, 2018 15:03:58.363 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 200 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02709.ts (12 live) TLS 2449ms 1569612 bytes (pipelined: 15)
Dec 05, 2018 15:03:58.494 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:58.497 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.224:33869 (Allowed Network)] GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02710.ts (12 live) TLS Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:58.500 [0x7f4af4ffe700] DEBUG - Asked for segment 2710 from session.
Dec 05, 2018 15:03:59.133 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.136 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49931 (Allowed Network)] GET /status/sessions (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.138 [0x7f4ae77fe700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:59.156 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49931] 200 GET /status/sessions (11 live) TLS GZIP 21ms 5651 bytes (pipelined: 2)
Dec 05, 2018 15:03:59.531 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.533 [0x7f4af27ff700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /video/:/transcode/universal/stop?session=963479ace4f3a64bd7777d8f574320bf (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.536 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.536 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33865 (Allowed Network)] GET /:/timeline?playbackTime=8945&time=2703000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=stopped&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.545 [0x7f4ad97fc700] DEBUG - Client [963479ace4f3a64bd7777d8f574320bf] reporting timeline state stopped, progress of 2703000/9656188ms for guid=com.plexapp.agents.imdb://tt0295297?lang=en, ratingKey=29304 url=, key=/library/metadata/29304, containerKey=, metadataId=29304, source=
Dec 05, 2018 15:03:59.571 [0x7f4ad97fc700] DEBUG - Play progress on 29304 'Harry Potter and the Chamber of Secrets' - got played 2703000 ms by account 1!
Dec 05, 2018 15:03:59.577 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /video/:/transcode/universal/stop?session=963479ace4f3a64bd7777d8f574320bf (11 live) TLS GZIP 45ms 195 bytes (pipelined: 6)
Dec 05, 2018 15:03:59.578 [0x7f4adbfff700] DEBUG - Found session GUID of 963479ace4f3a64bd7777d8f574320bf in session start.
Dec 05, 2018 15:03:59.579 [0x7f4adbfff700] DEBUG - Killing job.
Dec 05, 2018 15:03:59.579 [0x7f4adbfff700] DEBUG - Signalling job ID 2193 with 9
Dec 05, 2018 15:03:59.579 [0x7f4adbfff700] DEBUG - Job was already killed, not killing again.
Dec 05, 2018 15:03:59.580 [0x7f4adbfff700] DEBUG - Stopping transcode session 963479ace4f3a64bd7777d8f574320bf
Dec 05, 2018 15:03:59.587 [0x7f4adbfff700] DEBUG - Transcoder: Cleaning old transcode directories.
Dec 05, 2018 15:03:59.589 [0x7f4adbfff700] DEBUG - Transcoder: Cleaning old transcode directory: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40"
Dec 05, 2018 15:03:59.590 [0x7f4ad97fc700] DEBUG - It took 10.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:59.598 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.598 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49931 (Allowed Network)] GET /status/sessions (11 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.599 [0x7f4ae77fe700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:59.606 [0x7f4adcffe700] DEBUG - Cleaning directory for session 963479ace4f3a64bd7777d8f574320bf (/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40)
Dec 05, 2018 15:03:59.609 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49931] 200 GET /status/sessions (11 live) TLS GZIP 11ms 5628 bytes (pipelined: 3)
Dec 05, 2018 15:03:59.612 [0x7f4adbfff700] ERROR - Transcoder: Failed to delete session directory (boost::filesystem::remove: No such file or directory: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40")
Dec 05, 2018 15:03:59.613 [0x7f4adbfff700] DEBUG - Whacked session 963479ace4f3a64bd7777d8f574320bf, 0 remaining.
Dec 05, 2018 15:03:59.632 [0x7f4aee7ff700] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 2193 is -9 (signal: Killed)
Dec 05, 2018 15:03:59.633 [0x7f4af4ffe700] WARN - Transcode runner appears to have died.
Dec 05, 2018 15:03:59.633 [0x7f4af4ffe700] DEBUG - Session was stopped.
Dec 05, 2018 15:03:59.634 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33869] 404 GET /video/:/transcode/universal/session/963479ace4f3a64bd7777d8f574320bf/base/02710.ts (11 live) TLS 1137ms 288 bytes (pipelined: 16)
Dec 05, 2018 15:03:59.651 [0x7f4af27ff700] DEBUG - Request: [172.31.101.8:49942 (Allowed Network)] GET /status/sessions (11 live) TLS GZIP Signed-in
Dec 05, 2018 15:03:59.652 [0x7f4af27ff700] DEBUG - [Now] Adding 1 sessions.
Dec 05, 2018 15:03:59.657 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49942] 200 GET /status/sessions (11 live) TLS GZIP 6ms 5555 bytes (pipelined: 1)
Dec 05, 2018 15:03:59.658 [0x7f4ad97fc700] DEBUG - [Now] User is jhadmin1 (ID: 1)
Dec 05, 2018 15:03:59.658 [0x7f4ad97fc700] DEBUG - [Now] Device is Roku (3810X - 4K - David Office).
Dec 05, 2018 15:03:59.658 [0x7f4ad97fc700] DEBUG - [Now] Profile is Roku-7.x
Dec 05, 2018 15:03:59.658 [0x7f4ad97fc700] DEBUG - [Now] Updated play state for /library/metadata/29304.
Dec 05, 2018 15:03:59.659 [0x7f4ad97fc700] DEBUG - Statistics: (963479ace4f3a64bd7777d8f574320bf) Reporting active playback in state 3 of type 1 (scrobble: 0) for account 1
Dec 05, 2018 15:03:59.660 [0x7f4ad97fc700] DEBUG - Streaming Resource: Terminating session 0x7f4af28386e0:963479ace4f3a64bd7777d8f574320bf which is using transcoder slot.  Used slots is now 0
Dec 05, 2018 15:03:59.660 [0x7f4ad97fc700] DEBUG - Streaming Resource: Terminated session 0x7f4af28386e0:963479ace4f3a64bd7777d8f574320bf with reason Client stopped playback.
Dec 05, 2018 15:03:59.660 [0x7f4ad97fc700] DEBUG - Streaming Resource: Removing session 0x7f4af28386e0:963479ace4f3a64bd7777d8f574320bf
Dec 05, 2018 15:03:59.660 [0x7f4af0fff700] DEBUG - Job was already killed, not killing again.
Dec 05, 2018 15:03:59.660 [0x7f4af0fff700] DEBUG - Job was already killed, not killing again.
Dec 05, 2018 15:03:59.660 [0x7f4af0fff700] DEBUG - Transcoder: Cleaning old transcode directories.
Dec 05, 2018 15:03:59.662 [0x7f4af0fff700] DEBUG - Whacked session 963479ace4f3a64bd7777d8f574320bf, 0 remaining.
Dec 05, 2018 15:03:59.663 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.224:33865] 200 GET /:/timeline?playbackTime=8945&time=2703000&key=%2Flibrary%2Fmetadata%2F29304&ratingKey=29304&state=stopped&guid=com.plexapp.agents.imdb%3A%2F%2Ftt0295297%3Flang%3Den&duration=9656188&playQueueItemID=32016 (11 live) TLS GZIP 126ms 497 bytes (pipelined: 5)
Dec 05, 2018 15:03:59.676 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49942 (Allowed Network)] GET /hubs/home/continueWatching (10 live) TLS Page 0-15 GZIP Signed-in
Dec 05, 2018 15:03:59.690 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.691 [0x7f4af27ff700] DEBUG - Request: [172.31.101.8:49931 (Allowed Network)] GET /hubs/home/continueWatching (11 live) TLS Page 0-15 GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.707 [0x7f4ae77fe700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.711 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49942] 200 GET /hubs/home/continueWatching (13 live) TLS GZIP Page 0-15 34ms 1769 bytes (pipelined: 2)
Dec 05, 2018 15:03:59.718 [0x7f4af27ff700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.720 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.8:49946 (Allowed Network)] GET /hubs/home/onDeck (12 live) TLS Page 0-15 GZIP Signed-in
Dec 05, 2018 15:03:59.721 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49931] 200 GET /hubs/home/continueWatching (12 live) TLS GZIP Page 0-15 30ms 1842 bytes (pipelined: 4)
Dec 05, 2018 15:03:59.746 [0x7f4af4ffe700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.747 [0x7f4af4ffe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.747 [0x7f4af4ffe700] DEBUG - Selecting best audio stream for part ID 2321 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.747 [0x7f4af4ffe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.747 [0x7f4af4ffe700] DEBUG - Audio Stream: 1720, Subtitle Stream: -1
Dec 05, 2018 15:03:59.748 [0x7f4af4ffe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.748 [0x7f4af4ffe700] DEBUG - Selecting best audio stream for part ID 67365 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.748 [0x7f4af4ffe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.748 [0x7f4af4ffe700] DEBUG - Audio Stream: 101635, Subtitle Stream: -1
Dec 05, 2018 15:03:59.751 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49946] 200 GET /hubs/home/onDeck (16 live) TLS GZIP Page 0-15 30ms 2113 bytes (pipelined: 1)
Dec 05, 2018 15:03:59.763 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49942 (Allowed Network)] GET /hubs/home/recentlyAdded?type=13 (14 live) TLS Page 0-15 GZIP Signed-in
Dec 05, 2018 15:03:59.765 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.766 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.8:49949 (Allowed Network)] GET /hubs/home/onDeck (14 live) TLS Page 0-15 GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.766 [0x7f4ae77fe700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.769 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49942] 200 GET /hubs/home/recentlyAdded?type=13 (17 live) TLS GZIP Page 0-15 6ms 480 bytes (pipelined: 3)
Dec 05, 2018 15:03:59.771 [0x7f4af27ff700] DEBUG - Request: [172.31.101.8:49950 (Allowed Network)] GET /hubs/home/recentlyAdded?type=8 (17 live) TLS Page 0-15 GZIP Signed-in
Dec 05, 2018 15:03:59.773 [0x7f4af27ff700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.774 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49950] 200 GET /hubs/home/recentlyAdded?type=8 (17 live) TLS GZIP Page 0-15 2ms 480 bytes (pipelined: 1)
Dec 05, 2018 15:03:59.777 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.777 [0x7f4af4ffe700] DEBUG - Request: [172.31.101.8:49931 (Allowed Network)] GET /hubs/home/recentlyAdded?type=1 (18 live) TLS Page 0-50 GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.778 [0x7f4af4ffe700] DEBUG - Setting container serialization range to [0, 50] (total=-1)
Dec 05, 2018 15:03:59.780 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.785 [0x7f4ae77fe700] DEBUG - Request: [172.31.101.8:49946 (Allowed Network)] GET /hubs/home/recentlyAdded?type=2 (18 live) TLS Page 0-15 GZIP Signed-in
Dec 05, 2018 15:03:59.785 [0x7f4af27ff700] DEBUG - Request: [172.31.101.8:49951 (Allowed Network)] GET /hubs/home/recentlyAdded?type=2 (17 live) TLS Page 0-25 GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.792 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.806 [0x7f4adbfff700] DEBUG - Request: [172.31.101.8:49942 (Allowed Network)] GET /hubs/home/recentlyAdded?type=1 (18 live) TLS Page 0-15 GZIP Signed-in
Dec 05, 2018 15:03:59.806 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.808 [0x7f4adbfff700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.809 [0x7f4ad87fa700] DEBUG - Request: [172.31.101.8:49953 (Allowed Network)] GET /hubs/home/recentlyAdded?type=1&personal=1 (18 live) TLS Page 0-15 GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.818 [0x7f4adafff700] DEBUG - Request: [172.31.101.8:49950 (Allowed Network)] GET /hubs/home/recentlyAdded?type=1&personal=1 (18 live) TLS Page 0-15 GZIP Signed-in
Dec 05, 2018 15:03:59.819 [0x7f4ad9ffd700] DEBUG - Request: [172.31.101.8:49954 (Allowed Network)] GET /hubs/home/recentlyAdded?type=13 (18 live) TLS Page 0-15 GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.824 [0x7f4adafff700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.826 [0x7f4ad9ffd700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.829 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49954] 200 GET /hubs/home/recentlyAdded?type=13 (18 live) TLS GZIP Page 0-15 23ms 553 bytes (pipelined: 1)
Dec 05, 2018 15:03:59.831 [0x7f4af27ff700] DEBUG - It took 180.000000 ms to retrieve 8 items.
Dec 05, 2018 15:03:59.838 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49950] 200 GET /hubs/home/recentlyAdded?type=1&personal=1 (18 live) TLS GZIP Page 0-15 32ms 480 bytes (pipelined: 2)
Dec 05, 2018 15:03:59.839 [0x7f4ae77fe700] DEBUG - It took 200.000000 ms to retrieve 200 items.
Dec 05, 2018 15:03:59.847 [0x7f4ad87fa700] DEBUG - It took 140.000000 ms to retrieve 8 items.
Dec 05, 2018 15:03:59.847 [0x7f4ad87fa700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.849 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.850 [0x7f4ad9ffd700] DEBUG - Request: [172.31.101.8:49954 (Allowed Network)] GET /hubs/home/recentlyAdded?type=8 (18 live) TLS Page 0-15 GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.851 [0x7f4ad97fc700] DEBUG - It took 60.000000 ms to retrieve 1 items.
Dec 05, 2018 15:03:59.852 [0x7f4ad9ffd700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.854 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49954] 200 GET /hubs/home/recentlyAdded?type=8 (18 live) TLS GZIP Page 0-15 4ms 553 bytes (pipelined: 2)
Dec 05, 2018 15:03:59.854 [0x7f4ad97fc700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:03:59.859 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49953] 200 GET /hubs/home/recentlyAdded?type=1&personal=1 (18 live) TLS GZIP Page 0-15 64ms 553 bytes (pipelined: 1)
Dec 05, 2018 15:03:59.861 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.862 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 2321 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.862 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.862 [0x7f4ad97fc700] DEBUG - Audio Stream: 1720, Subtitle Stream: -1
Dec 05, 2018 15:03:59.864 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.864 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 67365 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.865 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.865 [0x7f4ad97fc700] DEBUG - Audio Stream: 101635, Subtitle Stream: -1
Dec 05, 2018 15:03:59.867 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.867 [0x7f4adafff700] DEBUG - Request: [172.31.101.8:49954 (Allowed Network)] GET /library/metadata/29304?includeConcerts=1&includeExtras=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=1&includeChapters=1&includeStations=1&asyncAugmentMetadata=1&asyncCheckFiles=1&asyncRefreshAnalysis=1&asyncRefreshLocalMediaAgent=1&skipRefresh=1 (18 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.868 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49949] 200 GET /hubs/home/onDeck (18 live) TLS GZIP Page 0-15 101ms 2186 bytes (pipelined: 1)
Dec 05, 2018 15:03:59.877 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.878 [0x7f4af27ff700] DEBUG - It took 170.000000 ms to retrieve 200 items.
Dec 05, 2018 15:03:59.879 [0x7f4ad8ffb700] DEBUG - Request: [172.31.101.8:49953 (Allowed Network)] GET /hubs/metadata/29304/related?excludeFields=summary&count=12&includeExternalMetadata=1&asyncAugmentMetadata=1 (18 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.887 [0x7f4adafff700] DEBUG - It took 50.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:59.891 [0x7f4adafff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.891 [0x7f4adafff700] DEBUG - Selecting best audio stream for part ID 61681 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.891 [0x7f4adafff700] DEBUG - Audio Stream: 94018, Subtitle Stream: 0
Dec 05, 2018 15:03:59.897 [0x7f4af87fe700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:03:59.898 [0x7f4ad9ffd700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /library/metadata/29304?includeExtras=1 (18 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:03:59.899 [0x7f4ad8ffb700] DEBUG - It took 40.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:59.900 [0x7f4ae77fe700] DEBUG - It took 230.000000 ms to retrieve 413 items.
Dec 05, 2018 15:03:59.917 [0x7f4ad9ffd700] DEBUG - It took 50.000000 ms to retrieve 143 items.
Dec 05, 2018 15:03:59.921 [0x7f4af27ff700] DEBUG - It took 150.000000 ms to retrieve 413 items.
Dec 05, 2018 15:03:59.923 [0x7f4adafff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.924 [0x7f4adafff700] DEBUG - Selecting best audio stream for part ID 41345 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.924 [0x7f4adafff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.924 [0x7f4adafff700] DEBUG - Audio Stream: 49373, Subtitle Stream: -1
Dec 05, 2018 15:03:59.924 [0x7f4ae77fe700] DEBUG - It took 90.000000 ms to retrieve 293 items.
Dec 05, 2018 15:03:59.925 [0x7f4adafff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.928 [0x7f4adafff700] DEBUG - Selecting best audio stream for part ID 41346 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.928 [0x7f4adafff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.928 [0x7f4adafff700] DEBUG - Audio Stream: 49375, Subtitle Stream: -1
Dec 05, 2018 15:03:59.929 [0x7f4adafff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.929 [0x7f4adafff700] DEBUG - Selecting best audio stream for part ID 41347 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.929 [0x7f4adafff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.929 [0x7f4adafff700] DEBUG - Audio Stream: 49377, Subtitle Stream: -1
Dec 05, 2018 15:03:59.930 [0x7f4adafff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.930 [0x7f4adafff700] DEBUG - Selecting best audio stream for part ID 41348 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.930 [0x7f4adafff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.930 [0x7f4adafff700] DEBUG - Audio Stream: 49379, Subtitle Stream: -1
Dec 05, 2018 15:03:59.931 [0x7f4adafff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.931 [0x7f4adafff700] DEBUG - Selecting best audio stream for part ID 41349 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.931 [0x7f4adafff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.931 [0x7f4adafff700] DEBUG - Audio Stream: 49381, Subtitle Stream: -1
Dec 05, 2018 15:03:59.931 [0x7f4adafff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.932 [0x7f4adafff700] DEBUG - Selecting best audio stream for part ID 41350 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.932 [0x7f4adafff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.932 [0x7f4adafff700] DEBUG - Audio Stream: 49383, Subtitle Stream: -1
Dec 05, 2018 15:03:59.936 [0x7f4adafff700] DEBUG - Activity: registered new activity 9777aba5-6ba0-4dc4-8530-7f790b3a21de - Refreshing
Dec 05, 2018 15:03:59.939 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.940 [0x7f4adcffe700] DEBUG - Activity: updated activity 9777aba5-6ba0-4dc4-8530-7f790b3a21de - completed 0% - Refreshing
Dec 05, 2018 15:03:59.943 [0x7f4ad9ffd700] DEBUG - Selecting best audio stream for part ID 61681 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.944 [0x7f4ad9ffd700] DEBUG - Audio Stream: 94018, Subtitle Stream: 0
Dec 05, 2018 15:03:59.942 [0x7f4af27ff700] DEBUG - It took 80.000000 ms to retrieve 293 items.
Dec 05, 2018 15:03:59.945 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49954] 200 GET /library/metadata/29304?includeConcerts=1&includeExtras=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=1&includeChapters=1&includeStations=1&asyncAugmentMetadata=1&asyncCheckFiles=1&asyncRefreshAnalysis=1&asyncRefreshLocalMediaAgent=1&skipRefresh=1 (18 live) TLS GZIP 77ms 7249 bytes (pipelined: 3)
Dec 05, 2018 15:03:59.949 [0x7f4adcffe700] DEBUG - Activity: updated activity 9777aba5-6ba0-4dc4-8530-7f790b3a21de - completed 25% - Refreshing
Dec 05, 2018 15:03:59.954 [0x7f4adcffe700] DEBUG - Activity: updated activity 9777aba5-6ba0-4dc4-8530-7f790b3a21de - completed 50% - Refreshing
Dec 05, 2018 15:03:59.954 [0x7f4adcffe700] DEBUG - Activity: updated activity 9777aba5-6ba0-4dc4-8530-7f790b3a21de - completed 50% - Refreshing
Dec 05, 2018 15:03:59.956 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.956 [0x7f4ad9ffd700] DEBUG - Selecting best audio stream for part ID 41345 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.957 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.957 [0x7f4ad9ffd700] DEBUG - Audio Stream: 49373, Subtitle Stream: -1
Dec 05, 2018 15:03:59.957 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.957 [0x7f4ad9ffd700] DEBUG - Selecting best audio stream for part ID 41346 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.957 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.958 [0x7f4ad9ffd700] DEBUG - Audio Stream: 49375, Subtitle Stream: -1
Dec 05, 2018 15:03:59.958 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.958 [0x7f4ad9ffd700] DEBUG - Selecting best audio stream for part ID 41347 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.958 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.958 [0x7f4ad9ffd700] DEBUG - Audio Stream: 49377, Subtitle Stream: -1
Dec 05, 2018 15:03:59.959 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.959 [0x7f4ad9ffd700] DEBUG - Selecting best audio stream for part ID 41348 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.959 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.959 [0x7f4ad9ffd700] DEBUG - Audio Stream: 49379, Subtitle Stream: -1
Dec 05, 2018 15:03:59.960 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.960 [0x7f4ad9ffd700] DEBUG - Selecting best audio stream for part ID 41349 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.960 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.961 [0x7f4ad9ffd700] DEBUG - Audio Stream: 49381, Subtitle Stream: -1
Dec 05, 2018 15:03:59.961 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:03:59.961 [0x7f4ad9ffd700] DEBUG - Selecting best audio stream for part ID 41350 (autoselect: 1 language: en)
Dec 05, 2018 15:03:59.961 [0x7f4adcffe700] DEBUG - Activity: Ended activity 9777aba5-6ba0-4dc4-8530-7f790b3a21de.
Dec 05, 2018 15:03:59.961 [0x7f4ad9ffd700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:03:59.962 [0x7f4ad9ffd700] DEBUG - Audio Stream: 49383, Subtitle Stream: -1
Dec 05, 2018 15:03:59.966 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /library/metadata/29304?includeExtras=1 (18 live) TLS GZIP 68ms 5927 bytes (pipelined: 7)
Dec 05, 2018 15:03:59.969 [0x7f4ae77fe700] DEBUG - It took 160.000000 ms to retrieve 26 items.
Dec 05, 2018 15:03:59.976 [0x7f4af27ff700] DEBUG - It took 90.000000 ms to retrieve 26 items.
Dec 05, 2018 15:03:59.983 [0x7f4ae77fe700] DEBUG - It took 20.000000 ms to retrieve 102 items.
Dec 05, 2018 15:03:59.985 [0x7f4af27ff700] DEBUG - It took 30.000000 ms to retrieve 102 items.
Dec 05, 2018 15:04:00.000 [0x7f4af27ff700] DEBUG - It took 20.000000 ms to retrieve 104 items.
Dec 05, 2018 15:04:00.002 [0x7f4af4ffe700] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 51 items.
Dec 05, 2018 15:04:00.006 [0x7f4af4ffe700] DEBUG - Setting container serialization range to [0, 50] (total=1283)
Dec 05, 2018 15:04:00.012 [0x7f4adbfff700] DEBUG - It took 60.000000 ms to retrieve 16 items.
Dec 05, 2018 15:04:00.013 [0x7f4adbfff700] DEBUG - Setting container serialization range to [0, 15] (total=1283)
Dec 05, 2018 15:04:00.016 [0x7f4ae77fe700] DEBUG - It took 70.000000 ms to retrieve 104 items.
Dec 05, 2018 15:04:00.021 [0x7f4af27ff700] DEBUG - Setting container serialization range to [0, 25] (total=-1)
Dec 05, 2018 15:04:00.022 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.022 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 67365 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.022 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.023 [0x7f4af27ff700] DEBUG - Audio Stream: 101635, Subtitle Stream: -1
Dec 05, 2018 15:04:00.026 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.026 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 39685 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.026 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.026 [0x7f4af27ff700] DEBUG - Audio Stream: 46961, Subtitle Stream: -1
Dec 05, 2018 15:04:00.026 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49942] 200 GET /hubs/home/recentlyAdded?type=1 (18 live) TLS GZIP Page 0-15 232ms 7541 bytes (pipelined: 4)
Dec 05, 2018 15:04:00.027 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.027 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 39329 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.027 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.027 [0x7f4af27ff700] DEBUG - Audio Stream: 46702, Subtitle Stream: -1
Dec 05, 2018 15:04:00.028 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.028 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 34027 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.028 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.028 [0x7f4af27ff700] DEBUG - Audio Stream: 36579, Subtitle Stream: -1
Dec 05, 2018 15:04:00.029 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.029 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 33956 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.029 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.029 [0x7f4af27ff700] DEBUG - Audio Stream: 36266, Subtitle Stream: -1
Dec 05, 2018 15:04:00.030 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.030 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 33939 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.030 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.030 [0x7f4ad8ffb700] DEBUG - It took 90.000000 ms to retrieve 13 items.
Dec 05, 2018 15:04:00.031 [0x7f4af27ff700] DEBUG - Audio Stream: 36227, Subtitle Stream: -1
Dec 05, 2018 15:04:00.031 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49931] 200 GET /hubs/home/recentlyAdded?type=1 (18 live) TLS GZIP Page 0-50 253ms 20030 bytes (pipelined: 5)
Dec 05, 2018 15:04:00.032 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.032 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 33912 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.032 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.032 [0x7f4af27ff700] DEBUG - Audio Stream: 36204, Subtitle Stream: -1
Dec 05, 2018 15:04:00.034 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.034 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 33468 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.034 [0x7f4af27ff700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.034 [0x7f4af27ff700] DEBUG - Audio Stream: 35646, Subtitle Stream: -1
Dec 05, 2018 15:04:00.038 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for Better Call Saul.
Dec 05, 2018 15:04:00.040 [0x7f4ae77fe700] DEBUG - Setting container serialization range to [0, 15] (total=-1)
Dec 05, 2018 15:04:00.041 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.041 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 67365 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.041 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.041 [0x7f4ae77fe700] DEBUG - Audio Stream: 101635, Subtitle Stream: -1
Dec 05, 2018 15:04:00.041 [0x7f4ad8ffb700] DEBUG - It took 20.000000 ms to retrieve 153 items.
Dec 05, 2018 15:04:00.044 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.044 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 39685 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.044 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.044 [0x7f4ae77fe700] DEBUG - Audio Stream: 46961, Subtitle Stream: -1
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 39329 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - Audio Stream: 46702, Subtitle Stream: -1
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 34027 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.045 [0x7f4ae77fe700] DEBUG - Audio Stream: 36579, Subtitle Stream: -1
Dec 05, 2018 15:04:00.046 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for The Shield.
Dec 05, 2018 15:04:00.046 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.046 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 33956 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.046 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.046 [0x7f4ae77fe700] DEBUG - Audio Stream: 36266, Subtitle Stream: -1
Dec 05, 2018 15:04:00.047 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.047 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 33939 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.047 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.047 [0x7f4ae77fe700] DEBUG - Audio Stream: 36227, Subtitle Stream: -1
Dec 05, 2018 15:04:00.048 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.048 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 33912 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.048 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.048 [0x7f4ae77fe700] DEBUG - Audio Stream: 36204, Subtitle Stream: -1
Dec 05, 2018 15:04:00.049 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.049 [0x7f4ae77fe700] DEBUG - Selecting best audio stream for part ID 33468 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.049 [0x7f4ae77fe700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.049 [0x7f4ae77fe700] DEBUG - Audio Stream: 35646, Subtitle Stream: -1
Dec 05, 2018 15:04:00.052 [0x7f4ae77fe700] DEBUG - There were 1 top-level paths for Better Call Saul.
Dec 05, 2018 15:04:00.055 [0x7f4ad8ffb700] DEBUG - It took 50.000000 ms to retrieve 211 items.
Dec 05, 2018 15:04:00.055 [0x7f4ae77fe700] DEBUG - There were 1 top-level paths for The Shield.
Dec 05, 2018 15:04:00.056 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for The Office (US).
Dec 05, 2018 15:04:00.062 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for Star Trek.
Dec 05, 2018 15:04:00.062 [0x7f4ad8ffb700] DEBUG - It took 10.000000 ms to retrieve 118 items.
Dec 05, 2018 15:04:00.065 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for The Wire.
Dec 05, 2018 15:04:00.065 [0x7f4ae77fe700] DEBUG - There were 1 top-level paths for The Office (US).
Dec 05, 2018 15:04:00.068 [0x7f4ae77fe700] DEBUG - There were 1 top-level paths for Star Trek.
Dec 05, 2018 15:04:00.070 [0x7f4ae77fe700] DEBUG - There were 1 top-level paths for The Wire.
Dec 05, 2018 15:04:00.071 [0x7f4ad8ffb700] DEBUG - It took 40.000000 ms to retrieve 193 items.
Dec 05, 2018 15:04:00.072 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for The Sopranos.
Dec 05, 2018 15:04:00.076 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for Game of Thrones.
Dec 05, 2018 15:04:00.078 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.078 [0x7f4ad8ffb700] DEBUG - It took 10.000000 ms to retrieve 130 items.
Dec 05, 2018 15:04:00.078 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 2285 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.078 [0x7f4af27ff700] DEBUG - Audio Stream: 1553, Subtitle Stream: 1554
Dec 05, 2018 15:04:00.079 [0x7f4af0fff700] DEBUG - Cleaning directory for session 963479ace4f3a64bd7777d8f574320bf (/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-963479ace4f3a64bd7777d8f574320bf-00ad7f36-9ca4-45ba-89a1-29c8e1211d40)
Dec 05, 2018 15:04:00.079 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49946] 200 GET /hubs/home/recentlyAdded?type=2 (18 live) TLS GZIP Page 0-15 293ms 13734 bytes (pipelined: 2)
Dec 05, 2018 15:04:00.079 [0x7f4af27ff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.079 [0x7f4af27ff700] DEBUG - Selecting best audio stream for part ID 2283 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.079 [0x7f4af27ff700] DEBUG - Audio Stream: 1545, Subtitle Stream: 0
Dec 05, 2018 15:04:00.084 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for Breaking Bad.
Dec 05, 2018 15:04:00.084 [0x7f4ad8ffb700] DEBUG - It took 20.000000 ms to retrieve 138 items.
Dec 05, 2018 15:04:00.092 [0x7f4ad8ffb700] DEBUG - It took 10.000000 ms to retrieve 127 items.
Dec 05, 2018 15:04:00.093 [0x7f4af27ff700] DEBUG - There were 1 top-level paths for Seinfeld.
Dec 05, 2018 15:04:00.099 [0x7f4ad8ffb700] DEBUG - It took 10.000000 ms to retrieve 162 items.
Dec 05, 2018 15:04:00.101 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.8:49951] 200 GET /hubs/home/recentlyAdded?type=2 (18 live) TLS GZIP Page 0-25 316ms 22897 bytes (pipelined: 1)
Dec 05, 2018 15:04:00.105 [0x7f4ad8ffb700] DEBUG - It took 20.000000 ms to retrieve 132 items.
Dec 05, 2018 15:04:00.111 [0x7f4ad8ffb700] DEBUG - It took 0.000000 ms to retrieve 158 items.
Dec 05, 2018 15:04:00.117 [0x7f4ad8ffb700] DEBUG - It took 10.000000 ms to retrieve 157 items.
Dec 05, 2018 15:04:00.126 [0x7f4ad8ffb700] DEBUG - It took 10.000000 ms to retrieve 228 items.
Dec 05, 2018 15:04:00.137 [0x7f4ad8ffb700] DEBUG - It took 0.000000 ms to retrieve 148 items.
Dec 05, 2018 15:04:00.156 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.156 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61680 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.156 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94013, Subtitle Stream: 0
Dec 05, 2018 15:04:00.157 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.157 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61676 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.157 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.157 [0x7f4ad8ffb700] DEBUG - Audio Stream: 93995, Subtitle Stream: -1
Dec 05, 2018 15:04:00.158 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.158 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61682 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.158 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94023, Subtitle Stream: 0
Dec 05, 2018 15:04:00.158 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.158 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61683 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.158 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.158 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94028, Subtitle Stream: -1
Dec 05, 2018 15:04:00.159 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.159 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61684 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.159 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.159 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94033, Subtitle Stream: -1
Dec 05, 2018 15:04:00.160 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.160 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61677 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.160 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.160 [0x7f4ad8ffb700] DEBUG - Audio Stream: 93999, Subtitle Stream: -1
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61679 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94009, Subtitle Stream: -1
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61678 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.161 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94003, Subtitle Stream: -1
Dec 05, 2018 15:04:00.162 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.162 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61699 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.162 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.162 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94128, Subtitle Stream: -1
Dec 05, 2018 15:04:00.163 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.163 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61710 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.163 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.163 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94184, Subtitle Stream: -1
Dec 05, 2018 15:04:00.164 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.164 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61673 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.164 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.164 [0x7f4ad8ffb700] DEBUG - Audio Stream: 93927, Subtitle Stream: -1
Dec 05, 2018 15:04:00.165 [0x7f4ad8ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.165 [0x7f4ad8ffb700] DEBUG - Selecting best audio stream for part ID 61700 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.165 [0x7f4ad8ffb700] DEBUG - Audio Stream: 94132, Subtitle Stream: 0
Dec 05, 2018 15:04:00.197 [0x7f4af87fe700] DEBUG - Completed: [172.31.101.8:49953] 200 GET /hubs/metadata/29304/related?excludeFields=summary&count=12&includeExternalMetadata=1&asyncAugmentMetadata=1 (18 live) TLS GZIP 319ms 43795 bytes (pipelined: 2)
Dec 05, 2018 15:04:00.456 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:04:00.457 [0x7f4ad97fc700] DEBUG - Request: [172.31.101.224:33864 (Allowed Network)] GET /library/metadata/29304?checkFiles=1&includeExtras=1&includeRelated=1&includeRelatedCount=1 (18 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:04:00.470 [0x7f4ad97fc700] DEBUG - It took 0.000000 ms to retrieve 143 items.
Dec 05, 2018 15:04:00.474 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.474 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 61681 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.474 [0x7f4ad97fc700] DEBUG - Audio Stream: 94018, Subtitle Stream: 0
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 41345 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - Audio Stream: 49373, Subtitle Stream: -1
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 41346 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - Audio Stream: 49375, Subtitle Stream: -1
Dec 05, 2018 15:04:00.480 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 41347 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - Audio Stream: 49377, Subtitle Stream: -1
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 41348 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - Audio Stream: 49379, Subtitle Stream: -1
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 41349 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.481 [0x7f4ad97fc700] DEBUG - Audio Stream: 49381, Subtitle Stream: -1
Dec 05, 2018 15:04:00.482 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.482 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 41350 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.482 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select a subtitle.
Dec 05, 2018 15:04:00.482 [0x7f4ad97fc700] DEBUG - Audio Stream: 49383, Subtitle Stream: -1
Dec 05, 2018 15:04:00.503 [0x7f4ad97fc700] DEBUG - It took 0.000000 ms to retrieve 162 items.
Dec 05, 2018 15:04:00.507 [0x7f4ad97fc700] DEBUG - It took 0.000000 ms to retrieve 132 items.
Dec 05, 2018 15:04:00.518 [0x7f4ad97fc700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Dec 05, 2018 15:04:00.518 [0x7f4ad97fc700] DEBUG - Selecting best audio stream for part ID 61680 (autoselect: 1 language: en)
Dec 05, 2018 15:04:00.518 [0x7f4ad97fc700] DEBUG - Audio Stream: 94013, Subtitle Stream: 0
Dec 05, 2018 15:04:00.523 [0x7f4af8fff700] DEBUG - Completed: [172.31.101.224:33864] 200 GET /library/metadata/29304?checkFiles=1&includeExtras=1&includeRelated=1&includeRelatedCount=1 (18 live) TLS GZIP 66ms 7934 bytes (pipelined: 8)
Dec 05, 2018 15:04:05.182 [0x7f4af87fe700] DEBUG - handleStreamRead code 335544539: short read
Dec 05, 2018 15:04:05.201 [0x7f4ad87fa700] DEBUG - Request: [172.31.101.8:49946 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) TLS GZIP Signed-in
Dec 05, 2018 15:04:05.202 [0x7f4ad87fa700] DEBUG - Beginning read from two-way stream.
Dec 05, 2018 15:04:05.644 [0x7f4af87fe700] DEBUG - handleStreamRead code 335544539: short read
Dec 05, 2018 15:04:05.657 [0x7f4af8fff700] DEBUG - Auth: authenticated user 1 as jhadmin1
Dec 05, 2018 15:04:05.657 [0x7f4adafff700] DEBUG - Request: [172.31.101.8:49953 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (16 live) TLS GZIP Signed-in Token (jhadmin1)
Dec 05, 2018 15:04:05.658 [0x7f4adafff700] DEBUG - Beginning read from two-way stream.
^Z
[8]+  Stopped                 tail -f /var/lib/plexmed