[Ubuntu 16.06] Many of my MKV files are not playing in Plex - why?

server-linux

#1

I have problem with playback of some mkv files. Especially when playing with subtitles. Here is log - any ideas what is hapaning?

Aug 18, 2017 15:06:41.639 [0x7f9f847ff700] DEBUG - Request: [192.168.0.108:54506 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=7384&key=%2Flibrary%2Fmetadata%2F7384&state=buffering&playQueueItemID=3635&time=0&duration=2884887 (6 live) TLS GZIP Signed-in Token (qrczakk)
Aug 18, 2017 15:06:41.640 [0x7f9f847ff700] DEBUG - Client [3v28subyn76gubwl8f301lr2] reporting timeline state buffering, progress of 0/2884887ms for guid=, ratingKey=7384 url=, key=/library/metadata/7384, containerKey=, metadataId=7384
Aug 18, 2017 15:06:41.640 [0x7f9f847ff700] DEBUG - [Now] User is qrczakk (ID: 1)
Aug 18, 2017 15:06:41.640 [0x7f9f847ff700] DEBUG - [Now] Device is Safari (Plex Web (Safari)).
Aug 18, 2017 15:06:41.640 [0x7f9f847ff700] DEBUG - [Now] Profile is Web
Aug 18, 2017 15:06:41.640 [0x7f9f847ff700] DEBUG - [Now] Updated play state for /library/metadata/7384.
Aug 18, 2017 15:06:41.641 [0x7f9f847ff700] DEBUG - Statistics: (hzj9r5m8t86) Reporting active playback in state 2 of type 4 (scrobble: 0) for account 1
Aug 18, 2017 15:06:41.644 [0x7f9f847ff700] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Aug 18, 2017 15:06:41.645 [0x7f9faa7fe700] DEBUG - Completed: [192.168.0.108:54506] 200 GET /:/timeline?hasMDE=1&ratingKey=7384&key=%2Flibrary%2Fmetadata%2F7384&state=buffering&playQueueItemID=3635&time=0&duration=2884887 (6 live) TLS GZIP 6ms 494 bytes (pipelined: 1)
Aug 18, 2017 15:06:41.646 [0x7f9faa7fe700] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Aug 18, 2017 15:06:41.646 [0x7f9faa7fe700] DEBUG - Auth: authenticated user 1 as qrczakk
Aug 18, 2017 15:06:41.646 [0x7f9faa7fe700] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Aug 18, 2017 15:06:41.646 [0x7f9f8b7fb700] DEBUG - Request: [127.0.0.1:59736 (Loopback)] GET /status/sessions (7 live) GZIP Signed-in Token (qrczakk)
Aug 18, 2017 15:06:41.647 [0x7f9f8b7fb700] DEBUG - [Now] Adding 1 sessions.
Aug 18, 2017 15:06:41.649 [0x7f9f8b7fb700] DEBUG - It took 0.0 sec to serialize a list with 1 elements.
Aug 18, 2017 15:06:41.650 [0x7f9faa7fe700] DEBUG - Completed: [127.0.0.1:59736] 200 GET /status/sessions (7 live) GZIP 3ms 1645 bytes (pipelined: 1)
Aug 18, 2017 15:06:42.767 [0x7f9f93bff700] DEBUG - Request: [192.168.0.108:54500 (Subnet)] GET /video/:/transcode/universal/session/9af8itg0l4ks7zrwimntvdmx/base/00000.ts (7 live) TLS Signed-in
Aug 18, 2017 15:06:42.767 [0x7f9f93bff700] DEBUG - Asked for segment 0 from session.
Aug 18, 2017 15:06:42.767 [0x7f9f93bff700] WARN - Transcode runner appears to have died.
Aug 18, 2017 15:06:42.867 [0x7f9f93bff700] WARN - Timed out waiting for segment.
Aug 18, 2017 15:06:42.868 [0x7f9faafff700] DEBUG - Completed: [192.168.0.108:54500] 404 GET /video/:/transcode/universal/session/9af8itg0l4ks7zrwimntvdmx/base/00000.ts (7 live) TLS 101ms 288 bytes (pipelined: 9)
Aug 18, 2017 15:06:42.896 [0x7f9faa7fe700] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Aug 18, 2017 15:06:42.896 [0x7f9faa7fe700] DEBUG - Auth: authenticated user 1 as qrczakk
Aug 18, 2017 15:06:42.897 [0x7f9faa7fe700] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Aug 18, 2017 15:06:42.897 [0x7f9f847ff700] DEBUG - Request: [192.168.0.108:54506 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=7384&key=%2Flibrary%2Fmetadata%2F7384&state=error&playQueueItemID=3635&time=0&duration=2884887 (7 live) TLS GZIP Signed-in Token (qrczakk)
Aug 18, 2017 15:06:42.898 [0x7f9f847ff700] DEBUG - Client [3v28subyn76gubwl8f301lr2] reporting timeline state error, progress of 0/2884887ms for guid=, ratingKey=7384 url=, key=/library/metadata/7384, containerKey=, metadataId=7384
Aug 18, 2017 15:06:42.907 [0x7f9f847ff700] DEBUG - [Now] User is qrczakk (ID: 1)
Aug 18, 2017 15:06:42.907 [0x7f9f847ff700] DEBUG - [Now] Device is Safari (Plex Web (Safari)).
Aug 18, 2017 15:06:42.908 [0x7f9f847ff700] DEBUG - [Now] Profile is Web
Aug 18, 2017 15:06:42.908 [0x7f9f847ff700] DEBUG - [Now] Updated play state for /library/metadata/7384.
Aug 18, 2017 15:06:42.909 [0x7f9f847ff700] DEBUG - Statistics: (hzj9r5m8t86) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
Aug 18, 2017 15:06:42.910 [0x7f9f847ff700] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Aug 18, 2017 15:06:42.912 [0x7f9faa7fe700] DEBUG - Completed: [192.168.0.108:54506] 200 GET /:/timeline?hasMDE=1&ratingKey=7384&key=%2Flibrary%2Fmetadata%2F7384&state=error&playQueueItemID=3635&time=0&duration=2884887 (7 live) TLS GZIP 15ms 494 bytes (pipelined: 2)
Aug 18, 2017 15:06:42.914 [0x7f9faa7fe700] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Aug 18, 2017 15:06:42.914 [0x7f9faa7fe700] DEBUG - Auth: authenticated user 1 as qrczakk
Aug 18, 2017 15:06:42.914 [0x7f9faa7fe700] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Aug 18, 2017 15:06:42.914 [0x7f9f83ffe700] DEBUG - Request: [127.0.0.1:59738 (Loopback)] GET /status/sessions (8 live) GZIP Signed-in Token (qrczakk)
Aug 18, 2017 15:06:42.915 [0x7f9f83ffe700] DEBUG - [Now] Adding 1 sessions.
Aug 18, 2017 15:06:42.917 [0x7f9f83ffe700] DEBUG - It took 0.0 sec to serialize a list with 1 elements.
Aug 18, 2017 15:06:42.919 [0x7f9faa7fe700] DEBUG - Completed: [127.0.0.1:59738] 200 GET /status/sessions (7 live) GZIP 4ms 1641 bytes (pipelined: 1)
Aug 18, 2017 15:06:47.395 [0x7f9faafff700] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Aug 18, 2017 15:06:47.395 [0x7f9faafff700] DEBUG - Auth: authenticated user 1 as qrczakk
Aug 18, 2017 15:06:47.395 [0x7f9faafff700] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Aug 18, 2017 15:06:47.395 [0x7f9f8b7fb700] DEBUG - Request: [192.168.0.108:54506 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=7384&key=%2Flibrary%2Fmetadata%2F7384&state=stopped&playQueueItemID=3635&time=0&duration=2884887 (7 live) TLS GZIP Signed-in Token (qrczakk)
Aug 18, 2017 15:06:47.396 [0x7f9f8b7fb700] DEBUG - Client [3v28subyn76gubwl8f301lr2] reporting timeline state stopped, progress of 0/2884887ms for guid=, ratingKey=7384 url=, key=/library/metadata/7384, containerKey=, metadataId=7384
Aug 18, 2017 15:06:47.404 [0x7f9f8b7fb700] DEBUG - [Now] User is qrczakk (ID: 1)
Aug 18, 2017 15:06:47.404 [0x7f9f8b7fb700] DEBUG - [Now] Device is Safari (Plex Web (Safari)).
Aug 18, 2017 15:06:47.404 [0x7f9f8b7fb700] DEBUG - [Now] Profile is Web
Aug 18, 2017 15:06:47.405 [0x7f9f8b7fb700] DEBUG - [Now] Updated play state for /library/metadata/7384.
Aug 18, 2017 15:06:47.405 [0x7f9f8b7fb700] DEBUG - Statistics: (hzj9r5m8t86) Reporting active playback in state 3 of type 4 (scrobble: 0) for account 1
Aug 18, 2017 15:06:47.406 [0x7f9f8b7fb700] DEBUG - Streaming Resource: Terminating session 0x7f9fab23fb60:3v28subyn76gubwl8f301lr2 which is using transcoder slot.  Used slots is now 0
Aug 18, 2017 15:06:47.406 [0x7f9f8b7fb700] DEBUG - Streaming Resource: Terminated session 0x7f9fab23fb60:3v28subyn76gubwl8f301lr2 with reason Client stopped playback.
Aug 18, 2017 15:06:47.406 [0x7f9f8b7fb700] DEBUG - Streaming Resource: Removing session 0x7f9fab23fb60:3v28subyn76gubwl8f301lr2
Aug 18, 2017 15:06:47.406 [0x7f9fa9ffd700] DEBUG - Killing job.
Aug 18, 2017 15:06:47.406 [0x7f9fa9ffd700] DEBUG - Signalling job ID 30560 with 9
Aug 18, 2017 15:06:47.407 [0x7f9fa9ffd700] DEBUG - Job was already killed, not killing again.
Aug 18, 2017 15:06:47.407 [0x7f9fa9ffd700] DEBUG - Stopping transcode session 9af8itg0l4ks7zrwimntvdmx
Aug 18, 2017 15:06:47.408 [0x7f9fa9ffd700] DEBUG - Cleaning old transcode directories.
Aug 18, 2017 15:06:47.408 [0x7f9f8b7fb700] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Aug 18, 2017 15:06:47.409 [0x7f9faafff700] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Aug 18, 2017 15:06:47.409 [0x7f9faafff700] DEBUG - Auth: authenticated user 1 as qrczakk
Aug 18, 2017 15:06:47.409 [0x7f9fa9ffd700] DEBUG - Cleaning old transcode directory: /mnt/data/plex_cache/plex-transcode-9af8itg0l4ks7zrwimntvdmx-60768280-a3c6-4067-aeea-94c24d6e3030
Aug 18, 2017 15:06:47.409 [0x7f9faafff700] DEBUG - Auth: Came in with a super-token, authorization succeeded.
Aug 18, 2017 15:06:47.409 [0x7f9fa9ffd700] DEBUG - Whacked session 9af8itg0l4ks7zrwimntvdmx, 0 remaining.
Aug 18, 2017 15:06:47.410 [0x7f9f847ff700] DEBUG - Request: [192.168.0.108:54507 (Subnet)] GET /video/:/transcode/universal/stop?session=9af8itg0l4ks7zrwimntvdmx (9 live) TLS GZIP Signed-in Token (qrczakk)

#2

Would you please recreate one playback attempt, wait ~20 seconds after the attempt for all buffers to flush, then go to Settings - Server - Help - Download logs. It will present you with a ZIP file. Please attach that ZIP file and the XML (Get Info -> View XML) for the video you played in the test. This will allow me to see what PMS does and the decisions it made.


#3

running with ubuntu 16.04 just fine. i would recommend to use docker; less problematic and easier to deal with issue.


#4

@GForce10 said:
running with ubuntu 16.04 just fine. i would recommend to use docker; less problematic and easier to deal with issue.

Respectfully, how is it possible to tell if not in docker or on Ubuntu already?


#5

Here is the log and XML of file which does not play.

<MediaContainer size="1" allowSync="1" identifier="com.plexapp.plugins.library" librarySectionID="2" librarySectionTitle="TV Shows" librarySectionUUID="b121711d-9fdc-42f6-abd0-85b278bab152" mediaTagPrefix="/system/bundle/media/flags/" mediaTagVersion="1492033170">
<Video ratingKey="7397" key="/library/metadata/7397" parentRatingKey="7396" grandparentRatingKey="7352" guid="com.plexapp.agents.thetvdb://81189/2/1?lang=en" librarySectionID="2" librarySectionKey="/library/sections/2" type="episode" title="Seven Thirty-Seven" grandparentKey="/library/metadata/7352" parentKey="/library/metadata/7396" grandparentTitle="Breaking Bad" parentTitle="Season 2" contentRating="TV-MA" summary="Walt and Jesse are vividly reminded of Tuco’s volatile nature, and try to figure a way out of their business partnership. Hank attempts to mend fences between the estranged Marie and Skyler." index="1" parentIndex="2" rating="7.7" year="2009" thumb="/library/metadata/7397/thumb/1503131108" art="/library/metadata/7352/art/1503130741" parentThumb="/library/metadata/7396/thumb/1502886473" grandparentThumb="/library/metadata/7352/thumb/1503130741" grandparentArt="/library/metadata/7352/art/1503130741" grandparentTheme="/library/metadata/7352/theme/1503130741" duration="2835691" originallyAvailableAt="2009-03-08" addedAt="1502886466" updatedAt="1503131108" chapterSource="media">
<Media videoResolution="1080" id="19963" duration="2835691" bitrate="20592" width="1920" height="1080" aspectRatio="1.78" audioChannels="6" audioCodec="dca-ma" videoCodec="h264" container="mkv" videoFrameRate="24p" audioProfile="ma" videoProfile="high">
<Part accessible="1" exists="1" id="19989" key="/library/parts/19989/1503088344/file.mkv" duration="2835691" file="/mnt/data/torrents/Breaking.Bad.COMPLETE.PACK.1080p.BluRay.x264-PT/Breaking.Bad.S02.2009.Bluray.1080p.DTSMA.5.1.x264.dxva-FraMeSToR/Breaking.Bad.S02E01.Seven.Thirty-Seven.2009.Bluray.1080p.DTSMA.5.1.x264.dxva-FraMeSToR.mkv" size="7299144624" audioProfile="ma" container="mkv" videoProfile="high">
<Stream id="42085" streamType="1" default="1" codec="h264" index="0" bitrate="18864" language="English" languageCode="eng" bitDepth="8" chromaSubsampling="4:2:0" frameRate="23.976" hasScalingMatrix="0" height="1080" level="41" profile="high" refFrames="4" scanType="progressive" width="1920"/>
<Stream id="42086" streamType="2" selected="1" default="1" codec="dca" index="1" channels="6" bitrate="1536" language="English" languageCode="eng" audioChannelLayout="5.1(side)" bitDepth="24" profile="ma" samplingRate="48000"/>
<Stream id="42087" streamType="2" codec="ac3" index="2" channels="2" bitrate="192" language="English" languageCode="eng" audioChannelLayout="stereo" samplingRate="48000" title="Commentary Track"/>
<Stream id="42088" streamType="3" default="1" codec="srt" index="3" language="English" languageCode="eng"/>
<Stream id="42089" streamType="3" codec="srt" index="4" language="Nederlands" languageCode="dut"/>
<Stream id="42155" key="/library/streams/42155" streamType="3" codec="sub" language="polski" languageCode="pol"/>
</Part>
</Media>
<Director id="8642" filter="director=8642" tag="Bryan Cranston"/>
<Writer id="8641" filter="writer=8641" tag="J. Roberts"/>
<Extras size="0"></Extras>
</Video>
</MediaContainer>

#6

I'm seeing other issues with the torrents directory tree. PMS is attemping to play items which aren't there / can no longer see .. these generate a LPE error (Local Path Evaluator.

If PMS latched onto a file which later moved without the library updating, this error would happen.

I'm not seeing any other specific errors outside of Breaking Bad so will ask what happens if you move / copy that data out of the directory into a mainstream "TV" directory.

Also, is your TV section pointing to the torrents directory or further into it? If further into it, that's too far.

Aug 19, 2017 10:26:44.444 [0x7f9f93bff700] DEBUG - Library Updater: Queueing section 1
Aug 19, 2017 10:26:44.445 [0x7f9f8a7f9700] DEBUG - Library Updater: Requested that section 2 be updated, force=0, deep=0, subdir=/mnt/data/torrents/Breaking.Bad.COMPLETE.PACK.1080p.BluRay.x264-PT/Breaking.Bad.S03.1080p.Bluray.DTS.x264-DON/Breaking.Bad.S03E01.1080p.Bluray.DTS.x264-DON iTunes=0
Aug 19, 2017 10:26:44.445 [0x7f9f8a7f9700] DEBUG - Library Updater: Queueing section 2
Aug 19, 2017 10:26:44.682 [0x7f9faa7fe700] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Aug 19, 2017 10:26:44.682 [0x7f9faa7fe700] DEBUG - Auth: Came in with the master token, authorization succeeded.
Aug 19, 2017 10:26:44.682 [0x7f9f96fff700] DEBUG - Request: [127.0.0.1:49578 (Loopback)] PUT /video/:/transcode/session/3080ugddn11myobwtx89u8c4/progress?progress=2.6&size=-22&remaining=33722 (18 live) Signed-in Token (qrczakk)
Aug 19, 2017 10:26:44.682 [0x7f9f96fff700] DEBUG - We want 60 seconds ahead, last returned was 3.000000 and max is 74.032367.
Aug 19, 2017 10:26:44.682 [0x7f9f96fff700] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
Aug 19, 2017 10:26:44.682 [0x7f9faa7fe700] DEBUG - Completed: [127.0.0.1:49578] 206 PUT /video/:/transcode/session/3080ugddn11myobwtx89u8c4/progress?progress=2.6&size=-22&remaining=33722 (17 live) 0ms 342 bytes
Aug 19, 2017 10:26:44.764 [0x7f9f847ff700] DEBUG - BPQ: onConsiderProcessing: Idle (true)
Aug 19, 2017 10:26:44.764 [0x7f9f847ff700] DEBUG - BPQ: [Idle] -> [Processing]
Aug 19, 2017 10:26:44.765 [0x7f9f847ff700] DEBUG - BPQ: generating queue items from 2 generator(s)
Aug 19, 2017 10:26:44.766 [0x7f9f847ff700] DEBUG - Sync: updating status for sync list 10355675, sync item 17255908, generator 1029
Aug 19, 2017 10:26:44.768 [0x7f9f847ff700] ERROR - LPE: unknown item 6539.
Aug 19, 2017 10:26:44.768 [0x7f9f847ff700] ERROR - Sync: failed to generate query for path library://7d876161-29a8-4426-a283-fafcf5a46702/item/%2Flibrary%2Fmetadata%2F6539 in sync item 17255913
Aug 19, 2017 10:26:44.768 [0x7f9f847ff700] ERROR - Sync: skipping i

#7

Changing folders tree to less deep helped. But than again it stucks when playing on my TV. It is strange as I have been using Plex for around 2 years without same problems. Attaching logs after last failure on my Sony TV (via Opera). Anything you can see there failing?

<MediaContainer size="1" allowSync="1" identifier="com.plexapp.plugins.library" librarySectionID="2" librarySectionTitle="TV Shows" librarySectionUUID="b121711d-9fdc-42f6-abd0-85b278bab152" mediaTagPrefix="/system/bundle/media/flags/" mediaTagVersion="1492033170">
<Video ratingKey="7457" key="/library/metadata/7457" parentRatingKey="7469" grandparentRatingKey="7352" guid="com.plexapp.agents.thetvdb://81189/2/2?lang=en" librarySectionID="2" librarySectionKey="/library/sections/2" type="episode" title="Grilled" grandparentKey="/library/metadata/7352" parentKey="/library/metadata/7469" grandparentTitle="Breaking Bad" parentTitle="Season 2" contentRating="TV-MA" summary="Walt and Jesse find themselves in close quarters with an unhinged Tuco. Marie and Hank comfort Skyler, who is distraught over Walt’s disappearance. Hank pays a visit to Mrs. Pinkman on some not-so-official business." index="2" parentIndex="2" rating="7.9" viewOffset="1135640" lastViewedAt="1503250247" year="2009" thumb="/library/metadata/7457/thumb/1503227935" art="/library/metadata/7352/art/1503130741" parentThumb="/library/metadata/7469/thumb/1503209794" grandparentThumb="/library/metadata/7352/thumb/1503130741" grandparentArt="/library/metadata/7352/art/1503130741" grandparentTheme="/library/metadata/7352/theme/1503130741" duration="2877739" originallyAvailableAt="2009-03-15" addedAt="1503209780" updatedAt="1503227935" chapterSource="media">
<Media videoResolution="1080" id="20190" duration="2877739" bitrate="20557" width="1920" height="1080" aspectRatio="1.78" audioChannels="6" audioCodec="dca-ma" videoCodec="h264" container="mkv" videoFrameRate="24p" audioProfile="ma" videoProfile="high">
<Part accessible="1" exists="1" id="20217" key="/library/parts/20217/1503103546/file.mkv" duration="2877739" file="/mnt/data/torrents/Breaking.Bad.S02.2009.Bluray.1080p.DTSMA.5.1.x264.dxva-FraMeSToR/Breaking.Bad.S02E02.Grilled.2009.Bluray.1080p.DTSMA.5.1.x264.dxva-FraMeSToR.mkv" size="7394728258" audioProfile="ma" container="mkv" videoProfile="high">
<Stream id="42675" streamType="1" default="1" codec="h264" index="0" bitrate="19021" language="English" languageCode="eng" bitDepth="8" chromaSubsampling="4:2:0" frameRate="23.976" hasScalingMatrix="0" height="1080" level="41" profile="high" refFrames="4" scanType="progressive" width="1920"/>
<Stream id="42676" streamType="2" selected="1" default="1" codec="dca" index="1" channels="6" bitrate="1536" language="English" languageCode="eng" audioChannelLayout="5.1(side)" bitDepth="24" profile="ma" samplingRate="48000"/>
<Stream id="42677" streamType="3" selected="1" default="1" codec="srt" index="2" language="English" languageCode="eng"/>
<Stream id="42678" streamType="3" codec="srt" index="3" language="Nederlands" languageCode="dut"/>
<Stream id="42778" key="/library/streams/42778" streamType="3" codec="sub" language="polski" languageCode="pol"/>
</Part>
</Media>
<Director id="8644" filter="director=8644" tag="Charles Haid"/>
<Writer id="8599" filter="writer=8599" tag="George Mastras"/>
<Extras size="0"></Extras>
</Video>
</MediaContainer>