Apple TV app causing high CPU load on server

[Tommy_Hewitt]

Server Version#: 1.24.5.5173
Player Version#: 7.24

Hi guys!

First of all, I want to say that this is not about transcoding or something else that’s causing the high CPU load. It also happens when I direct play files and even when I’m only on the main page.

Over the last few weeks I’ve seen quite a strange behavior when I watch something on my Apple TV using the official Plex app. It strangely happens after I have finished a movie or an episode of a TV series and go back to the menu. Suddenly, out of nowhere the CPU ramps up to 100% and stays there until I force close the app. After I relaunch it and continue watching, everything’s back to normal for a while. This happens only occasionally, maybe one out of 20 playbacks.

Has anyone experienced something similar? This only happens when I’m using the Plex app on Apple TV. Watching on my iPad or via Plex Web everything’s totally fine.

[ChuckPa]

DEBUG log files please which capture the first 1 minute of playback when it does happen so we can see what is happening ?

[Tommy_Hewitt]

The next time it happens I’ll provide you with the log files. Unfortunately I forgot to note the time when it happend =/ I think it’s not useful to upload the full log files, is it?

Just to get clear: This does not only happen during playback but also after playback.

[ChuckPa]

It actually is useful to upload the logs ZIP because we never know if the playback is contained in 1 file or spans multiple.

[Tommy_Hewitt]

@ChuckPa Finally managed to get some more detailed information for you. This time it started as follows:

I was watching “The Hobbit” as suddenly playback stuttered a few times. A friend of mine texted me the same time that he was playing around with some subtitles the CPU couldn’t handle, so I asked him to close his app for a moment. Then the funny stuff started: Taking a look into Synology’s resource manager, Plex Media Server still caused >90% CPU-load without anything transcoding or playing at all.

Although my movie was still open (paused), nothing was shown inside the dashboard. After a while it resumed playback completely by itself and the movie reappeared inside the dashboard. I paused it again aaaaaaand it was gone once again within the dash.

I closed the movie and went back to the main page but CPU remained at 100%. I kept watching it for a few more minutes but nothing changed, so I force closed the app and everything went back to normal immediately.

This all happend between 19:24 and 19:30 (approximately), I’ve attached the log files for you

Plex Media Server Logs_2021-11-11_19-33-27.zip (4.8 MB)

Additionally, a guy with the same problem sent me a PM a few days ago:

I had the exact same issue with Apple TV, Plex server CPU would spike up and stay high for 15 to 20 mins randomly. I couldn’t reproduce with the same file but it would happen frequently enough for me to notice. I didn’t find anything useful in logs, I ended downgrading the sever version to fix it.

I run Plex server on docker on Linux, so it quick easy to roll back to 1.24.2.x. After rolling back, everything works and never saw this issue again. In my case the CPU spike from Apple TV was so bad that it would kill other streams as well. It only happens on Apple TV. This is definitely a major bug.

[ChuckPa]

@Tommy_Hewitt

Thank you for the logs.

The client is disconnecting from the server.

