Streaming stops after 94 minutes

Plex Media Server Desktops & Laptops
, ,
21

Thanks. that has what I needed.

Mar 17, 2019 18:12:05.985 [0x7f3f9e7ff700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 17, 2019 18:12:05.985 [0x7f3f677fe700] DEBUG - Request: [192.168.1.10:33261 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2136&time=5691149&duration=10664704 (10 live) GZIP Signed-in Token (BambiSlayer)
Mar 17, 2019 18:12:05.988 [0x7f3f677fe700] DEBUG - Client [y1ym91bwcex9a4ia4j0oa8me] reporting timeline state buffering, progress of 5691149/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 17, 2019 18:12:06.014 [0x7f3f677fe700] DEBUG - Play progress on 681 'Braveheart' - got played 5691149 ms by account 1!
Mar 17, 2019 18:12:06.015 [0x7f3f677fe700] DEBUG - [Now] User is BambiSlayer (ID: 1)
Mar 17, 2019 18:12:06.015 [0x7f3f677fe700] DEBUG - [Now] Device is Smart TV Alliance ().
Mar 17, 2019 18:12:06.015 [0x7f3f677fe700] DEBUG - [Now] Profile is HTML TV App
Mar 17, 2019 18:12:06.015 [0x7f3f677fe700] DEBUG - [Now] Updated play state for /library/metadata/681.
Mar 17, 2019 18:12:06.016 [0x7f3f677fe700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Mar 17, 2019 18:12:06.019 [0x7f3f9e7ff700] DEBUG - Completed: [192.168.1.10:33261] 200 GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2136&time=5691149&duration=10664704 (10 live) GZIP 33ms 818 bytes (pipelined: 1)
Mar 17, 2019 18:12:06.024 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 17, 2019 18:12:06.024 [0x7f3f913fd700] DEBUG - Request: [192.168.1.10:33261 (Subnet)] GET /transcode/sessions/5lpcyjv0sd8nz5mi1au95s1d (10 live) GZIP Signed-in Token (BambiSlayer)
Mar 17, 2019 18:12:06.026 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.10:33261] 200 GET /transcode/sessions/5lpcyjv0sd8nz5mi1au95s1d (10 live) GZIP 1ms 736 bytes (pipelined: 2)
Mar 17, 2019 18:12:10.652 [0x7f3f677fe700] DEBUG - Transcoder segment range: 0 - 5759
Mar 17, 2019 18:12:13.266 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 17, 2019 18:12:13.266 [0x7f3f5ebfe700] DEBUG - Request: [192.168.1.10:33261 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2136&time=5691149&duration=10664704 (9 live) GZIP Signed-in Token (BambiSlayer)
Mar 17, 2019 18:12:13.268 [0x7f3f5ebfe700] DEBUG - Client [y1ym91bwcex9a4ia4j0oa8me] reporting timeline state buffering, progress of 5691149/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 17, 2019 18:12:13.289 [0x7f3f5ebfe700] DEBUG - Play progress on 681 'Braveheart' - got played 5691149 ms by account 1!
Mar 17, 2019 18:12:13.289 [0x7f3f5ebfe700] DEBUG - [Now] User is BambiSlayer (ID: 1)
Mar 17, 2019 18:12:13.289 [0x7f3f5ebfe700] DEBUG - [Now] Device is Smart TV Alliance ().
Mar 17, 2019 18:12:13.289 [0x7f3f5ebfe700] DEBUG - [Now] Profile is HTML TV App
Mar 17, 2019 18:12:13.289 [0x7f3f5ebfe700] DEBUG - [Now] Updated play state for /library/metadata/681.
Mar 17, 2019 18:12:13.291 [0x7f3f5ebfe700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Mar 17, 2019 18:12:13.294 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.10:33261] 200 GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2136&time=5691149&duration=10664704 (9 live) GZIP 27ms 818 bytes (pipelined: 3)
Mar 17, 2019 18:12:13.494 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 17, 2019 18:12:13.495 [0x7f3f5cbfa700] DEBUG - Request: [192.168.1.10:33261 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=stopped&playQueueItemID=2136&time=5691149&duration=10664704 (9 live) GZIP Signed-in Token (BambiSlayer)
Mar 17, 2019 18:12:13.497 [0x7f3f5cbfa700] DEBUG - Client [y1ym91bwcex9a4ia4j0oa8me] reporting timeline state stopped, progress of 5691149/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 17, 2019 18:12:13.532 [0x7f3f5cbfa700] DEBUG - Play progress on 681 'Braveheart' - got played 5691149 ms by account 1!
Mar 17, 2019 18:12:13.534 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 17, 2019 18:12:13.534 [0x7f3f71bff700] DEBUG - Request: [192.168.1.10:59448 (Subnet)] GET /video/:/transcode/universal/stop?session=5lpcyjv0sd8nz5mi1au95s1d (10 live) GZIP Signed-in Token (BambiSlayer)
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Found session GUID of 5lpcyjv0sd8nz5mi1au95s1d in session start.
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Killing job.
Mar 17, 2019 18:12:13.535 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.10:59448] 200 GET /video/:/transcode/universal/stop?session=5lpcyjv0sd8nz5mi1au95s1d (10 live) GZIP 0ms 268 bytes (pipelined: 1)
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Signalling job ID 30143 with 9
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Job was already killed, not killing again.
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Stopping transcode session 5lpcyjv0sd8nz5mi1au95s1d
Mar 17, 2019 18:12:13.535 [0x7f3f5e3fd700] DEBUG - Cleaning directory for session 5lpcyjv0sd8nz5mi1au95s1d (/tmp/PMS/Transcode/Sessions/plex-transcode-5lpcyjv0sd8nz5mi1au95s1d-e4994f83-c26a-43d7-952f-807519644130)
Mar 17, 2019 18:12:13.545 [0x7f3f5cbfa700] DEBUG - It took 20.000000 ms to retrieve 110 items.
Mar 17, 2019 18:12:13.565 [0x7f3fa0fff700] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 30143 is -9 (signal: Killed)
Mar 17, 2019 18:12:13.577 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer

The Player reported “Stop” (Stopped message in the log) to Plex and so it stopped.

The only thing I know of which would make the app tell Plex to stop would be a lost connection,
Your logs appear to show the IP address changing. That will cause PMS to stop.

Mar 17, 2019 18:12:13.534 [0x7f3f71bff700] DEBUG - Request: [192.168.1.10:59448 (Subnet)] GET /video/:/transcode/universal/stop?session=5lpcyjv0sd8nz5mi1au95s1d (10 live) GZIP Signed-in Token (BambiSlayer)
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Found session GUID of 5lpcyjv0sd8nz5mi1au95s1d in session start.
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Killing job.
Mar 17, 2019 18:12:13.535 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.10:59448] 200 GET /video/:/transcode/universal/stop?session=5lpcyjv0sd8nz5mi1au95s1d (10 live) GZIP 0ms 268 bytes (pipelined: 1)
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Signalling job ID 30143 with 9
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Job was already killed, not killing again.
Mar 17, 2019 18:12:13.535 [0x7f3f5a3f5700] DEBUG - Stopping transcode session 5lpcyjv0sd8nz5mi1au95s1d
Mar 17, 2019 18:12:13.535 [0x7f3f5e3fd700] DEBUG - Cleaning directory for session 5lpcyjv0sd8nz5mi1au95s1d (/tmp/PMS/Transcode/Sessions/plex-transcode-5lpcyjv0sd8nz5mi1au95s1d-e4994f83-c26a-43d7-952f-807519644130)
Mar 17, 2019 18:12:13.545 [0x7f3f5cbfa700] DEBUG - It took 20.000000 ms to retrieve 110 items.
Mar 17, 2019 18:12:13.565 [0x7f3fa0fff700] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 30143 is -9 (signal: Killed)
Mar 17, 2019 18:12:13.577 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 17, 2019 18:12:13.577 [0x7f3f8f3ff700] DEBUG - Request: [192.168.1.215:63127 (Subnet)] GET /status/sessions (11 live) TLS GZIP Signed-in Token (BambiSlayer)
Mar 17, 2019 18:12:13.577 [0x7f3f8f3ff700] DEBUG - [Now] Adding 1 sessions.

Since it’s in a range normally assigned to DHCP, what is the DHCP minimum lease time in the DHCP server? what is maximum?

192.168.1.10 - becomes 192.168.1.215 ??

Is the TV static IP assigned (best)?

22

Apologies for the verbose logging on my previous upload. New logs attached and this time it only took about 16 minutes to repro the issue.

Obviously not an expert but I’ve had a quick look through the PMS log and can see things possibly start to go south around 14:17:56. There is a warning of “Excessive buffering detected; unknown”. Could this be relevant?

At 14:18:56 I see “Aborting playback while in buffering state” which is where it all seems to stop.

On the client I enabled Log to Media Server under Settings > Privacy but as I’m not sure where, or how, it logs I didn’t know what to look for.
Plex Media Server Logs_2019-03-17_14-24-45.zip (2.1 MB)

23

OK, so I set the IP of the TV to static and ran the test again with the same result. 94Minutes and 51 seconds.

Plex Media Server Logs_2019-03-18_14-36-32.zip (5.5 MB)

24

it’s not that… GRRRR
I continue to see this sequence:.

Transcoder progresses, sending data (notice the played duration & status) then it suddenly stops advancing as if the TV pauses.

Mar 18, 2019 14:27:34.967 [0x7f3f7b7fc700] DEBUG - Request: [192.168.1.210:39117 (Subnet)] GET /video/:/transcode/universal/session/3ledvco1i7j8m2t9chg5ti49/base/05696.ts (9 live) Signed-in
Mar 18, 2019 14:27:34.968 [0x7f3f7b7fc700] DEBUG - Asked for segment 5696 from session.
Mar 18, 2019 14:27:34.968 [0x7f3f7b7fc700] DEBUG - Returning segment 5696 from session: "/tmp/PMS/Transcode/Sessions/plex-transcode-3ledvco1i7j8m2t9chg5ti49-e2daa85d-c4a5-4b68-af3c-97990beddf04/media-05696.ts"
Mar 18, 2019 14:27:34.968 [0x7f3f7b7fc700] DEBUG - Content-Length of /tmp/PMS/Transcode/Sessions/plex-transcode-3ledvco1i7j8m2t9chg5ti49-e2daa85d-c4a5-4b68-af3c-97990beddf04/media-05696.ts is 847880.
Mar 18, 2019 14:27:34.970 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.210:39117] 200 GET /video/:/transcode/universal/session/3ledvco1i7j8m2t9chg5ti49/base/05696.ts (9 live) 2ms 847880 bytes (pipelined: 5697)
Mar 18, 2019 14:27:35.055 [0x7f3f9e7ff700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 18, 2019 14:27:35.055 [0x7f3f5bbf8700] DEBUG - Request: [192.168.1.210:18761 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=playing&playQueueItemID=2138&time=5690440&duration=10664704 (9 live) GZIP Signed-in Token (BambiSlayer)
Mar 18, 2019 14:27:35.057 [0x7f3f5bbf8700] DEBUG - Client [qudl8hhy20cw61orialtnmv6] reporting timeline state playing, progress of 5690440/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 18, 2019 14:27:35.080 [0x7f3f5bbf8700] DEBUG - Play progress on 681 'Braveheart' - got played 5690440 ms by account 1!
Mar 18, 2019 14:27:35.080 [0x7f3f5bbf8700] DEBUG - [Now] User is BambiSlayer (ID: 1)
Mar 18, 2019 14:27:35.080 [0x7f3f5bbf8700] DEBUG - [Now] Device is Smart TV Alliance ().
Mar 18, 2019 14:27:35.080 [0x7f3f5bbf8700] DEBUG - [Now] Profile is HTML TV App
Mar 18, 2019 14:27:35.081 [0x7f3f5bbf8700] DEBUG - [Now] Updated play state for /library/metadata/681.
Mar 18, 2019 14:27:35.081 [0x7f3f5bbf8700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Mar 18, 2019 14:27:35.084 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.210:18761] 200 GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=playing&playQueueItemID=2138&time=5690440&duration=10664704 (9 live) GZIP 29ms 817 bytes (pipelined: 573)
Mar 18, 2019 14:27:35.452 [0x7f3f9cfff700] DEBUG - Session 3ledvco1i7j8m2t9chg5ti49 (3) is unthrottling
Mar 18, 2019 14:27:35.454 [0x7f3f7bffd700] DEBUG - [Transcoder] Throttle - Getting back to work.
Mar 18, 2019 14:27:35.755 [0x7f3f59bf4700] DEBUG - Transcoder segment range: 0 - 5757
Mar 18, 2019 14:27:35.858 [0x7f3f5ebfe700] DEBUG - Session 3ledvco1i7j8m2t9chg5ti49 (3) is throttling
Mar 18, 2019 14:27:35.859 [0x7f3f5b3f7700] DEBUG - [Transcoder] Throttle - Going into sloth mode.
Mar 18, 2019 14:27:37.583 [0x7f3f9e7ff700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 18, 2019 14:27:37.583 [0x7f3f7b7fc700] DEBUG - Request: [192.168.1.210:18761 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2138&time=5690857&duration=10664704 (7 live) GZIP Signed-in Token (BambiSlayer)
Mar 18, 2019 14:27:37.586 [0x7f3f7b7fc700] DEBUG - Client [qudl8hhy20cw61orialtnmv6] reporting timeline state buffering, progress of 5690857/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 18, 2019 14:27:37.605 [0x7f3f7b7fc700] DEBUG - Play progress on 681 'Braveheart' - got played 5690857 ms by account 1!
Mar 18, 2019 14:27:37.605 [0x7f3f7b7fc700] DEBUG - [Now] User is BambiSlayer (ID: 1)
Mar 18, 2019 14:27:37.605 [0x7f3f7b7fc700] DEBUG - [Now] Device is Smart TV Alliance ().
Mar 18, 2019 14:27:37.605 [0x7f3f7b7fc700] DEBUG - [Now] Profile is HTML TV App
Mar 18, 2019 14:27:37.606 [0x7f3f7b7fc700] DEBUG - [Now] Updated play state for /library/metadata/681.
Mar 18, 2019 14:27:37.607 [0x7f3f9e7ff700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 18, 2019 14:27:37.607 [0x7f3f5bbf8700] DEBUG - Request: [192.168.1.210:34469 (Subnet)] GET /transcode/sessions/3ledvco1i7j8m2t9chg5ti49 (8 live) GZIP Signed-in Token (BambiSlayer)
Mar 18, 2019 14:27:37.607 [0x7f3f7b7fc700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Mar 18, 2019 14:27:37.608 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.210:34469] 200 GET /transcode/sessions/3ledvco1i7j8m2t9chg5ti49 (8 live) GZIP 1ms 734 bytes (pipelined: 1)
Mar 18, 2019 14:27:37.610 [0x7f3f9e7ff700] DEBUG - Completed: [192.168.1.210:18761] 200 GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2138&time=5690857&duration=10664704 (8 live) GZIP 26ms 815 bytes (pipelined: 574)
Mar 18, 2019 14:27:41.017 [0x7f3f5dbfc700] DEBUG - Transcoder segment range: 0 - 5758
Mar 18, 2019 14:27:45.061 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 18, 2019 14:27:45.061 [0x7f3f9f7ff700] DEBUG - Request: [192.168.1.210:18761 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2138&time=5690857&duration=10664704 (7 live) GZIP Signed-in Token (BambiSlayer)
Mar 18, 2019 14:27:45.064 [0x7f3f9f7ff700] DEBUG - Client [qudl8hhy20cw61orialtnmv6] reporting timeline state buffering, progress of 5690857/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 18, 2019 14:27:45.088 [0x7f3f9f7ff700] DEBUG - Play progress on 681 'Braveheart' - got played 5690857 ms by account 1!
Mar 18, 2019 14:27:45.088 [0x7f3f9f7ff700] DEBUG - [Now] User is BambiSlayer (ID: 1)
Mar 18, 2019 14:27:45.089 [0x7f3f9f7ff700] DEBUG - [Now] Device is Smart TV Alliance ().
Mar 18, 2019 14:27:45.089 [0x7f3f9f7ff700] DEBUG - [Now] Profile is HTML TV App
Mar 18, 2019 14:27:45.089 [0x7f3f9f7ff700] DEBUG - [Now] Updated play state for /library/metadata/681.
Mar 18, 2019 14:27:45.089 [0x7f3f9f7ff700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Mar 18, 2019 14:27:45.091 [0x7f3f9e7ff700] DEBUG - Completed: [192.168.1.210:18761] 200 GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2138&time=5690857&duration=10664704 (7 live) GZIP 30ms 816 bytes (pipelined: 575)
Mar 18, 2019 14:27:48.293 [0x7f3f59bf4700] DEBUG - Transcoder segment range: 0 - 5759
Mar 18, 2019 14:27:55.063 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 18, 2019 14:27:55.063 [0x7f3f9f7ff700] DEBUG - Request: [192.168.1.210:18761 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2138&time=5690857&duration=10664704 (7 live) GZIP Signed-in Token (BambiSlayer)
Mar 18, 2019 14:27:55.066 [0x7f3f9f7ff700] DEBUG - Client [qudl8hhy20cw61orialtnmv6] reporting timeline state buffering, progress of 5690857/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 18, 2019 14:27:55.090 [0x7f3f9f7ff700] DEBUG - Play progress on 681 'Braveheart' - got played 5690857 ms by account 1!
Mar 18, 2019 14:27:55.090 [0x7f3f9f7ff700] DEBUG - [Now] User is BambiSlayer (ID: 1)
Mar 18, 2019 14:27:55.090 [0x7f3f9f7ff700] DEBUG - [Now] Device is Smart TV Alliance ().
Mar 18, 2019 14:27:55.090 [0x7f3f9f7ff700] DEBUG - [Now] Profile is HTML TV App
Mar 18, 2019 14:27:55.090 [0x7f3f9f7ff700] DEBUG - [Now] Updated play state for /library/metadata/681.
Mar 18, 2019 14:27:55.091 [0x7f3f9f7ff700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Mar 18, 2019 14:27:55.092 [0x7f3f9dffe700] DEBUG - Completed: [192.168.1.210:18761] 200 GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2138&time=5690857&duration=10664704 (7 live) GZIP 29ms 818 bytes (pipelined: 576)
Mar 18, 2019 14:27:55.458 [0x7f3f677fe700] DEBUG - Statistics: Flushing 39 expired bandwidth entries, 0 expired media entries.
Mar 18, 2019 14:27:55.570 [0x7f3f5ebfe700] DEBUG - Transcoder segment range: 0 - 5760
Mar 18, 2019 14:28:02.759 [0x7f3f5dbfc700] DEBUG - Transcoder segment range: 0 - 5761
Mar 18, 2019 14:28:05.071 [0x7f3f9dffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Mar 18, 2019 14:28:05.071 [0x7f3f5ebfe700] DEBUG - Request: [192.168.1.210:18761 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=681&key=%2Flibrary%2Fmetadata%2F681&state=buffering&playQueueItemID=2138&time=5690857&duration=10664704 (7 live) GZIP Signed-in Token (BambiSlayer)
Mar 18, 2019 14:28:05.074 [0x7f3f5ebfe700] DEBUG - Client [qudl8hhy20cw61orialtnmv6] reporting timeline state buffering, progress of 5690857/10664704ms for guid=, ratingKey=681 url=, key=/library/metadata/681, containerKey=, metadataId=681, source=
Mar 18, 2019 14:28:05.097 [0x7f3f5ebfe700] DEBUG - Play progress on 681 'Braveheart' - got played 5690857 ms by account 1!

can this be repeated on ANYTHING else ?
Does that movie play file on other devices ?

25

Both of my smart TVs are Panasonic devices. and the exact same thing happens on both.

So here is exactly what I have done to test.

In the Plex App on the TV I set the video settings to not play direct to forck PMS to transcode. Bot TVs stop after 94:51

Then I change the settings in the App so it plays direct. The movie plays all the way through.

DLNA seems to play all the way through.

I am currently playing a movei on my S8 to see what happens. It is transcoding so I expect it to stop.

More to come.

Do you have any specific tests you would like me to do?

26

So just finished testing playing a movie on my phone. It finished as expected. Somewhat surprising. Maybe this is to do with the transcode resolution for the client. I’m starting to think to PMS serrver isn’t fast enough for transcoding for the smart TVs due to resolution. Bit of the stab in the dark.

Anyways, I’ve attached the logs from my last test with the modile phone as a client.

Plex Media Server Logs_2019-03-18_20-01-43.zip (5.7 MB)

27

FWIW, here is another example of a failure. Again bang on 1:34:51. I have a suspicion that the last time I saw this happen after 16 mins was maybe due to one of my sons watching a shorter film earlier in the day and the TV not being turned off in between me testing. This perhaps resulted in me seeing an early failure when the sum of both play times reached the 94:51 mark in total.

Plex Media Server Logs_2019-03-20_07-40-07.zip (2.5 MB)

I have a Mac Mini that I can hook up and try to see if I can repro on that too. Will try to do that today if I get chance.

Edit: I see there is a new server available, 1.15.1.791. Do shout if you want any testing of this new version.

28

This is so bizarre and I apologize as I cannot figure it out.

Would you be willing to conduct a “small” test ?

  1. Stop Plex
  2. As root: cd /var/lib/plexmediaserver and mv Library Libray.save (this saves your Library)
  3. Start Plex again
  4. Open it directly via IP and actually setup a new machine with 2 exceptions:
    a. Give this “TEST” server a unique name, like “TEST” so it does not collide with yoru main server
    b. Create the smallest library you can. If type movies (likely), only include a small group or one of your movie directories. Anything to keep it small.
  5. When it’s ready, Play the movie and see if it runs to completion
  6. If it does then you have a corruption unlike anything I’ve ever seen.
  7. If it does not, it’s time to start looking outside PMS at the machine or LAN.
29

Absolutely no need to apologise! Thanks for your continued efforts.

I’ve tried the above and unfortunately it’s the same result as before.

Plex Media Server Logs_2019-03-21_22-41-22.zip (1.1 MB)

I need to reset this config back to how it was so that the kids can use it in the morning. I’ll save this config so that I can go back to it again if needed.

If specifics of the environment and settings will help, let me know and I’ll document for you.

30

OK, so it stopped after doing what was suggested above.

Server: Toshiba Satelite L650 laptop with 8G RAM running Debian 9. I’m thinking its far to under powered even for a single transcoded session, although the hardware specs for PMS suggests otherwise.

I’m currently looking at an HP DL385 G7 2 x AMD 6274 16 core each cpu (totally 32 cores) with 64Gb RAM. Should be more than I need for 2 transcoded session at a time. Yes I will be putting Debian 9 on it again.

More to come when the new server arrives.

31

The L650’s CPU is a dual core i3. That will do two transcodes of audio but I would not press it for much more than a single video (lower bitrate at that)

32

I run on a RockPro64 which is a hexacore big.LITTLE architecture with 2xA72 and 4xA53 cores. My board has 4GB LPDDR4 RAM.
I’m under no illusions that this will not be able to transcode video and I do not try. There are plenty of people over on the Pine64 forums happily running Plex on these boards, all working to the realisation that as long as you don’t expect to transcode your video, you’ll be fine.

I only ever watch content within my home network and 99.9% of that is on the TV. The TV can direct stream video but seems to need to transcode audio. I’ve sat watching htop whilst a movie is playing and it barely breaks a sweat. It will use 100% of a single core for maybe 5 seconds and then sleep, then repeat. RAM usage by the entire system is rarely above 1.5GB even under load.

My most recent logs were for a library with a single movie in it but I’m struggling to see how the size of the library has anything to do with playback. I get that using a default setup is a good test, so maybe that’s what you were aiming for?

Worth noting in my setup is that the OS runs on an SD card. Whilst the Plex binaries are installed there I have added an override.conf to /etc/systemd/system/plexmediaserver.service.d so that the Library (and transcode directory) is stored on an SSD. This does all the heavy lifting and is directly attached via SATA (the board has a PCIe slot). Additionally, the content is stored on an external 2TB HDD connected via USB3.

I’ve ensured that the HDD is not sleeping, which I understand can be a problem with externally stored content.

I’m open to further suggestions so that I can keep working on resolving this and would appreciate some guidance on getting logs out of the client.

33

OK, so I’ve installed the new server.

HP Proliant DL385 G7 32CORES AMD 6274 2.20GHz 48GB 146GB 15K SAS

The drives containg the media are external 4T USB 3 drives and are connected to a USB 3 card installed in the server as all factory ports are USB 2

Streamimg still stops after 94 minutes and 51 seconds

So now I’m guessing as to what to look for.

IP is static on all servers and clients so I assume it has nothing to do with that.

I have hardwired all the TVs so it can’t be a wireless issue.

Let the games begin.

34

From the client (smart TV) I dissabled every timer or anything that could potentially stop the client.

I then played a movie untill it stopped.

Plex Media Server Logs_2019-03-25_09-30-54.zip (7.6 MB)

35

Personally I think this has got client issue written all over it. I’ve tried mucking about with profiles tonight but the changes I made don’t seem to do anything. I’m not editing the /Resources/Profiles files directly btw.

It seems my CX802b uses the HTML TV App profile, which doesn’t list any direct play video profiles like the other branded TV profiles do (Samsung etc.)

I also see that there is a Panasonic Viera 3D TV profile but I’m guessing the TV doesn’t announce itself or its capabilities to match this.

Is it possible for me to modify a copy of the HTML TV App profile to add further capability such as direct play?

36

Are you using the Plex App for smart TVs or DLNA?
I’m using the Plex App for smart TVs. If I use DLNA I don’t seem to have the problem. And I’m using the app because the DLNA menu is so cumbersome to navigate.

37

Yep, I use the Plex App. I did try using DLNA through the Media Player last night but as you say it’s cumbersome to say the least.

I also tried firing up my Mac Mini the other day and that worked flawlessly. That direct plays both video and audio, hence my thought around trying to get the TV direct playing via the profile settings.

The reason I still persist with the Plex App on the TV is that I have a ‘technologically challenged’ wife and 6 and 3 yr old boys. The missus and the elder can cope with getting to the content direct from the TV and it gives me the ability to filter content suitable for kids via a separate account. DLNA would be a complete non-starter for them and I’m not sure if you can filter non-kid-friendly content via that means. I also don’t want my son having direct access to the Mac Mini, so I don’t really see this as a solution either.

In some respects I’m hoping the v2 Plex App for Smart TVs magically fixes this, but with no word on when it’s likely to be released for Panasonic TVs, I’m not overly confident.

38

I wasn’t aware that using the App for smart TVs used the DLNA profiles we are so used to playing with. Part of the reason for me moving to the app is that I didn’t have to play around with DLNA profiles.

But I may be wrong. Hopefully someone with more knowledge on this will chime in.

39

I may be entirely wrong on this. I just kind of expected the clients to communicate what their capabilities were to the server. I saw the HTML profile in the log and made the jump. If those profiles are DLNA specific then I’m barking up the wrong tree.

What I tried last night was to copy the Panasonic profile to a Profile dir and rename it to the HTML profile. Fired up the client and tried to play a film and it gave me an error stating that there was no protocol for hls. The HTML profile has an entry for hls specifically, which made me think I was on the right track.
I then edited the original HTML file to include ac3, mp3 and pcm audio to see if I could get the audio direct streaming. This did not work, the film played but audio was still transcoded.

As you say, would be good if someone with knowledge of the clients could chime in so I know whether to continue or quit with this line of exploration.

I mentioned this issue over on the other thread, but don’t want to cross-post so just hoping one of the client guys over there drops in here.

40

I’ve just completed the following test.
Moved a movie to the internal drive on the server. Set the appropriate permissions and add the folder to my movie collection.

I did this because I thought the external USB drives I have my media on were to slow. And with the internal drive being a 15K drive it is certainly fast enough.

But the stream stopped again after 94 minutes and 51 seconds. So no change.

Two different servers so its not the server hardware.

The only thing between my server and the client is a 10/100/1000 TPLink switch. I dout it is the switch or anything on the network as the times are always the same.

When I do my tests I am only running a single session at a time to ensure sufficient resources and to eliminate conflict. And it makes things easier to find in the logs.

Any suggestions on what to look/test for would be most helpful.

Plex Media Server Logs_2019-03-26_08-44-01.zip (6.4 MB)