Server Version#: 1.14.1.5488
Player Version#: 0.1.6
Hey there,
I think since the last update of the app I have an issue playing movies via “Plex for Kodi”. (Tried on 3 different devices). Funny enough, Plex for Kodi has no issue whatsoever playing any TV Shows, but as soon as it tries to play a movie, it throttles and then go back to the movie info page…
What is weird(er?) is that it is working perfectly if I use “Plex” (direct play) or any browser (transcoding)
Any idea what the issue could be?
(The error I can see in the log is the following:
Dec 31, 2018 13:15:44.645 [26912] ERROR - Caught exception trying to stream file: /storage/DISKSTATION/Movies/The.Predator.2018.1080p.WEB-DL.DD5.1.H264-FGT.mkv: write: Broken pipe
Bigger extract of the log:
Dec 31, 2018 13:15:43.715 [8737] DEBUG - handleStreamRead code 335544539: short read
Dec 31, 2018 13:15:43.734 [8738] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:43.735 [26895] DEBUG - Request: [IP:53451 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (14 live) TLS GZIP Signed-in Token (User)
Dec 31, 2018 13:15:43.736 [26895] DEBUG - Beginning read from two-way stream.
Dec 31, 2018 13:15:44.645 [26912] ERROR - Caught exception trying to stream file: /storage/DISKSTATION/Movies/The.Predator.2018.1080p.WEB-DL.DD5.1.H264-FGT.mkv: write: Broken pipe
Dec 31, 2018 13:15:44.645 [8737] DEBUG - Completed after connection close: [IP:53449] 500 GET /library/parts/13464/1544982458/file.mkv (15 live) TLS 30048ms 0 bytes (pipelined: 1)
Dec 31, 2018 13:15:44.674 [8737] DEBUG - Failed to stream media, client probably disconnected after 1769472 bytes: 104 - Connection reset by peer
Dec 31, 2018 13:15:44.674 [8737] DEBUG - Completed: [IP:53448] 200 GET /library/parts/13464/1544982458/file.mkv (15 live) TLS 30145ms 1769472 bytes (pipelined: 1) (range: bytes=0-)
Dec 31, 2018 13:15:44.684 [8738] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.685 [26895] DEBUG - Request: [IP:53452 (Subnet)] GET /:/timeline?containerKey=/video/:/transcode/universal/decision%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx%26copyts%3D1%26path%3D%252Flibrary%252Fmetadata%252F12076%26offset%3D1120%26session%3Dfd790b70-894b-413f-9301-8c4cafb0f3e8%26directStream%3D1%26directPlay%3D1%26videoQuality%3D100%26videoResolution%3D3840x2160%26maxVideoBitrate%3D200000%26mediaIndex%3D0%26partIndex%3D0%26X-Plex-Client-Profile-Extra%3Dappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Dac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Dac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Deac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Deac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Ddca%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Ddca%2529%252Badd-limitation%2528scope%253DvideoAudioCodec%2526scopeName%253Ddca%2526type%253DupperBound%2526name%253Daudio.channels%2526value%253D6%2526isRequired%253Dfalse%2529%252Bappend-transcode-target-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526videoCodec%253Dvp9%2529%26location%3Dlan%26subtitles%3Dsidecar%26mediaBufferSize%3D20971%26hasMDE%3D1%26X-Plex-Platform%3DChrome&ratingKey=12076&state=playing&key=/library/metadata/12076&time=1120000&duration=6456655&guid=com.plexapp.agents.imdb%3A//tt3829266%3Flang%3Den (14 live) TLS GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.686 [26895] DEBUG - Client [fd790b70-894b-413f-9301-8c4cafb0f3e8] reporting timeline state playing, progress of 1120000/6456655ms for guid=com.plexapp.agents.imdb://tt3829266?lang=en, ratingKey=12076 url=, key=/library/metadata/12076, containerKey=/video/:/transcode/universal/decision?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx©ts=1&path=%2Flibrary%2Fmetadata%2F12076&offset=1120&session=fd790b70-894b-413f-9301-8c4cafb0f3e8&directStream=1&directPlay=1&videoQuality=100&videoResolution=3840x2160&maxVideoBitrate=200000&mediaIndex=0&partIndex=0&X-Plex-Client-Profile-Extra=append-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Dac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Dac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Deac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Deac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Ddca%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Ddca%29%2Badd-limitation%28scope%3DvideoAudioCodec%26scopeName%3Ddca%26type%3DupperBound%26name%3Daudio.channels%26value%3D6%26isRequired%3Dfalse%29%2Bappend-transcode-target-codec%28type%3DvideoProfile%26context%3Dstreaming%26videoCodec%3Dvp9%29&location=lan&subtitles=sidecar&mediaBufferSize=20971&hasMDE=1&X-Plex-Platform=Chrome, metadataId=12076, source=
Dec 31, 2018 13:15:44.693 [26895] DEBUG - Play progress on 12076 ‘The Predator’ - got played 1120000 ms by account 1!
Dec 31, 2018 13:15:44.719 [26895] DEBUG - It took 20.000000 ms to retrieve 127 items.
Dec 31, 2018 13:15:44.751 [26895] DEBUG - It took 10.000000 ms to retrieve 127 items.
Dec 31, 2018 13:15:44.764 [26895] DEBUG - Audio Stream: 33664, Subtitle Stream: -1
Dec 31, 2018 13:15:44.768 [26895] DEBUG - [Now] User is User (ID: 1)
Dec 31, 2018 13:15:44.768 [26895] DEBUG - [Now] Device is Kodi (Kodi Add-on ( )).
Dec 31, 2018 13:15:44.768 [26895] DEBUG - [Now] Profile is Windows
Dec 31, 2018 13:15:44.768 [26895] DEBUG - [Now] Updated play state for /library/metadata/12076.
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/home.continue/1/hubs/en-us/’ because event plex.event.play.session.state.update referenced an item the hub contained
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/home.movies.recent/1/hubs//count=10’ because event plex.event.play.session.state.update referenced an item the hub contained
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/home.movies.recent/1/hubs/en-us/’ because event plex.event.play.session.state.update referenced an item the hub contained
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/movie.inprogress.1/1/hubs/sections/1//count=10’ because event plex.event.play.session.state.update referenced an item the hub contained
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/movie.recentlyadded.1/1/hubs/sections/1//count=10’ because event plex.event.play.session.state.update referenced an item the hub contained
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/movie.recentlyreleased.1/1/hubs/sections/1//count=10’ because event plex.event.play.session.state.update referenced an item the hub contained
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/movie.recentlyviewed.1/1/hubs/sections/1//count=10’ because of event plex.event.play.session.state.update.
Dec 31, 2018 13:15:44.769 [26895] DEBUG - HubCache: Expiring ‘1/movie.topunwatched.1/1/hubs/sections/1//count=10’ because of event plex.event.play.session.state.update.
Dec 31, 2018 13:15:44.773 [26895] DEBUG - Statistics: (fd790b70-894b-413f-9301-8c4cafb0f3e8) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Dec 31, 2018 13:15:44.776 [8737] DEBUG - Completed: [IP:53452] 200 GET /:/timeline?containerKey=/video/:/transcode/universal/decision%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx%26copyts%3D1%26path%3D%252Flibrary%252Fmetadata%252F12076%26offset%3D1120%26session%3Dfd790b70-894b-413f-9301-8c4cafb0f3e8%26directStream%3D1%26directPlay%3D1%26videoQuality%3D100%26videoResolution%3D3840x2160%26maxVideoBitrate%3D200000%26mediaIndex%3D0%26partIndex%3D0%26X-Plex-Client-Profile-Extra%3Dappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Dac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Dac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Deac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Deac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Ddca%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Ddca%2529%252Badd-limitation%2528scope%253DvideoAudioCodec%2526scopeName%253Ddca%2526type%253DupperBound%2526name%253Daudio.channels%2526value%253D6%2526isRequired%253Dfalse%2529%252Bappend-transcode-target-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526videoCodec%253Dvp9%2529%26location%3Dlan%26subtitles%3Dsidecar%26mediaBufferSize%3D20971%26hasMDE%3D1%26X-Plex-Platform%3DChrome&ratingKey=12076&state=playing&key=/library/metadata/12076&time=1120000&duration=6456655&guid=com.plexapp.agents.imdb%3A//tt3829266%3Flang%3Den (14 live) TLS GZIP 91ms 492 bytes (pipelined: 1)
Dec 31, 2018 13:15:44.788 [8738] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.788 [8737] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.788 [26895] DEBUG - Request: [IP:53453 (Subnet)] GET /status/sessions (15 live) TLS GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.788 [26962] DEBUG - Request: [IP:53454 (Subnet)] GET /status/sessions (15 live) TLS GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.789 [26895] DEBUG - [Now] Adding 1 sessions.
Dec 31, 2018 13:15:44.789 [8737] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.789 [26912] DEBUG - Request: [IP Server:60820 (Subnet)] GET /status/sessions (16 live) Signed-in Token (User)
Dec 31, 2018 13:15:44.790 [26912] DEBUG - [Now] Adding 1 sessions.
Dec 31, 2018 13:15:44.791 [26962] DEBUG - [Now] Adding 1 sessions.
Dec 31, 2018 13:15:44.791 [8737] DEBUG - Completed: [IP Server:60820] 200 GET /status/sessions (16 live) 1ms 12178 bytes (pipelined: 1)
Dec 31, 2018 13:15:44.793 [8737] DEBUG - Completed: [IP:53453] 200 GET /status/sessions (16 live) TLS GZIP 5ms 4760 bytes (pipelined: 1)
Dec 31, 2018 13:15:44.795 [8737] DEBUG - Completed: [IP:53454] 200 GET /status/sessions (16 live) TLS GZIP 6ms 4760 bytes (pipelined: 1)
Dec 31, 2018 13:15:44.797 [8737] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.797 [26964] DEBUG - Request: [IP:53453 (Subnet)] GET /status/sessions (15 live) TLS GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.797 [26964] DEBUG - [Now] Adding 1 sessions.
Dec 31, 2018 13:15:44.802 [8737] DEBUG - Completed: [IP:53453] 200 GET /status/sessions (15 live) TLS GZIP 4ms 4760 bytes (pipelined: 2)
Dec 31, 2018 13:15:44.832 [8738] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.832 [26912] DEBUG - Request: [IP Server:60821 (Subnet)] GET /library/metadata/12076 (17 live) Signed-in Token (User)
Dec 31, 2018 13:15:44.852 [26912] DEBUG - It took 30.000000 ms to retrieve 127 items.
Dec 31, 2018 13:15:44.857 [26912] DEBUG - Audio Stream: 33664, Subtitle Stream: -1
Dec 31, 2018 13:15:44.859 [8737] DEBUG - Completed: [IP Server:60821] 200 GET /library/metadata/12076 (17 live) 27ms 11350 bytes (pipelined: 1)
Dec 31, 2018 13:15:44.862 [8737] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.863 [26962] DEBUG - Request: [IP:53455 (Subnet)] GET /:/timeline?containerKey=/video/:/transcode/universal/decision%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx%26copyts%3D1%26path%3D%252Flibrary%252Fmetadata%252F12076%26offset%3D1120%26session%3Dfd790b70-894b-413f-9301-8c4cafb0f3e8%26directStream%3D1%26directPlay%3D1%26videoQuality%3D100%26videoResolution%3D3840x2160%26maxVideoBitrate%3D200000%26mediaIndex%3D0%26partIndex%3D0%26X-Plex-Client-Profile-Extra%3Dappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Dac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Dac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Deac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Deac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Ddca%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Ddca%2529%252Badd-limitation%2528scope%253DvideoAudioCodec%2526scopeName%253Ddca%2526type%253DupperBound%2526name%253Daudio.channels%2526value%253D6%2526isRequired%253Dfalse%2529%252Bappend-transcode-target-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526videoCodec%253Dvp9%2529%26location%3Dlan%26subtitles%3Dsidecar%26mediaBufferSize%3D20971%26hasMDE%3D1%26X-Plex-Platform%3DChrome&ratingKey=12076&state=stopped&key=/library/metadata/12076&time=1120000&duration=6456655&guid=com.plexapp.agents.imdb%3A//tt3829266%3Flang%3Den (17 live) TLS GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.864 [26962] DEBUG - Client [fd790b70-894b-413f-9301-8c4cafb0f3e8] reporting timeline state stopped, progress of 1120000/6456655ms for guid=com.plexapp.agents.imdb://tt3829266?lang=en, ratingKey=12076 url=, key=/library/metadata/12076, containerKey=/video/:/transcode/universal/decision?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx©ts=1&path=%2Flibrary%2Fmetadata%2F12076&offset=1120&session=fd790b70-894b-413f-9301-8c4cafb0f3e8&directStream=1&directPlay=1&videoQuality=100&videoResolution=3840x2160&maxVideoBitrate=200000&mediaIndex=0&partIndex=0&X-Plex-Client-Profile-Extra=append-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Dac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Dac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Deac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Deac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Ddca%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Ddca%29%2Badd-limitation%28scope%3DvideoAudioCodec%26scopeName%3Ddca%26type%3DupperBound%26name%3Daudio.channels%26value%3D6%26isRequired%3Dfalse%29%2Bappend-transcode-target-codec%28type%3DvideoProfile%26context%3Dstreaming%26videoCodec%3Dvp9%29&location=lan&subtitles=sidecar&mediaBufferSize=20971&hasMDE=1&X-Plex-Platform=Chrome, metadataId=12076, source=
Dec 31, 2018 13:15:44.864 [8737] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.865 [26964] DEBUG - Request: [IP:53456 (Subnet)] GET /hubs/metadata/12076/postplay (17 live) TLS GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.870 [26962] DEBUG - Play progress on 12076 ‘The Predator’ - got played 1120000 ms by account 1!
Dec 31, 2018 13:15:44.892 [26964] DEBUG - It took 30.000000 ms to retrieve 127 items.
Dec 31, 2018 13:15:44.897 [26962] DEBUG - It took 40.000000 ms to retrieve 127 items.
Dec 31, 2018 13:15:44.910 [26962] DEBUG - [Now] User is User (ID: 1)
Dec 31, 2018 13:15:44.910 [26962] DEBUG - [Now] Device is Kodi (Kodi Add-on ( )).
Dec 31, 2018 13:15:44.911 [26962] DEBUG - [Now] Profile is Windows
Dec 31, 2018 13:15:44.911 [26962] DEBUG - [Now] Updated play state for /library/metadata/12076.
Dec 31, 2018 13:15:44.912 [26962] DEBUG - Statistics: (fd790b70-894b-413f-9301-8c4cafb0f3e8) Reporting active playback in state 3 of type 1 (scrobble: 0) for account 1
Dec 31, 2018 13:15:44.913 [26962] DEBUG - Streaming Resource: Terminated session 0x236707a020:fd790b70-894b-413f-9301-8c4cafb0f3e8 with reason Client stopped playback.
Dec 31, 2018 13:15:44.913 [26962] DEBUG - Streaming Resource: Removing session 0x236707a020:fd790b70-894b-413f-9301-8c4cafb0f3e8
Dec 31, 2018 13:15:44.918 [8738] DEBUG - Completed: [IP:53455] 200 GET /:/timeline?containerKey=/video/:/transcode/universal/decision%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx%26copyts%3D1%26path%3D%252Flibrary%252Fmetadata%252F12076%26offset%3D1120%26session%3Dfd790b70-894b-413f-9301-8c4cafb0f3e8%26directStream%3D1%26directPlay%3D1%26videoQuality%3D100%26videoResolution%3D3840x2160%26maxVideoBitrate%3D200000%26mediaIndex%3D0%26partIndex%3D0%26X-Plex-Client-Profile-Extra%3Dappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Dac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Dac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Deac3%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Deac3%2529%252Bappend-transcode-target-audio-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526audioCodec%253Ddca%2529%252Badd-direct-play-profile%2528type%253DvideoProfile%2526container%253Dmatroska%2526videoCodec%253D%252A%2526audioCodec%253Ddca%2529%252Badd-limitation%2528scope%253DvideoAudioCodec%2526scopeName%253Ddca%2526type%253DupperBound%2526name%253Daudio.channels%2526value%253D6%2526isRequired%253Dfalse%2529%252Bappend-transcode-target-codec%2528type%253DvideoProfile%2526context%253Dstreaming%2526videoCodec%253Dvp9%2529%26location%3Dlan%26subtitles%3Dsidecar%26mediaBufferSize%3D20971%26hasMDE%3D1%26X-Plex-Platform%3DChrome&ratingKey=12076&state=stopped&key=/library/metadata/12076&time=1120000&duration=6456655&guid=com.plexapp.agents.imdb%3A//tt3829266%3Flang%3Den (17 live) TLS GZIP 55ms 492 bytes (pipelined: 1)
Dec 31, 2018 13:15:44.929 [8738] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.929 [26895] DEBUG - Request: [IP:53453 (Subnet)] GET /hubs/home/continueWatching (17 live) TLS Page 0-15 GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.931 [8737] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.931 [26912] DEBUG - Request: [IP:53454 (Subnet)] GET /hubs/home/continueWatching (15 live) TLS Page 0-15 GZIP Signed-in Token (User)
Dec 31, 2018 13:15:44.946 [8738] DEBUG - Auth: authenticated user 1 as User
Dec 31, 2018 13:15:44.946 [26962] DEBUG - Request: [IP:53457 (Subnet)] GET /hubs/home/onDeck (16 live) TLS Page 0-15 GZIP Signed-in Token (User)
Dec 31, 2018 13:15:45.005 [26964] WARN - SLOW QUERY: It took 290.000000 ms to retrieve 1 items.
Dec 31, 2018 13:15:45.032 [26964] DEBUG - It took 70.000000 ms to retrieve 7 items.
Dec 31, 2018 13:15:45.046 [26964] DEBUG - It took 60.000000 ms to retrieve 122 items.
Dec 31, 2018 13:15:45.076 [26964] DEBUG - It took 80.000000 ms to retrieve 175 items.
Dec 31, 2018 13:15:45.089 [26964] DEBUG - It took 50.000000 ms to retrieve 107 items.
Dec 31, 2018 13:15:45.104 [26964] DEBUG - It took 60.000000 ms to retrieve 129 items.
Dec 31, 2018 13:15:45.122 [26964] DEBUG - It took 50.000000 ms to retrieve 163 items.
Dec 31, 2018 13:15:45.136 [26964] DEBUG - We’re going to try to auto-select an audio stream for account 1.
Dec 31, 2018 13:15:45.136 [26964] DEBUG - Selecting best audio stream for part ID 52 (autoselect: 0 language: en)
Dec 31, 2018 13:15:45.136 [26964] DEBUG - Audio Stream: 33166, Subtitle Stream: -1
Dec 31, 2018 13:15:45.138 [26964] DEBUG - We’re going to try to auto-select an audio stream for account 1.
Dec 31, 2018 13:15:45.138 [26964] DEBUG - Selecting best audio stream for part ID 133 (autoselect: 0 language: en)
Dec 31, 2018 13:15:45.138 [26964] DEBUG - Audio Stream: 33310, Subtitle Stream: -1
Dec 31, 2018 13:15:45.140 [26964] DEBUG - We’re going to try to auto-select an audio stream for account 1.
Dec 31, 2018 13:15:45.140 [26964] DEBUG - Selecting best audio stream for part ID 84 (autoselect: 0 language: en)
Dec 31, 2018 13:15:45.140 [26964] DEBUG - Audio Stream: 33428, Subtitle Stream: -1
Dec 31, 2018 13:15:45.142 [26964] DEBUG - We’re going to try to auto-select an audio stream for account 1.
Dec 31, 2018 13:15:45.143 [26964] DEBUG - Selecting best audio stream for part ID 59 (autoselect: 0 language: en)
Dec 31, 2018 13:15:45.143 [26964] DEBUG - Audio Stream: 32793, Subtitle Stream: -1
Dec 31, 2018 13:15:45.144 [26964] DEBUG - We’re going to try to auto-select an audio stream for account 1.
Dec 31, 2018 13:15:45.144 [26964] DEBUG - Selecting best audio stream for part ID 12931 (autoselect: 0 language: en)
Dec 31, 2018 13:15:45.145 [26964] DEBUG - Audio Stream: 32765, Subtitle Stream: -1
Dec 31, 2018 13:15:45.146 [26964] DEBUG - We’re going to try to auto-select an audio stream for account 1.
Dec 31, 2018 13:15:45.146 [26964] DEBUG - Selecting best audio stream for part ID 12922 (autoselect: 0 language: en)
Dec 31, 2018 13:15:45.146 [26964] DEBUG - Audio Stream: 33957, Subtitle Stream: -1
Dec 31, 2018 13:15:45.163 [8737] DEBUG - Completed: [IP:53456] 200 GET /hubs/metadata/12076/postplay (16 live) TLS GZIP 297ms 22580 bytes (pipelined: 1)
