Transcoding 1080p permission error, 720p works fine

Plex Media Server
, ,
1

Server Version: 1.29.2.6364-6d72b0cf6 (LinuxServer Docker on unRAID)
Player Version: Android TV 9.12.2.36964 (Nvidia Shield Pro)
Server Logs Transcoding to 20Mbps 1080p
Server Logs Transcoding to 4Mbps 720

I’ve been having an issue where I’ll be direct playing a 1080p movie and trying to change the quality to a lower bitrate 1080p it will jump straight to the end of file screen but if I change to any other resolution 720p, 240p, etc, it will transcode just fine.

If I reduce the default quality in the client settings before starting the movie, the client will show it is transcoding to the lower 1080p bitrate but the server would say it is direct playing.

In the log file from line 966, I’m getting some kind of permission error after I have tried to change the quality on the client.
WARN - [Req#98] Denying access due to session lacking permission to direct play part 74548

Any ideas?

EDIT: It seems to be isolated to Plex on Android TV, the iOS app and Plex Web get the transcoded 1080p stream fine but three Android TV clients are all having this problem.

2

That doesn’t make any sense so the DEBUG server logs which capture it happening are needed.

3

They are already linked in the main post.
Transcoding to 20Mbps 1080p https://hastebin.com/raw/ozicizidux
Transcoding to 4Mbps 720 https://hastebin.com/raw/tajovivete

I didn’t attach them to the post because I was getting an error when uploading the zip folder.

4

The 1080p file does not show the error.

Dec 11, 2022 12:20:26.672 [0x14a37d19eb38] DEBUG - [Req#b1] We're going to try to auto-select an audio stream for account 1.
Dec 11, 2022 12:20:26.672 [0x14a37d19eb38] DEBUG - [Req#b1] Selecting best audio stream for part ID 74548 (autoselect: 1 language: en)
Dec 11, 2022 12:20:26.672 [0x14a37d19eb38] DEBUG - [Req#b1] We're going to try to auto-select a subtitle.
Dec 11, 2022 12:20:26.672 [0x14a37d19eb38] DEBUG - [Req#b1] Subtitles: Found a candidate subtitle language [en] for a foreign film
Dec 11, 2022 12:20:26.672 [0x14a37d19eb38] DEBUG - [Req#b1] Subtitles: Found a candidate subtitle that matches our forced / language preference. [en] [0]. Reason [Prefer sidecar]
Dec 11, 2022 12:20:26.672 [0x14a37d19eb38] DEBUG - [Req#b1] Audio Stream: 255799, Subtitle Stream: 255986
Dec 11, 2022 12:20:26.673 [0x14a37c564b38] DEBUG - Request: [106.69.43.141:55738 (WAN)] GET /library/sections/6/extras/all?excludeFields=summary&extraType!=1&id=30826 (13 live) #b3 TLS Page 0-23 GZIP Signed-in Token (lachie99) (SHIELD Android TV)
Dec 11, 2022 12:20:26.673 [0x14a37c564b38] DEBUG - [Req#b3] Setting container serialization range to [0, 23] (total=-1)
Dec 11, 2022 12:20:26.674 [0x14a37d19eb38] DEBUG - [Req#b1] [Now] User is lachie99 (ID: 1)
Dec 11, 2022 12:20:26.674 [0x14a37d19eb38] DEBUG - [Req#b1] [Now] Device is Android (SHIELD Android TV).
Dec 11, 2022 12:20:26.675 [0x14a37d19eb38] DEBUG - [Req#b1] [Now] Profile is Android
Dec 11, 2022 12:20:26.675 [0x14a37d19eb38] DEBUG - [Req#b1] [Now] Updated play state for /library/metadata/30826.
Dec 11, 2022 12:20:26.675 [0x14a37d19eb38] DEBUG - [Req#b1] Statistics: (476e78a6c2608558-com-plexapp-android) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Dec 11, 2022 12:20:26.676 [0x14a37f34eb38] DEBUG - Completed: [106.69.43.141:55732] 200 GET /:/timeline?audioStreamID=255799&bufferedTime=0&column=2&context=home%3Ahub.movie.recentlyadded&duration=7813856&guid=plex%3A%2F%2Fmovie%2F5d77707e6afb3d002061b768&key=%2Flibrary%2Fmetadata%2F30826&playbackTime=12130&playQueueItemID=98726&ratingKey=30826&row=3&state=buffering&time=7006&token=xxxxxxxxxxxxxxxxxxxx (13 live) TLS GZIP 126ms 494 bytes (pipelined: 15)
Dec 11, 2022 12:20:26.684 [0x14a37f34eb38] DEBUG - Completed: [106.69.43.141:55738] 200 GET /library/sections/6/extras/all?excludeFields=summary&extraType!=1&id=30826 (13 live) TLS GZIP Page 0-23 11ms 2560 bytes (pipelined: 2)
Dec 11, 2022 12:20:26.728 [0x14a37c982b38] DEBUG - Request: [106.69.43.141:55732 (WAN)] GET /:/timeline?audioStreamID=255799&bufferedTime=0&column=2&context=home%3Ahub.movie.recentlyadded&duration=7813856&guid=plex%3A%2F%2Fmovie%2F5d77707e6afb3d002061b768&key=%2Flibrary%2Fmetadata%2F30826&playbackTime=12130&playQueueItemID=98726&ratingKey=30826&row=3&state=buffering&time=7006&token=xxxxxxxxxxxxxxxxxxxx (12 live) #c9 TLS GZIP Signed-in Token (lachie99) (SHIELD Android TV)
Dec 11, 2022 12:20:26.730 [0x14a37c982b38] DEBUG - [Req#c9] Client [476e78a6c2608558-com-plexapp-android] reporting timeline state buffering, progress of 7006/7813856ms for guid=plex://movie/5d77707e6afb3d002061b768, playbackTime=12130ms ratingKey=30826 url=, key=/library/metadata/30826, containerKey=, metadataId=30826, source=
Dec 11, 2022 12:20:26.732 [0x14a37c982b38] DEBUG - [Req#c9] [Now] User is lachie99 (ID: 1)
Dec 11, 2022 12:20:26.732 [0x14a37c982b38] DEBUG - [Req#c9] [Now] Device is Android (SHIELD Android TV).
Dec 11, 2022 12:20:26.738 [0x14a37c982b38] DEBUG - [Req#c9] [Now] Profile is Android
Dec 11, 2022 12:20:26.738 [0x14a37c982b38] DEBUG - [Req#c9] [Now] Updated play state for /library/metadata/30826.
Dec 11, 2022 12:20:26.738 [0x14a37c982b38] DEBUG - [Req#c9] Statistics: (476e78a6c2608558-com-plexapp-android) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Dec 11, 2022 12:20:26.742 [0x14a37f551b38] DEBUG - Completed: [106.69.43.141:55732] 200 GET /:/timeline?audioStreamID=255799&bufferedTime=0&column=2&context=home%3Ahub.movie.recentlyadded&duration=7813856&guid=plex%3A%2F%2Fmovie%2F5d77707e6afb3d002061b768&key=%2Flibrary%2Fmetadata%2F30826&playbackTime=12130&playQueueItemID=98726&ratingKey=30826&row=3&state=buffering&time=7006&token=xxxxxxxxxxxxxxxxxxxx (12 live) TLS GZIP 14ms 494 bytes (pipelined: 16)
Dec 11, 2022 12:20:27.020 [0x14a376753b38] DEBUG - Request: [106.69.43.141:55732 (WAN)] GET /library/metadata/30826/related?count=10&excludeElements=Actor%2CCollection%2CCountry%2CDirector%2CLabel%2CMood%2CPart%2CPhoto%2CProducer%2CSimilar%2CTopic%2CVast%2CWriter&excludeFields=file%2Ctagline&includeAugmentations=1&includeDetails=1&includeEmpty=1&includeExternalMetadata=1&includeLibraryPlaylists=1&includeMeta=1&includeRecentChannels=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&libraryHubsOnly=1 (11 live) #d1 TLS GZIP Signed-in Token (lachie99) (SHIELD Android TV)
Dec 11, 2022 12:20:27.232 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 112 items.
Dec 11, 2022 12:20:27.235 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 107 items.
Dec 11, 2022 12:20:27.238 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 149 items.
Dec 11, 2022 12:20:27.241 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 107 items.
Dec 11, 2022 12:20:27.243 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 121 items.
Dec 11, 2022 12:20:27.247 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 139 items.
Dec 11, 2022 12:20:27.250 [0x14a376753b38] DEBUG - [Req#d1] It took 10.000000 ms to retrieve 126 items.
Dec 11, 2022 12:20:27.252 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 120 items.
Dec 11, 2022 12:20:27.254 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 114 items.
Dec 11, 2022 12:20:27.256 [0x14a376753b38] DEBUG - [Req#d1] It took 0.000000 ms to retrieve 102 items.
Dec 11, 2022 12:20:27.274 [0x14a37f551b38] DEBUG - Completed: [106.69.43.141:55732] 200 GET /library/metadata/30826/related?count=10&excludeElements=Actor%2CCollection%2CCountry%2CDirector%2CLabel%2CMood%2CPart%2CPhoto%2CProducer%2CSimilar%2CTopic%2CVast%2CWriter&excludeFields=file%2Ctagline&includeAugmentations=1&includeDetails=1&includeEmpty=1&includeExternalMetadata=1&includeLibraryPlaylists=1&includeMeta=1&includeRecentChannels=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&libraryHubsOnly=1 (11 live) TLS GZIP 254ms 38817 bytes (pipelined: 17)
Dec 11, 2022 12:20:36.322 [0x14a376550b38] DEBUG - Request: [106.69.43.141:55732 (WAN)] GET /:/timeline?audioStreamID=255799&bufferedTime=0&column=2&context=home%3Ahub.movie.recentlyadded&duration=7813856&guid=plex%3A%2F%2Fmovie%2F5d77707e6afb3d002061b768&key=%2Flibrary%2Fmetadata%2F30826&playbackTime=12130&playQueueItemID=98726&ratingKey=30826&row=3&state=buffering&time=7006&timeStalled=10&token=xxxxxxxxxxxxxxxxxxxx (9 live) #db TLS GZIP Signed-in Token (lachie99) (SHIELD Android TV)
Dec 11, 2022 12:20:36.324 [0x14a376550b38] DEBUG - [Req#db] Client [476e78a6c2608558-com-plexapp-android] reporting timeline state buffering, progress of 7006/7813856ms for guid=plex://movie/5d77707e6afb3d002061b768, playbackTime=12130ms ratingKey=30826 url=, key=/library/metadata/30826, containerKey=, metadataId=30826, source=
Dec 11, 2022 12:20:36.325 [0x14a376550b38] DEBUG - [Req#db] [Now] User is lachie99 (ID: 1)
Dec 11, 2022 12:20:36.325 [0x14a376550b38] DEBUG - [Req#db] [Now] Device is Android (SHIELD Android TV).
Dec 11, 2022 12:20:36.332 [0x14a376550b38] DEBUG - [Req#db] [Now] Profile is Android
Dec 11, 2022 12:20:36.332 [0x14a376550b38] DEBUG - [Req#db] [Now] Updated play state for /library/metadata/30826.
Dec 11, 2022 12:20:36.333 [0x14a376550b38] DEBUG - [Req#db] Statistics: (476e78a6c2608558-com-plexapp-android) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Dec 11, 2022 12:20:36.337 [0x14a37f551b38] DEBUG - Completed: [106.69.43.141:55732] 200 GET /:/timeline?audioStreamID=255799&bufferedTime=0&column=2&context=home%3Ahub.movie.recentlyadded&duration=7813856&guid=plex%3A%2F%2Fmovie%2F5d77707e6afb3d002061b768&key=%2Flibrary%2Fmetadata%2F30826&playbackTime=12130&playQueueItemID=98726&ratingKey=30826&row=3&state=buffering&time=7006&timeStalled=10&token=xxxxxxxxxxxxxxxxxxxx (9 live) TLS GZIP 15ms 494 bytes (pipelined: 18)

You didn’t provide enough information.
May I now please have the ZIP containing the PMS logs after you recreate and capture fresh?

5

The log file linked already (https://hastebin.com/raw/ozicizidux) does show the error at Line 967. It happens at Dec 11, 2022 12:20:22.800

I can upload more logs later today (in Australia) if you need.

6

Please look at this (I think this is what you are looking at)

Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] [FFMPEG] - Format 0x30323449 -> yuv420p.
Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] [FFMPEG] - Format 0x50313134 -> yuv411p.
Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] [FFMPEG] - Format 0x48323234 -> yuv422p.
Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] [FFMPEG] - Format 0x56323234 -> yuv440p.
Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] [FFMPEG] - Format 0x50343434 -> yuv444p.
Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] [FFMPEG] - Format 0x33434d49 -> unknown.
Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] [FFMPEG] - Format 0x30313050 -> p010le.
Dec 11, 2022 12:20:22.716 [0x14a37c982b38] DEBUG - [Req#94/Transcode] Codecs: Testing with profile 'High'
Dec 11, 2022 12:20:22.717 [0x14a37c982b38] DEBUG - [Req#94/Transcode] MDE: Knives Out (2019): Audio Direct Streaming is disabled, so video's audio stream will be transcoded
Dec 11, 2022 12:20:22.719 [0x14a37c982b38] DEBUG - [Req#94/Transcode] MDE: Cannot direct stream audio stream due to profile or setting limitations
Dec 11, 2022 12:20:22.719 [0x14a37c982b38] DEBUG - [Req#94/Transcode] MDE: Knives Out (2019): selected media 0 / 61279
Dec 11, 2022 12:20:22.719 [0x14a37c982b38] DEBUG - [Req#94/Transcode] Streaming Resource: Session 0x14a37bffa618:476e78a6c2608558-com-plexapp-android changed from using 37155kbps to 19956kbps of WAN bandwidth.  Used bandwidth is now 19956kbps
Dec 11, 2022 12:20:22.719 [0x14a37c982b38] DEBUG - [Req#94/Transcode] Streaming Resource: Session 0x14a37bffa618:476e78a6c2608558-com-plexapp-android changed transcode slot usage to used.  Used slots is now 1
Dec 11, 2022 12:20:22.719 [0x14a37c982b38] DEBUG - [Req#94/Transcode] Streaming Resource: Reached Decision id=30826 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=61279 part=(id=74548 decision=transcode container=mkv protocol=hls streams=(Video=(id=255798 decision=transcode bitrate=18097 encoder=h264_vaapi width=1920 height=1080) Audio=(id=255799 decision=transcode bitrate=908 encoder=libopus channels=8 rate=48000) Subtitle=(id=255986 decision=ignore languageCode=eng location=sidecar))))
Dec 11, 2022 12:20:22.720 [0x14a37f551b38] DEBUG - Completed: [106.69.43.141:55732] 200 GET /video/:/transcode/universal/decision?advancedSubtitles=text&audioBoost=180&autoAdjustQuality=0&directPlay=0&directStream=0&directStreamAudio=0&fastSeek=1&hasMDE=1&location=wan&maxVideoBitrate=20000&mediaBufferSize=209664&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F30826&protocol=*&session=476e78a6c2608558-com-plexapp-android&skipSubtitles=1&subtitleSize=75&videoBitrate=20000&videoQuality=100&videoResolution=3840x2160 (7 live) TLS GZIP 86ms 4159 bytes (pipelined: 8)
Dec 11, 2022 12:20:22.792 [0x14a37c564b38] DEBUG - Request: [106.69.43.141:55732 (WAN)] GET /library/parts/74548/1582098521/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=209664 (7 live) #98 TLS Signed-in Token (lachie99) (SHIELD Android TV)
Dec 11, 2022 12:20:22.799 [0x14a379080b38] DEBUG - [HCl#2c] HTTP requesting GET https://plex.tv/api/v2/shared_sources/owned?machineIdentifier=1159a34fa47b49bad1e6c61df3514b4be0efb1a4
Dec 11, 2022 12:20:22.800 [0x14a37c564b38] WARN - [Req#98] Denying access due to session lacking permission to direct play part 74548
Dec 11, 2022 12:20:22.800 [0x14a37f34eb38] DEBUG - Completed: [106.69.43.141:55732] 503 GET /library/parts/74548/1582098521/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=209664 (7 live) TLS 8ms 319 bytes (pipelined: 9)
Dec 11, 2022 12:20:22.851 [0x14a37d19eb38] DEBUG - Request: [106.69.43.141:55732 (WAN)] GET /library/parts/74548/1582098521/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=209664 (7 live) #99 TLS Signed-in Token (lachie99) (SHIELD Android TV)
Dec 11, 2022 12:20:22.858 [0x14a37d19eb38] WARN - [Req#99] Denying access due to session lacking permission to direct play part 74548
Dec 11, 2022 12:20:22.859 [0x14a37f551b38] DEBUG - Completed: [106.69.43.141:55732] 503 GET /library/parts/74548/1582098521/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=209664 (7 live) TLS 7ms 319 bytes (pipelined: 10)
Dec 11, 2022 12:20:23.036 [0x14a37dbccb38] DEBUG - [HttpClient/HCl#2c] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/api/v2/shared_sources/owned?machineIdentifier=1159a34fa47b49bad1e6c61df3514b4be0efb1a4 (reused)
Dec 11, 2022 12:20:23.038 [0x14a379080b38] DEBUG - [HCl#2d] HTTP requesting GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx
Dec 11, 2022 12:20:23.308 [0x14a37dbccb38] DEBUG - [HttpClient/HCl#2d] HTTP/2.0 (0.3s) 200 response from GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx (reused)
Dec 11, 2022 12:20:23.312 [0x14a379080b38] DEBUG - MyPlex: updating with 16 access tokens

Req#94 and Req#98 are two different actions happening.

One is denied DirectPlay (on the player settings).

I do need logs please. PasteBin is not working for me.

You can delete them from the post after I get them -or- I will open a PM for you if desired.

7

Seems like I had to use Chrome to upload attachments, Firefox was producing an error.

Anyway here are a different set of log files, I have also included the Android TV logs to each, the timing might not exactly match because NTP doesn’t work on my unRAID machine.

Between each run I stopped PMS and deleted all the logs. I then started the server up and then the Android TV app, navigated to the movie and pressed play. The client settings are set to Original/Maximum Quality. I let the movie play for about 10 seconds before changing the quality to either 1080p 20Mbps or 720p 4Mbps. When I choose any 1080p option it will wait a couple seconds and then jump me to the finished watching screen but choosing any quality lower than 1080p will cause it to wait a couple seconds and then it would play the transcoded stream normally.

Plex Media Server Logs_2022-12-12_16-00-25 1080p.zip (306.0 KB)
Plex Media Server Logs_2022-12-12_16-10-24 720p.zip (326.6 KB)

8

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.