Nov 11, 2021 19:30:49.586 [0x7f06f1032b38] DEBUG - Audio Stream: 50440, Subtitle Stream: -1
Nov 11, 2021 19:30:49.588 [0x7f06fd579b38] DEBUG - [Transcode] MDE: analyzing media item 963
Nov 11, 2021 19:30:49.588 [0x7f06fd579b38] DEBUG - [Transcode] MDE: Der Hobbit - Die Schlacht der fünf Heere (2014): Direct Playing due to no transcode profile
Nov 11, 2021 19:30:49.588 [0x7f06fd579b38] DEBUG - [Transcode] MDE: Der Hobbit - Die Schlacht der fünf Heere (2014): DirectPlay
Nov 11, 2021 19:30:49.588 [0x7f06fd579b38] DEBUG - [Transcode] MDE: Der Hobbit - Die Schlacht der fünf Heere (2014): selected media 0 / 963
Nov 11, 2021 19:30:49.592 [0x7f06f1032b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:49.592 [0x7f06f1032b38] DEBUG - Selecting best audio stream for part ID 17933 (autoselect: 1 language: de)
Nov 11, 2021 19:30:49.593 [0x7f06f1032b38] DEBUG - Audio Stream: 51811, Subtitle Stream: -1
Nov 11, 2021 19:30:49.596 [0x7f0711629b38] DEBUG - It took 60.000000 ms to retrieve 70 items.
Nov 11, 2021 19:30:49.596 [0x7f06fd579b38] DEBUG - [Transcode] Streaming Resource: Reached Decision id=538 codes=(General=1000,Direct play OK. Direct Play=1000,Direct play OK.) media=(id=963 part=(id=17461 decision=direct play protocol=http streams=(Video=(id=49561 decision= width=1920 height=1080) Audio=(id=49563 decision= channels=6 rate=48000))))
Nov 11, 2021 19:30:49.597 [0x7f06fd579b38] WARN - Caught exception trying to convert extra data attribute 'originallyAvailableAt' with type 1 and value '2014-12-11' ~ bad lexical cast: source type value could not be interpreted as target
Nov 11, 2021 19:30:49.610 [0x7f06f7436b38] DEBUG - It took 80.000000 ms to retrieve 108 items.
Nov 11, 2021 19:30:49.612 [0x7f06f1032b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:49.612 [0x7f06f1032b38] DEBUG - Selecting best audio stream for part ID 17364 (autoselect: 1 language: de)
Nov 11, 2021 19:30:49.612 [0x7f06f1032b38] DEBUG - Audio Stream: 49093, Subtitle Stream: -1
Nov 11, 2021 19:30:49.618 [0x7f071283db38] DEBUG - Completed: [192.168.0.101:50654] 200 GET /video/:/transcode/universal/decision?advancedSubtitles=text&audioBoost=100&autoAdjustQuality=0&directPlay=1&directStream=1&directStreamAudio=1&location=lan&mediaBufferSize=20000&partIndex=0&path=%2Flibrary%2Fmetadata%2F538&protocol=hls&subtitleSize=100&subtitles=auto&videoQuality=100&videoResolution=4096x2160 (36 live) TLS GZIP 461ms 4582 bytes (pipelined: 4)
Nov 11, 2021 19:30:49.624 [0x7f0710681b38] DEBUG - It took 160.000000 ms to retrieve 170 items.
Nov 11, 2021 19:30:49.627 [0x7f0700a21b38] DEBUG - Request: [192.168.0.101:50654 (Subnet)] GET /library/metadata/538?asyncAugmentMetadata=0&checkFiles=1&includeChapters=1&includeConcerts=1&includeExternalMedia=1&includeExternalMetadata=1&includeExtras=1&includeGeolocation=1&includeMarkers=1&includeMeta=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=0&includeRelated=0&includeRelatedCount=15&includeReviews=1&includeUserState=1 (36 live) TLS GZIP Signed-in Token (Reinhard-Moser)
Nov 11, 2021 19:30:49.630 [0x7f0704321b38] DEBUG - It took 110.000000 ms to retrieve 117 items.
Nov 11, 2021 19:30:49.649 [0x7f06fd755b38] DEBUG - Request: [192.168.0.123:53553 (Subnet)] GET /statistics/bandwidth?timespan=6 (36 live) TLS GZIP Signed-in Token (Reinhard-Moser)
Nov 11, 2021 19:30:49.698 [0x7f06f7436b38] DEBUG - It took 140.000000 ms to retrieve 107 items.
Nov 11, 2021 19:30:49.702 [0x7f0710681b38] DEBUG - It took 120.000000 ms to retrieve 101 items.
Nov 11, 2021 19:30:49.705 [0x7f0712860b38] DEBUG - Failed to stream media, client probably disconnected after 178438144 bytes: 104 - Connection reset by peer
Nov 11, 2021 19:30:49.705 [0x7f0712860b38] DEBUG - Completed after connection close: [192.168.0.101:50688] 206 GET /library/parts/17461/1532460128/file.mkv (36 live) TLS 115844ms 178438144 bytes (range: bytes=5217951182-) 
Nov 11, 2021 19:30:49.708 [0x7f0711629b38] DEBUG - It took 60.000000 ms to retrieve 117 items.
Nov 11, 2021 19:30:49.719 [0x7f070c6f0b38] DEBUG - It took 3690.000000 ms to retrieve 119 items.
Nov 11, 2021 19:30:49.725 [0x7f0700a21b38] DEBUG - It took 160.000000 ms to retrieve 250 items.

Unable to replicate yet on AppleTV 4K with my self-ripped file.

The logs show me what appears to be a file with a lot of extra , possibly unnecessary, tracks in it. I keep my tracks to a minimum. I don’t keep languages - audio or subtitles I do not need.

Nov 11, 2021 19:30:05.616 [0x7f06fe4c6b38] DEBUG - Play progress on 538 'Der Hobbit - Die Schlacht der fünf Heere' - got played 7342382 ms by account 1!
Nov 11, 2021 19:30:05.617 [0x7f06fe4c6b38] DEBUG - [Now] User is Reinhard-Moser (ID: 1)
Nov 11, 2021 19:30:05.617 [0x7f06fe4c6b38] DEBUG - [Now] Device is tvOS (Reinhards Apple TV).
Nov 11, 2021 19:30:05.618 [0x7f06ecb88b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.618 [0x7f06ecb88b38] DEBUG - Selecting best audio stream for part ID 17586 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.618 [0x7f06ecb88b38] DEBUG - Audio Stream: 50173, Subtitle Stream: -1
Nov 11, 2021 19:30:05.618 [0x7f06fe4c6b38] DEBUG - [Now] Profile is tvOS
Nov 11, 2021 19:30:05.618 [0x7f06fe4c6b38] DEBUG - [Now] Updated play state for /library/metadata/538.
Nov 11, 2021 19:30:05.618 [0x7f06fe4c6b38] DEBUG - Statistics: (09DEA092-37C7-4E14-8A71-F137312D533C) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Nov 11, 2021 19:30:05.619 [0x7f070146fb38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.619 [0x7f070146fb38] DEBUG - Selecting best audio stream for part ID 17690 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.619 [0x7f070146fb38] DEBUG - Audio Stream: 50690, Subtitle Stream: -1
Nov 11, 2021 19:30:05.619 [0x7f07115d9b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.619 [0x7f07115d9b38] DEBUG - Selecting best audio stream for part ID 17683 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.619 [0x7f07115d9b38] DEBUG - Audio Stream: 50660, Subtitle Stream: -1
Nov 11, 2021 19:30:05.621 [0x7f06fd579b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.621 [0x7f06fd579b38] DEBUG - Selecting best audio stream for part ID 17666 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.621 [0x7f06fd579b38] DEBUG - Audio Stream: 50555, Subtitle Stream: -1
Nov 11, 2021 19:30:05.622 [0x7f06fc650b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.622 [0x7f06fc650b38] DEBUG - Selecting best audio stream for part ID 17447 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.622 [0x7f06fc650b38] DEBUG - Audio Stream: 49494, Subtitle Stream: -1
Nov 11, 2021 19:30:05.623 [0x7f06f78ecb38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.623 [0x7f06f78ecb38] DEBUG - Selecting best audio stream for part ID 17327 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.623 [0x7f06f78ecb38] DEBUG - Audio Stream: 48942, Subtitle Stream: -1
Nov 11, 2021 19:30:05.624 [0x7f06fe903b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.624 [0x7f06fe903b38] DEBUG - Selecting best audio stream for part ID 17659 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.624 [0x7f06fe903b38] DEBUG - Audio Stream: 50521, Subtitle Stream: -1
Nov 11, 2021 19:30:05.627 [0x7f0711629b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.627 [0x7f0711629b38] DEBUG - Selecting best audio stream for part ID 17462 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.628 [0x7f0711629b38] DEBUG - Audio Stream: 49568, Subtitle Stream: -1
Nov 11, 2021 19:30:05.629 [0x7f06f45fab38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.629 [0x7f06f45fab38] DEBUG - Selecting best audio stream for part ID 17879 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.629 [0x7f06f45fab38] DEBUG - Audio Stream: 51574, Subtitle Stream: -1
Nov 11, 2021 19:30:05.630 [0x7f07009d8b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.630 [0x7f07009d8b38] DEBUG - Selecting best audio stream for part ID 17380 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.630 [0x7f07009d8b38] DEBUG - Audio Stream: 49163, Subtitle Stream: -1
Nov 11, 2021 19:30:05.635 [0x7f06fd7c8b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.635 [0x7f06fd7c8b38] DEBUG - Selecting best audio stream for part ID 17816 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.635 [0x7f06fd7c8b38] DEBUG - Audio Stream: 51307, Subtitle Stream: -1
Nov 11, 2021 19:30:05.636 [0x7f06f1563b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.636 [0x7f06f1563b38] DEBUG - Selecting best audio stream for part ID 17443 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.636 [0x7f06f1563b38] DEBUG - Audio Stream: 49477, Subtitle Stream: -1
Nov 11, 2021 19:30:05.637 [0x7f06f7436b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.637 [0x7f06f7436b38] DEBUG - Selecting best audio stream for part ID 17704 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.637 [0x7f06f7436b38] DEBUG - Audio Stream: 50756, Subtitle Stream: -1
Nov 11, 2021 19:30:05.638 [0x7f06ff014b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.638 [0x7f06ff014b38] DEBUG - Selecting best audio stream for part ID 17538 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.638 [0x7f06ff014b38] DEBUG - Audio Stream: 49901, Subtitle Stream: -1
Nov 11, 2021 19:30:05.639 [0x7f0701492b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.639 [0x7f0701492b38] DEBUG - Selecting best audio stream for part ID 17704 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.639 [0x7f0701492b38] DEBUG - Audio Stream: 50756, Subtitle Stream: -1
Nov 11, 2021 19:30:05.641 [0x7f0710972b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.641 [0x7f0710972b38] DEBUG - Selecting best audio stream for part ID 17522 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.641 [0x7f0710972b38] DEBUG - Audio Stream: 49819, Subtitle Stream: -1
Nov 11, 2021 19:30:05.641 [0x7f070144cb38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.641 [0x7f070144cb38] DEBUG - Selecting best audio stream for part ID 17854 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.641 [0x7f070144cb38] DEBUG - Audio Stream: 51501, Subtitle Stream: -1
Nov 11, 2021 19:30:05.642 [0x7f0700a82b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.642 [0x7f0700a82b38] DEBUG - Selecting best audio stream for part ID 17826 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.642 [0x7f0700a82b38] DEBUG - Audio Stream: 51352, Subtitle Stream: -1
Nov 11, 2021 19:30:05.644 [0x7f0704885b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.644 [0x7f0704885b38] DEBUG - Selecting best audio stream for part ID 17887 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.644 [0x7f0704885b38] DEBUG - Audio Stream: 51609, Subtitle Stream: -1
Nov 11, 2021 19:30:05.645 [0x7f06eca06b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.645 [0x7f06eca06b38] DEBUG - Selecting best audio stream for part ID 17481 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.645 [0x7f06eca06b38] DEBUG - Audio Stream: 49660, Subtitle Stream: -1
Nov 11, 2021 19:30:05.646 [0x7f070fdb4b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.646 [0x7f070fdb4b38] DEBUG - Selecting best audio stream for part ID 17386 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.646 [0x7f070fdb4b38] DEBUG - Audio Stream: 49189, Subtitle Stream: -1
Nov 11, 2021 19:30:05.656 [0x7f06fd579b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.656 [0x7f06fd579b38] DEBUG - Selecting best audio stream for part ID 17784 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.656 [0x7f06fd579b38] DEBUG - Audio Stream: 51182, Subtitle Stream: -1
Nov 11, 2021 19:30:05.656 [0x7f070146fb38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.656 [0x7f070146fb38] DEBUG - Selecting best audio stream for part ID 17446 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.656 [0x7f070146fb38] DEBUG - Audio Stream: 49486, Subtitle Stream: -1
Nov 11, 2021 19:30:05.657 [0x7f070144cb38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.658 [0x7f070144cb38] DEBUG - Selecting best audio stream for part ID 17587 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.658 [0x7f070144cb38] DEBUG - Audio Stream: 50179, Subtitle Stream: -1
Nov 11, 2021 19:30:05.658 [0x7f0701492b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.658 [0x7f0701492b38] DEBUG - Selecting best audio stream for part ID 1950 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.658 [0x7f0701492b38] DEBUG - Audio Stream: 4795, Subtitle Stream: -1
Nov 11, 2021 19:30:05.659 [0x7f0700a82b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.659 [0x7f0700a82b38] DEBUG - Selecting best audio stream for part ID 1362 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.659 [0x7f0700a82b38] DEBUG - Audio Stream: 3312, Subtitle Stream: -1
Nov 11, 2021 19:30:05.662 [0x7f07009d8b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.662 [0x7f07009d8b38] DEBUG - Selecting best audio stream for part ID 17677 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.662 [0x7f07009d8b38] DEBUG - Audio Stream: 50622, Subtitle Stream: -1
Nov 11, 2021 19:30:05.666 [0x7f06f1032b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.666 [0x7f06f1032b38] DEBUG - Selecting best audio stream for part ID 17694 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.666 [0x7f06f1032b38] DEBUG - Audio Stream: 50705, Subtitle Stream: -1
Nov 11, 2021 19:30:05.666 [0x7f06eca06b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 11, 2021 19:30:05.666 [0x7f06eca06b38] DEBUG - Selecting best audio stream for part ID 17884 (autoselect: 1 language: de)
Nov 11, 2021 19:30:05.666 [0x7f06eca06b38] DEBUG - Audio Stream: 51594, Subtitle Stream: -1
Nov 11, 2021 19:30:05.670 [0x7f071283db38] DEBUG - Completed: [192.168.0.123:53534] 200 GET /statistics/bandwidth?timespan=6 (68 live) TLS GZIP 1407ms 2151 bytes (pipelined: 21)
Nov 11, 2021 19:30:05.672 [0x7f070c6f0b38] DEBUG - Request: [192.168.0.1:50623 (Subnet)] GET /library/metadata/538 (68 live) TLS GZIP Signed-in Token (Reinhard-Moser)
Nov 11, 2021 19:30:05.675 [0x7f06fe3e6b38] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 63 items.

May I see the XML (<media> through </media> tags) ?

I wonder if you have PGS, VOBSUB, or DVDRIP subtitles which aren’t necessary

[Tommy_Hewitt]

@ChuckPa Thanks for your help

The disconnections are interesting. It seems that they appeared mostly when the CPU load was that high, resulting in a broken pipe error.

Nov 11, 2021 19:24:36.904 [0x7f0712860b38] DEBUG - Failed to stream media, client probably disconnected after 49577984 bytes: 104 - Connection reset by peer
Nov 11, 2021 19:26:04.314 [0x7f071283db38] DEBUG - Failed to stream media, client probably disconnected after 190545920 bytes: 104 - Connection reset by peer
Nov 11, 2021 19:26:04.822 [0x7f071283db38] DEBUG - Failed to stream media, client probably disconnected after 1179648 bytes: 104 - Connection reset by peer
Nov 11, 2021 19:26:15.614 [0x7f071283db38] DEBUG - Failed to stream media, client probably disconnected after 16384 bytes: 32 - Broken pipe
Nov 11, 2021 19:26:42.163 [0x7f0712860b38] DEBUG - Failed to stream media, client probably disconnected after 65536 bytes: 32 - Broken pipe
Nov 11, 2021 19:26:42.166 [0x7f071283db38] DEBUG - Failed to stream media, client probably disconnected after 65536 bytes: 32 - Broken pipe
Nov 11, 2021 19:26:48.377 [0x7f0712860b38] DEBUG - Failed to stream media, client probably disconnected after 442368 bytes: 32 - Broken pipe
Nov 11, 2021 19:26:59.702 [0x7f0712860b38] DEBUG - Failed to stream media, client probably disconnected after 759570 bytes: 32 - Broken pipe
Nov 11, 2021 19:28:51.382 [0x7f071283db38] DEBUG - Failed to stream media, client probably disconnected after 178257920 bytes: 104 - Connection reset by peer
Nov 11, 2021 19:28:53.719 [0x7f0712860b38] DEBUG - Failed to stream media, client probably disconnected after 671744 bytes: 104 - Connection reset by peer

Now I wonder, are the disconnections the result of the high CPU load or ist the high CPU load caused by the disconnections? But why would a disconnected client cause that much strain for the CPU? Could it be that due to the high load the server can’t send out data fast enough and then the client looses connection?

I searched through the logs and there are quite a few disconnections like this…

Failed to stream media, client probably disconnected after 49577984 bytes: 104 - Connection reset by peer

…when someone was streaming remotely. Are those normal in this case because of mobile internet connections? No broken pipe in these cases.

Unable to replicate yet on AppleTV 4K with my self-ripped file.

The huge problem here is that I’m not able to replicate those problems at any time. The high CPU load only appears now and then regardless of the file playing or even not playing anything at all in the menu. Just started again the same file as yesterday and everything runs smooth with the CPU doing basically nothing:

Anyway, here is the XML for it. There are PGS-subs but I didn’t use them yesterday (and because I learned that they aren’t performing very well). Everything’s streamed directly.

<Media id="963" duration="9842560" bitrate="5656" width="1920" height="1080" aspectRatio="1.78" audioChannels="6" audioCodec="ac3" videoCodec="hevc" videoResolution="1080" container="mkv" videoFrameRate="24p" videoProfile="main">
<Part accessible="1" exists="1" id="17461" key="/library/parts/17461/1532460128/file.mkv" duration="9842560" file="/volume1/video/movies/Der Hobbit - Die Schlacht der fünf Heere (2014).mkv" size="6964765901" container="mkv" deepAnalysisVersion="6" indexes="sd" requiredBandwidths="11345,10303,9114,8073,7825,7596,6410,5699" videoProfile="main">
<Stream id="49561" streamType="1" default="1" codec="hevc" index="0" bitrate="4336" bitDepth="8" chromaLocation="left" chromaSubsampling="4:2:0" codedHeight="1080" codedWidth="1920" colorRange="tv" frameRate="23.976" height="1080" level="120" profile="main" refFrames="1" requiredBandwidths="10064,9005,7791,6761,6510,6281,5088,4385" scanType="progressive" width="1920" displayTitle="1080p (HEVC Main)" extendedDisplayTitle="1080p (HEVC Main)"> </Stream>
<Stream id="49562" streamType="2" codec="ac3" index="1" channels="6" bitrate="640" language="Englisch" languageTag="en" languageCode="eng" audioChannelLayout="5.1(side)" requiredBandwidths="640,640,640,640,640,640,640,640" samplingRate="48000" title="English" displayTitle="Englisch (AC3 5.1)" extendedDisplayTitle="English (AC3 5.1)"> </Stream>
<Stream id="49563" streamType="2" selected="1" default="1" codec="ac3" index="2" channels="6" bitrate="640" language="Deutsch" languageTag="de" languageCode="deu" audioChannelLayout="5.1(side)" requiredBandwidths="640,640,640,640,640,640,640,640" samplingRate="48000" title="German" displayTitle="Deutsch (AC3 5.1)" extendedDisplayTitle="German (Deutsch AC3 5.1)"> </Stream>
<Stream id="49564" streamType="3" codec="pgs" index="3" bitrate="18" language="Englisch" languageTag="en" languageCode="eng" requiredBandwidths="61,61,61,61,61,61,61,61" title="Complete" displayTitle="Englisch (PGS)" extendedDisplayTitle="Complete (Englisch PGS)"> </Stream>
<Stream id="49565" streamType="3" codec="pgs" index="4" bitrate="22" language="Deutsch" languageTag="de" languageCode="deu" requiredBandwidths="76,76,76,76,76,76,76,76" title="Complete" displayTitle="Deutsch (PGS)" extendedDisplayTitle="Complete (Deutsch PGS)"> </Stream>
</Part>
</Media>

[Tommy_Hewitt]

@ChuckPa Just happend again watching a tv series with direct play. Playback stopped for a few seconds and CPU ramped up to 100%. After a while, the stream completely broke down and I received the message Couldn’t create the playback session for this item.

I’ve attached the log files again. Stuttering started at 20:52 and the error message appeared at around 20:54.

Plex Media Server Logs_2021-11-17_20-55-08.zip (4.6 MB)

I’m still wondering if the disconnections are caused by a faulty network or the high CPU load. I did a little bit of testing the last few days and The Hobbit played fine multiple times without any disconnection-error or something else shown in the logs.

I also found out that quitting a movie midways and immediately returning to the main page results in 100% CPU load and it takes a few seconds to reload the posters and timeline of the corresponding movie.

Edit: Apple TV app has remained slow until it completely crashed now. After reopening it everything works quite fast again. There’s definitely something going on with the app itself.

[ChuckPa]

@Tommy_Hewitt

Sorry for the delay.

I’m playing now on the AppleTV (The Hobbit - Five Armies) and it’s not giving me any issues.

It’s converting the audio (which I expect). and the video (50+ Mbps) is direct stream.

Is your AppleTV wired or WiFi ? Mine is wired.

[Tommy_Hewitt]

Mine is wired too. The bitrate was only 2-3Mbps this time. All the problems seem to go away as long as i regularly close the Apple TV app completely. That problems only occur once in a week or so too. I’m still curious why Plex Media Server causing that much strain for the CPU. Even if my network connection should be wonky (which it isn’t, I can drag tons of data without any error over it), why this behavior every time?

[ChuckPa]

AppleTV 4K or the older one?

Which tvOS version?

[Tommy_Hewitt]

Huh, I forgot to mention that all the time, sry. It’s the 2021 ATV 4k with tvOS 15.1.1.

[Tommy_Hewitt]

To keep this thread alive: I reset the Apple TV to factory settings and set up everything from scratch, just to be sure everything is right. It worked nice and fast for a few days and then startet to slow down again, causing high CPU load when loading metadata-content. Opening libraries took a few seconds instead of loading instantly like in the beginning. Trying to delete a movie brought it down completely and it ran into a timeout. No playback involved this time, we were just browsing our library. After completely closing the app, reopening failed with only showing a grey screen and resulted in a crash. After that, everything went back to normal and now it’s working normal again.

It seems that the problems occur only after a few days when the app is being used quite a bit and kept open in the background.

[itsnotv]

I have the same issue since 1.24.3.5033, I was able to reproduce it with the latest 1.25.0.5282 build as well.

Randomly, the apple TV UI will hang, and when I check the server, the 4 dedicated xeon cores are running at 100%, the SSD is reading at 5000 IOPS, plex memory is up from 300 MB to 2 GB. Plex server eventually hangs after 20 mins and I have force kill it and restart it. I have enabled debug and verbose logs, there is nothing unusual that is printed in the logs when this happens, the logging almost stops once this is trigggered. This cannot be reproduced with the same file. But it is relatively easy to trigger by playing random files.

There is a definitely a major bug in the server that affects apple TV. I have seen such issues reported in reddit too. I am currently running 1.24.2.4973, every update after that is unusable because it takes only one apple tv to take down the entire server.

[Tommy_Hewitt]

Hey, thanks for your feedback Funnily enough it just happend here again a few minutes ago. Series buffered two times and CPU ramped up to 100% for a while.

There is definitely a connection with the running time of the app too. After force quitting the app, everything runs nice and fast again. Then after a few days and playbacks loading metadata, opening series etc. is getting slower and slower until it completely breaks down.

Which Apple TV do you own? A friend of mine has the 2017 version and has no problems at all streaming from my server. I use the 2021 model.

[itsnotv]

Apple TV(2021) 4K Plex App - Crashes PMS

Server Version#: Latest Player Version#: Latest I have been having this issue where sometimes when I try to watch someone on my Plex Server on my Apple TV 4K 2021 at the same location as the Plex Server, on the same network, the media begins by showing a loading screen, then says that the server is either offline or cannot be found, then I see the explanation marks on each media directories. When I then check the server(which is running on Windows 10(latest version) the Plex Media Seever ap…

Another user with similar issue with Apple TV.

[Tommy_Hewitt]

@itsnotv There’s definitely something strange going on. Can you answer me if you have a 2017 or 2021 Apple TV?

[itsnotv]

Apple TV 4K 2017, tvOS 15.1.

I don’t think this is a hardware issue. Nevertheless, a buggy plex client shouldn’t take down an entire server.

[ChuckPa]

I apologize for the delay. The forum isn’t notifying me as it should

My first questions will be regarding app settings.

• Subtitle handling set to automatic ? (auto allows the internal player to decide what’s best and do the handling if it can. Burn forces the CPU to burn the subtiles)

• Using the legacy or new player in the app ?

[Tommy_Hewitt]

@ChuckPa It’s set to auto, but no subtitles enabled at all when I watch something. I tried with both, old and new player. No difference.