Server Version#: Version 1.29.1.6316
Player Version#: Roku 7.x
This recently started, I’m seeing an inability to play almost any title. When not playing, my rpi4 is sitting at about .08 cores. When playing, the cpu goes up to ~3.5, with all other services on the node. The stream breaks down within seconds, giving me a server not strong enough to play this title. Any help would be appreciated. I can provide fuller logs, below was of the logs prior to the crash.
Nov 04, 2022 20:55:07.952 [0x7f77171aa0] DEBUG - [Req#27c4] Play progress on 2052 ‘<media_title>’ - got played 102000 ms by account 1!
Nov 04, 2022 20:55:07.952 [0x7f77171aa0] DEBUG - [Req#27c4] [Now] User is (ID: 1)
Nov 04, 2022 20:55:07.953 [0x7f77171aa0] DEBUG - [Req#27c4] [Now] Device is Roku (Roku TV).
Nov 04, 2022 20:55:07.953 [0x7f77171aa0] DEBUG - [Req#27c4] [Now] Profile is Roku-7.x
Nov 04, 2022 20:55:07.953 [0x7f77171aa0] DEBUG - [Req#27c4] [Now] Updated play state for /library/metadata/2052.
Nov 04, 2022 20:55:07.953 [0x7f77171aa0] DEBUG - [Req#27c4] Statistics: (efde402f6b91a5c8a3ce09d0e426bddf) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Nov 04, 2022 20:55:07.979 [0x7f7b5a7aa0] DEBUG - Completed: [192.168.0.98:53625] 200 GET /:/timeline?playbackTime=40454&time=102000&state=playing&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&duration=6820081&playQueueItemID=1862 (4 live) TLS GZIP 72ms 802 bytes (pipelined: 16)
Nov 04, 2022 20:55:17.994 [0x7f76bc7aa0] DEBUG - Request: [192.168.0.98:53625 (Subnet)] GET /:/timeline?playbackTime=50543&time=113000&state=playing&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&duration=6820081&playQueueItemID=1862 (4 live) #27df TLS GZIP Signed-in Token () (Roku TV)
Nov 04, 2022 20:55:22.514 [0x7f76f6eaa0] DEBUG - [Req#27d4/Transcode/25835e1b-b6f2-4e95-a607-131843e39b36-69/3c808b89-d8af-477a-9ce1-eb782d255dcb] Transcoder segment range: 0 - 8 (8)
Nov 04, 2022 20:55:22.538 [0x7f77171aa0] DEBUG - [Req#27fc/Transcode/25835e1b-b6f2-4e95-a607-131843e39b36-69/3c808b89-d8af-477a-9ce1-eb782d255dcb] Transcoder segment range: 0 - 9 (8)
Nov 04, 2022 20:55:28.041 [0x7f769c4aa0] DEBUG - Request: [192.168.0.98:53647 (Subnet)] GET /:/timeline?playbackTime=60559&time=123000&state=playing&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&duration=6820081&playQueueItemID=1862 (5 live) #27fe TLS GZIP Signed-in Token () (Roku TV)
Nov 04, 2022 20:55:31.167 [0x7f76bc7aa0] DEBUG - [Req#27df] Client [efde402f6b91a5c8a3ce09d0e426bddf] reporting timeline state playing, progress of 113000/6820081ms for guid=, playbackTime=50543ms ratingKey=2052 url=, key=/library/metadata/2052, containerKey=, metadataId=2052, source=
Nov 04, 2022 20:55:31.207 [0x7f76bc7aa0] DEBUG - [Req#27df] Play progress on 2052 ‘<media_title>’ - got played 113000 ms by account 1!
Nov 04, 2022 20:55:31.207 [0x7f76bc7aa0] DEBUG - [Req#27df] [Now] User is (ID: 1)
Nov 04, 2022 20:55:31.207 [0x7f76bc7aa0] DEBUG - [Req#27df] [Now] Device is Roku (Roku TV).
Nov 04, 2022 20:55:31.207 [0x7f76bc7aa0] DEBUG - [Req#27df] [Now] Profile is Roku-7.x
Nov 04, 2022 20:55:31.207 [0x7f76bc7aa0] DEBUG - [Req#27df] [Now] Updated play state for /library/metadata/2052.
Nov 04, 2022 20:55:31.208 [0x7f76bc7aa0] DEBUG - [Req#27df] Statistics: (efde402f6b91a5c8a3ce09d0e426bddf) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Nov 04, 2022 20:55:31.228 [0x7f7b7aaaa0] DEBUG - Completed: [192.168.0.98:53625] 200 GET /:/timeline?playbackTime=50543&time=113000&state=playing&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&duration=6820081&playQueueItemID=1862 (5 live) TLS GZIP 13233ms 772 bytes (pipelined: 17)
Nov 04, 2022 20:55:32.153 [0x7f769c4aa0] DEBUG - [Req#27fe] Client [efde402f6b91a5c8a3ce09d0e426bddf] reporting timeline state playing, progress of 123000/6820081ms for guid=, playbackTime=60559ms ratingKey=2052 url=, key=/library/metadata/2052, containerKey=, metadataId=2052, source=
Nov 04, 2022 20:55:32.168 [0x7f769c4aa0] DEBUG - [Req#27fe] Play progress on 2052 ‘<media_title>’ - got played 123000 ms by account 1!
Nov 04, 2022 20:55:32.168 [0x7f769c4aa0] DEBUG - [Req#27fe] [Now] User is (ID: 1)
Nov 04, 2022 20:55:32.168 [0x7f769c4aa0] DEBUG - [Req#27fe] [Now] Device is Roku (Roku TV).
Nov 04, 2022 20:55:32.168 [0x7f769c4aa0] DEBUG - [Req#27fe] [Now] Profile is Roku-7.x
Nov 04, 2022 20:55:32.169 [0x7f769c4aa0] DEBUG - [Req#27fe] [Now] Updated play state for /library/metadata/2052.
Nov 04, 2022 20:55:32.169 [0x7f769c4aa0] DEBUG - [Req#27fe] Statistics: (efde402f6b91a5c8a3ce09d0e426bddf) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Nov 04, 2022 20:55:32.190 [0x7f7b5a7aa0] DEBUG - Completed: [192.168.0.98:53647] 200 GET /:/timeline?playbackTime=60559&time=123000&state=playing&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&duration=6820081&playQueueItemID=1862 (5 live) TLS GZIP 4149ms 772 bytes (pipelined: 1)
Nov 04, 2022 20:55:34.665 [0x7f76bc7aa0] DEBUG - Request: [192.168.0.98:53625 (Subnet)] GET /:/timeline?playbackTime=67202&time=128836&state=buffering&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&timeStalled=0&duration=6820081&playQueueItemID=1862 (5 live) #2813 TLS GZIP Signed-in Token () (Roku TV)
Nov 04, 2022 20:55:34.686 [0x7f76bc7aa0] DEBUG - [Req#2813] Client [efde402f6b91a5c8a3ce09d0e426bddf] reporting timeline state buffering, progress of 128836/6820081ms for guid=, playbackTime=67202ms ratingKey=2052 url=, key=/library/metadata/2052, containerKey=, metadataId=2052, source=
Nov 04, 2022 20:55:34.718 [0x7f76bc7aa0] DEBUG - [Req#2813] Play progress on 2052 ‘<media_title>’ - got played 128836 ms by account 1!
Nov 04, 2022 20:55:34.719 [0x7f76bc7aa0] DEBUG - [Req#2813] [Now] User is (ID: 1)
Nov 04, 2022 20:55:34.719 [0x7f76bc7aa0] DEBUG - [Req#2813] [Now] Device is Roku (Roku TV).
Nov 04, 2022 20:55:34.719 [0x7f76bc7aa0] DEBUG - [Req#2813] [Now] Profile is Roku-7.x
Nov 04, 2022 20:55:34.719 [0x7f76bc7aa0] DEBUG - [Req#2813] [Now] Updated play state for /library/metadata/2052.
Nov 04, 2022 20:55:34.719 [0x7f76bc7aa0] DEBUG - [Req#2813] Statistics: (efde402f6b91a5c8a3ce09d0e426bddf) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Nov 04, 2022 20:55:34.744 [0x7f7b5a7aa0] DEBUG - Completed: [192.168.0.98:53625] 200 GET /:/timeline?playbackTime=67202&time=128836&state=buffering&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&timeStalled=0&duration=6820081&playQueueItemID=1862 (5 live) TLS GZIP 78ms 773 bytes (pipelined: 18)
Nov 04, 2022 20:55:34.807 [0x7f77171aa0] DEBUG - [Req#280c/Transcode/25835e1b-b6f2-4e95-a607-131843e39b36-69/3c808b89-d8af-477a-9ce1-eb782d255dcb] Transcoder segment range: 0 - 9 (9)
Nov 04, 2022 20:55:34.826 [0x7f76f6eaa0] DEBUG - [Req#281c/Transcode/25835e1b-b6f2-4e95-a607-131843e39b36-69/3c808b89-d8af-477a-9ce1-eb782d255dcb] Transcoder segment range: 0 - 10 (9)
Nov 04, 2022 20:55:35.457 [0x7f77171aa0] DEBUG - Request: [192.168.0.98:53625 (Subnet)] GET /:/timeline?playbackTime=67202&time=128836&state=stopped&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&duration=6820081&playQueueItemID=1862 (5 live) #281b TLS GZIP Signed-in Token () (Roku TV)
Nov 04, 2022 20:55:35.464 [0x7f76f6eaa0] DEBUG - Request: [192.168.0.98:53647 (Subnet)] GET /video/:/transcode/universal/stop?session=25835e1b-b6f2-4e95-a607-131843e39b36-69 (5 live) #2815 TLS GZIP Signed-in Token () (Roku TV)
Nov 04, 2022 20:55:35.464 [0x7f78197aa0] DEBUG - [Req#2815/Transcode] Killing job.
Nov 04, 2022 20:55:35.464 [0x7f78197aa0] DEBUG - [Req#2815/Transcode] Signalling job ID 1097 with 9
Nov 04, 2022 20:55:35.464 [0x7f78197aa0] DEBUG - [Req#2815/Transcode] Job was already killed, not killing again.
Nov 04, 2022 20:55:35.464 [0x7f78197aa0] DEBUG - [Req#2815/Transcode] Stopping transcode session 25835e1b-b6f2-4e95-a607-131843e39b36-69
Nov 04, 2022 20:55:35.464 [0x7f75d52aa0] DEBUG - [Req#2815/Transcode] Cleaning directory for session 25835e1b-b6f2-4e95-a607-131843e39b36-69 (/config/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-25835e1b-b6f2-4e95-a607-131843e39b36-69-3c808b89-d8af-477a-9ce1-eb782d255dcb)
Nov 04, 2022 20:55:35.465 [0x7f7b5a7aa0] DEBUG - Completed: [192.168.0.98:53647] 200 GET /video/:/transcode/universal/stop?session=25835e1b-b6f2-4e95-a607-131843e39b36-69 (5 live) TLS GZIP 1ms 195 bytes (pipelined: 2)
Nov 04, 2022 20:55:35.480 [0x7f77171aa0] DEBUG - [Req#281b] Client [efde402f6b91a5c8a3ce09d0e426bddf] reporting timeline state stopped, progress of 128836/6820081ms for guid=, playbackTime=67202ms ratingKey=2052 url=, key=/library/metadata/2052, containerKey=, metadataId=2052, source=
Nov 04, 2022 20:55:35.485 [0x7f78197aa0] DEBUG - [Req#2815/Transcode] Transcoder: Cleaning old transcode directories.
Nov 04, 2022 20:55:35.491 [0x7f78197aa0] DEBUG - [Req#2815/Transcode] Transcoder: Cleaning old transcode directory: “/config/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-25835e1b-b6f2-4e95-a607-131843e39b36-69-3c808b89-d8af-477a-9ce1-eb782d255dcb”
Nov 04, 2022 20:55:35.495 [0x7f78197aa0] ERROR - [Req#2815/Transcode] Transcoder: Failed to delete session directory (boost::filesystem::remove: Resource busy: “/config/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-25835e1b-b6f2-4e95-a607-131843e39b36-69-3c808b89-d8af-477a-9ce1-eb782d255dcb/.nfs000000001c8b6f470000000f”)
Nov 04, 2022 20:55:35.495 [0x7f78197aa0] DEBUG - [Req#2815/Transcode] Whacked session 25835e1b-b6f2-4e95-a607-131843e39b36-69, 0 remaining.
Nov 04, 2022 20:55:35.498 [0x7f75d52aa0] ERROR - [Req#2815/Transcode] Failed to delete session directory (boost::filesystem::remove: Directory not empty: “/config/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-25835e1b-b6f2-4e95-a607-131843e39b36-69-3c808b89-d8af-477a-9ce1-eb782d255dcb”)
Nov 04, 2022 20:55:35.499 [0x7f75d52aa0] DEBUG - [Req#2815/Transcode] Deleting stale file “/tmp/pms-3bb5d1e9-1235-4633-b5a2-f7a4c7130d3c/EasyAudioEncoder/Convert to WAV (to 8ch or less)/25835e1b-b6f2-4e95-a607-131843e39b36-69_1097-0-167.tmp”
Nov 04, 2022 20:55:35.499 [0x7f75d52aa0] DEBUG - [Req#2815/Transcode] Deleting stale file “/tmp/pms-3bb5d1e9-1235-4633-b5a2-f7a4c7130d3c/EasyAudioEncoder/Convert to WAV (to 8ch or less)/25835e1b-b6f2-4e95-a607-131843e39b36-69_1097-0-167.mlp”
Nov 04, 2022 20:55:35.499 [0x7f75d52aa0] DEBUG - [Req#2815/Transcode] Deleting stale file “/tmp/pms-3bb5d1e9-1235-4633-b5a2-f7a4c7130d3c/EasyAudioEncoder/Convert to Dolby Digital Plus (Max Quality - 1024 kbps)/25835e1b-b6f2-4e95-a607-131843e39b36-69_1097-1-121.ec3”
Nov 04, 2022 20:55:35.499 [0x7f75d52aa0] DEBUG - [Req#2815/Transcode] Deleting stale file “/tmp/pms-3bb5d1e9-1235-4633-b5a2-f7a4c7130d3c/EasyAudioEncoder/Convert to Dolby Digital Plus (Max Quality - 1024 kbps)/25835e1b-b6f2-4e95-a607-131843e39b36-69_1097-1-121.wav”
Nov 04, 2022 20:55:35.529 [0x7f7b9e6aa0] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 1097 is -9 (signal: Killed)
Nov 04, 2022 20:55:35.529 [0x7f74b55aa0] DEBUG - Notifying consumer that data is complete.
Nov 04, 2022 20:55:35.530 [0x7f7516aaa0] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 16148539 bytes, m_closed=0, m_endOfFileReached=1, session->isStopped()=1
Nov 04, 2022 20:55:35.539 [0x7f77171aa0] DEBUG - [Req#281b] [Now] User is (ID: 1)
Nov 04, 2022 20:55:35.539 [0x7f77171aa0] DEBUG - [Req#281b] [Now] Device is Roku (Roku TV).
Nov 04, 2022 20:55:35.540 [0x7f77171aa0] DEBUG - [Req#281b] [Now] Profile is Roku-7.x
Nov 04, 2022 20:55:35.540 [0x7f77171aa0] DEBUG - [Req#281b] [Now] Updated play state for /library/metadata/2052.
Nov 04, 2022 20:55:35.564 [0x7f7b5a7aa0] DEBUG - [TranscodeOutputStream] Reached end of file
Nov 04, 2022 20:55:35.564 [0x7f7b5a7aa0] DEBUG - Removed transcode data consumer, active count 1 => 0
Nov 04, 2022 20:55:35.573 [0x7f7620eaa0] DEBUG - [Req#281b] Webhook: Delivering media.stop event by user (1) to 1 hooks.
Nov 04, 2022 20:55:35.575 [0x7f77171aa0] DEBUG - [Req#281b] Statistics: (efde402f6b91a5c8a3ce09d0e426bddf) Reporting active playback in state 3 of type 1 (scrobble: 0) for account 1
Nov 04, 2022 20:55:35.577 [0x7f77171aa0] DEBUG - [Req#281b] Cleaning directory for session 25835e1b-b6f2-4e95-a607-131843e39b36-69 (/config/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-25835e1b-b6f2-4e95-a607-131843e39b36-69-3c808b89-d8af-477a-9ce1-eb782d255dcb)
Nov 04, 2022 20:55:35.580 [0x7f758d1aa0] DEBUG - [Req#281b/HCl#f3] HTTP requesting POST https://prod-19.northcentralus.logic.azure.com:443/workflows/9a41852cfe004d0da9e52dbdb1f9e070/triggers/manual/paths/invoke?api-version=2016-10-01&sp=%2Ftriggers%2Fmanual%2Frun&sv=1.0&sig=eSPTTITD7MJ9hrp0vEeKx_YpXOZtglcKYRiMOEt4YPY
Nov 04, 2022 20:55:35.581 [0x7f77171aa0] DEBUG - [Req#281b] Streaming Resource: Terminating session 0x7f795acae8:efde402f6b91a5c8a3ce09d0e426bddf which is using transcoder slot. Used slots is now 0
Nov 04, 2022 20:55:35.581 [0x7f77171aa0] DEBUG - [Req#281b] Streaming Resource: Terminated session 0x7f795acae8:efde402f6b91a5c8a3ce09d0e426bddf with reason Client stopped playback.
Nov 04, 2022 20:55:35.581 [0x7f77171aa0] DEBUG - [Req#281b] Streaming Resource: Removing session 0x7f795acae8:efde402f6b91a5c8a3ce09d0e426bddf
Nov 04, 2022 20:55:35.592 [0x7f7b5a7aa0] DEBUG - Completed: [192.168.0.98:53625] 200 GET /:/timeline?playbackTime=67202&time=128836&state=stopped&ratingKey=2052&key=%2Flibrary%2Fmetadata%2F2052&col=3&row=1&context=source%3Ahub.movie.recentlyadded&duration=6820081&playQueueItemID=1862 (3 live) TLS GZIP 135ms 497 bytes (pipelined: 19)
Nov 04, 2022 20:55:35.969 [0x7f79800aa0] DEBUG - [HttpClient/HCl#f3] HTTP/2.0 (0.4s) 401 response from POST https://prod-19.northcentralus.logic.azure.com:443/workflows/9a41852cfe004d0da9e52dbdb1f9e070/triggers/manual/paths/invoke?api-version=2016-10-01&sp=%2Ftriggers%2Fmanual%2Frun&sv=1.0&sig=eSPTTITD7MJ9hrp0vEeKx_YpXOZtglcKYRiMOEt4YPY
Nov 04, 2022 20:55:35.969 [0x7f758d1aa0] WARN - [Req#281b] Webhook: Error delivering payload to https://prod-19.northcentralus.logic.azure.com:443/workflows/9a41852cfe004d0da9e52dbdb1f9e070/triggers/manual/paths/invoke?api-version=2016-10-01&sp=%2Ftriggers%2Fmanual%2Frun&sv=1.0&sig=eSPTTITD7MJ9hrp0vEeKx_YpXOZtglcKYRiMOEt4YPY: 401