Server Version#: 1.14.0.5470
Player Version#:3.13.21. Plex for smart TVs. Panasonic 50CX700
Streaming seams to stop after 94 minutes and 50 seconds. I get the 3 dots as if it is buffereing, but then it comes up and says it cannot find the media. If I exit the app and go back in and restart the movie from where it left off it plays again as normal from where it stopped.
It doesn’t seem to matter what device I play the movie from, or what movie I play, it always seems to stop at 94 minutes and 50 seconds.
I have changed from direct stream to transcode everything and it still does the same thing.
As I have no clue what I am ment to be looking for I thought I would ask here.
Not sure what other information you will need so here is the log before I restart the movie.
I see this in your logs. It looks like the client is dropping but I am not an app guy.
Dec 15, 2018 14:08:32.282 [0x7f419fffe700] VERBOSE - It took 0.0 sec to serialize a partial list with 25 elements (41 total).
Dec 15, 2018 14:08:32.287 [0x7f41beffe700] DEBUG - Completed: [192.168.1.5:60071] 200 GET /hubs/home/recentlyAdded?type=2 (13 live) TLS GZIP Page 16-50 103ms 9051 bytes (pipelined: 7)
Dec 15, 2018 14:08:32.762 [0x7f41bf7ff700] VERBOSE - WebSocket: processed 1 frame(s)
Dec 15, 2018 14:08:34.860 [0x7f41beffe700] VERBOSE - We didn't receive any data from 203.118.185.15:60060 in time, dropping connection.
Dec 15, 2018 14:08:34.860 [0x7f41beffe700] VERBOSE - We didn't receive any data from 203.118.185.15:60063 in time, dropping connection.
Dec 15, 2018 14:08:35.047 [0x7f41bf7ff700] VERBOSE - We didn't receive any data from 203.118.185.15:60072 in time, dropping connection.
Dec 15, 2018 14:08:35.120 [0x7f41bf7ff700] VERBOSE - WebSocket: processed 1 frame(s)
Dec 15, 2018 14:08:42.763 [0x7f41bf7ff700] VERBOSE - WebSocket: processed 1 frame(s)
Dec 15, 2018 14:08:45.123 [0x7f41bf7ff700] VERBOSE - WebSocket: processed 1 frame(s)
Dec 15, 2018 14:08:50.446 [0x7f41bf7ff700] DEBUG - WebSocket: client initiated close
Dec 15, 2018 14:08:50.446 [0x7f41bf7ff700] VERBOSE - WebSocket: processed 0 frame(s)
Dec 15, 2018 14:08:50.446 [0x7f41bf7ff700] DEBUG - handleStreamRead code 335544539: short read
Dec 15, 2018 14:08:50.446 [0x7f41bf7ff700] DEBUG - NotificationStream: Removing because of error
Dec 15, 2018 14:08:51.372 [0x7f41beffe700] VERBOSE - We didn't receive any data from 203.118.185.15:60070 in time, dropping connection.
Dec 15, 2018 14:08:52.073 [0x7f41beffe700] VERBOSE - We didn't receive any data from 192.168.1.5:60083 in time, dropping connection.
Dec 15, 2018 14:08:52.186 [0x7f41bf7ff700] VERBOSE - We didn't receive any data from 192.168.1.5:60081 in time, dropping connection.
Dec 15, 2018 14:08:52.228 [0x7f41beffe700] VERBOSE - We didn't receive any data from 192.168.1.5:60088 in time, dropping connection.
Dec 15, 2018 14:08:52.228 [0x7f41bf7ff700] VERBOSE - We didn't receive any data from 192.168.1.5:60089 in time, dropping connection.
Dec 15, 2018 14:08:52.287 [0x7f41beffe700] VERBOSE - We didn't receive any data from 192.168.1.5:60071 in time, dropping connection.
Dec 15, 2018 14:08:52.763 [0x7f41beffe700] VERBOSE - WebSocket: processed 1 frame(s)
I see where the players / devices “go away” and then reappear.
Are the devices using a DHCP server? What is its DHCP update interval?
It would not surprise me to find it’s 90 minutes then then the buffers draining and failure actually seen at 94 minutes.
Feb 02, 2019 16:54:19.622 [0x7f234a7f3700] DEBUG - Request: [192.168.1.5:12978 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (5 live) GZIP Signed-in Token (BambiSlayer)
Feb 02, 2019 16:54:19.623 [0x7f234a7f3700] DEBUG - Beginning read from two-way stream.
Feb 02, 2019 16:54:19.911 [0x7f23567ff700] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 21.999761 seconds: 192.168.1.1 (R8000 (Gateway))
Feb 02, 2019 16:54:19.911 [0x7f23567ff700] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 21.999872 seconds: 192.168.1.1 (WAN Device)
Feb 02, 2019 16:54:19.911 [0x7f23567ff700] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 21.999940 seconds: 192.168.1.1 (WAN Connection Device)
Feb 02, 2019 16:54:31.501 [0x7f2341bff700] DEBUG - Sync: uploadStatus
Feb 02, 2019 16:54:35.654 [0x7f23567ff700] DEBUG - Statistics: Flushing 3 expired bandwidth entries, 0 expired media entries.
Feb 02, 2019 16:54:39.623 [0x7f235c7ff700] DEBUG - handleStreamRead code 2: End of file
PMS re-discovers your router. This should never happen.
This only happens if the host has its IP dropped (as in a DHCP “renew”)
This made me start thinking of the Default DHCP Lease Time in the router.
If it is set to 5400 seconds then there is your 90 minutes exactly
You would want the unit of measure to be in days or minimally 86400 seconds (1 day)
Direct stream seems to run fine.
Transcoded media crashes after 94 minutes.
My test: Startrek Beyond (direct play) and The Huntsman (direct play) seems to run just fine.
The Horse Soldiers (transcoded) stopped after 94 minutes.
If you can reliably state that failure only occurs when media is transcoded, you have a problem with the system itself therefore please be absolutely certain of this statement as it takes diagnosis in a completely different direction.
OK, I’ve performed the following test.
Client: Panasonic 50DX700_SERIES using Plex App for smart TV’s ver 3.13.21.
Client is connected wirelessly to the network and is using static IP.
Played “The Horse Soldiers”. This file was transcoded. It stopped after 94 minutes.
Played “Star Trek Beyond”. This file played as direct and never stopped.
End of test. downloaded logs.
On my Panasonic 50CX700_SERIES (previous model to the unit above) all files play as transcoded and all stop after 94 minutes.
I will contact Panasonic in an attempt to find out why the 2 clients play the same media differently.
For the time being I am more concerned about resolving the issue with transcoded files stopping after 94 minutes.
Please let me know if you need further configuration details.
The attached file was downloaded shortly after star trek completed.
All smart TVs have the latest firmware installed.
Server: Linux mx 4.9.0-8-amd64 #1 SMP Debian 4.9.130-2 (2018-10-27) x86_64 GNU/Linux with all latest updates.
free -m
total used free shared buff/cache available
Mem: 7849 1723 177 70 5948 5802
Swap: 8052 0 8052
You’re not on your own. I see almost identical behaviour, although the timing seems to vary somewhat for me depending on the overall length of the film. It’s almost as if it gets to about 75% and just locks up.
I’m running Plex on a custom-built NAS (RockPro64 board) and using a Panasonic CX802b (2015). It’s deeply frustrating but I’ve been living with it as, like you, I do not know where to start looking. I’ve also not really had time to run any detailed tests and collect logs as if my kids aren’t using the TV, my wife is.
I am also running a Pihole which acts as my DHCP/DNS server for the network, all regular clients have static leases and the TV/NAS are both hard wired. DHCP lease is 24 hrs.
Everything is running the latest versions available and all OS patches/updates are installed regularly.
Plex Media Server v1.14.1.5488
Plex Media Player v3.13.21 Panasonic 55CX802b
Linux 5.0.0-1101-ayufan-g41eeb7cd789e #ayufan SMP PREEMPT Fri Mar 8 22:14:59 UTC 2019 aarch64 GNU/Linux
I’ll see about collecting logs next time I watch a movie and will post here to see if we can get to a resolution.
Well I have done further tests. And even resorted to hard wiring all my clients.
The fault only occures using the Plex App for smart TV’s as the fault does not seem to occure using DLNA. Oddly enough using the App is when transcoding occures and doesn’t seem to occure with DLNA.
For me it is extremely consistent at 94 minutes and 51 seconds regardless of movie length.
I have not tested using my mobile phone as a client yet.
But all the testing in the world is of absolutely no use unless you know what your looking for in the logs.
Currently I’m looking at replacing my server in an attempt to resolve this issue. Something I feel I shouldn’t have to resort to. But I feel there is a significant lack of support from Plex over this issue. And as a lifetime Plex Pass holder I feel a little miffed by that.
Heck I would even pay Plex to log into my server in an attempt to resolve the problem. But there seems to be no way of contacting Plex for paid support.
I see this when it ends, NO errors except a device timeout.
Feb 04, 2019 16:14:09.688 [0x7f60ffff3700] DEBUG - [Now] Updated play state for /library/metadata/8701.
Feb 04, 2019 16:14:09.689 [0x7f60ffff3700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Feb 04, 2019 16:14:09.691 [0x7f6120ffe700] DEBUG - Completed: [192.168.1.16:38989] 200 GET /:/timeline?hasMDE=1&ratingKey=8701&key=%2Flibrary%2Fmetadata%2F8701&state=buffering&playQueueItemID=8501&time=5685435&duration=7208288 (8 live) GZIP 29ms 828 bytes (pipelined: 2)
Feb 04, 2019 16:14:10.132 [0x7f6111bf8700] DEBUG - Statistics: Flushing 33 expired bandwidth entries, 0 expired media entries.
Feb 04, 2019 16:14:14.119 [0x7f6102ff9700] DEBUG - Transcoder segment range: 0 - 5761
Feb 04, 2019 16:14:19.666 [0x7f6120ffe700] DEBUG - Auth: authenticated user 1 as BambiSlayer
Feb 04, 2019 16:14:19.667 [0x7f61037fa700] DEBUG - Request: [192.168.1.16:38989 (Subnet)] GET /:/timeline?hasMDE=1&ratingKey=8701&key=%2Flibrary%2Fmetadata%2F8701&state=buffering&playQueueItemID=8501&time=5685435&duration=7208288 (7 live) GZIP Signed-in Token (BambiSlayer)
Feb 04, 2019 16:14:19.669 [0x7f61037fa700] DEBUG - Client [v8gce43mel0ltyb92c9g9ple] reporting timeline state buffering, progress of 5685435/7208288ms for guid=, ratingKey=8701 url=, key=/library/metadata/8701, containerKey=, metadataId=8701, source=
Feb 04, 2019 16:14:19.711 [0x7f61037fa700] DEBUG - Play progress on 8701 'The Horse Soldiers' - got played 5685435 ms by account 1!
Feb 04, 2019 16:14:19.711 [0x7f61037fa700] DEBUG - [Now] User is BambiSlayer (ID: 1)
Feb 04, 2019 16:14:19.711 [0x7f61037fa700] DEBUG - [Now] Device is Smart TV Alliance ().
Feb 04, 2019 16:14:19.712 [0x7f61037fa700] DEBUG - [Now] Profile is HTML TV App
Feb 04, 2019 16:14:19.712 [0x7f61037fa700] DEBUG - [Now] Updated play state for /library/metadata/8701.
Feb 04, 2019 16:14:19.712 [0x7f61037fa700] DEBUG - Statistics: (xlhlfisqb72xzuxrfzqpn3o6) Reporting active playback in state 2 of type 1 (scrobble: 0) for account 1
Feb 04, 2019 16:14:19.714 [0x7f6120ffe700] DEBUG - Completed: [192.168.1.16:38989] 200 GET /:/timeline?hasMDE=1&ratingKey=8701&key=%2Flibrary%2Fmetadata%2F8701&state=buffering&playQueueItemID=8501&time=5685435&duration=7208288 (7 live) GZIP 47ms 818 bytes (pipelined: 3)
Feb 04, 2019 16:14:21.366 [0x7f61007f4700] DEBUG - Transcoder segment range: 0 - 5762
Feb 04, 2019 16:14:22.114 [0x7f61183fe700] ERROR - Error issuing curl_easy_perform(handle): 28
Feb 04, 2019 16:14:22.114 [0x7f61183fe700] DEBUG - HTTP simulating 408 after curl timeout
Feb 04, 2019 16:14:22.114 [0x7f61183fe700] ERROR - SSDP: Error parsing device schema for http://192.168.1.12:52881/simplecfg.xml
Feb 04, 2019 16:14:22.114 [0x7f611e7fe700] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 23.617007 seconds: 192.168.1.2 (RX-V677 B6A29A)
Feb 04, 2019 16:14:22.114 [0x7f611e7fe700] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 24.486261 seconds: 192.168.1.3 (DMR-BWT720)
Feb 04, 2019 16:14:22.114 [0x7f611e7fe700] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 22.957775 seconds: 192.168.1.5 (Chromecast4109)
Here are some logs from my system. 1hr :34mins and change through when it failed (I’d never paid that much attention to it until now). I let it sit there until it fell back to a page stating that the media could not be played. Interestingly the Dashboard on PMS was showing as still playing at this point. I started playback again from where it stopped and then the Player crashed around 2 minutes later. Again, PMS showed as still playing on the dashboard.
Restart the player and resume the movie and it’s all ok again.
First, please go back and turn off VERBOSE logging. It is absolutely useless in this scenario.
DEBUG logging is the best. It allows me to see everything I need to see. Verbose is used for packet tracking.
Mar 16, 2019 21:22:12.913 [0xe5cfa400] VERBOSE - * Connection => close
Mar 16, 2019 21:22:12.913 [0xe5cfa400] VERBOSE - * Host => 127.0.0.1:32400
Mar 16, 2019 21:22:12.913 [0xe5cfa400] VERBOSE - * Icy-MetaData => 1
Mar 16, 2019 21:22:12.916 [0xe5cfa400] DEBUG - Transcoder segment range: 0 - 230
Mar 16, 2019 21:22:12.917 [0xf37ff400] DEBUG - Completed: [127.0.0.1:50798] 200 POST /video/:/transcode/session/sb4pjx7rz3nb3xr46y7q46gd/8ddc3a06-d2b0-4211-9e3c-ae4ba51ed738/seglist (18 live) 4ms 166 bytes
Mar 16, 2019 21:22:12.951 [0xf2ffe400] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Mar 16, 2019 21:22:12.951 [0xf2ffe400] DEBUG - Auth: authenticated user 1 as moebiusone
Mar 16, 2019 21:22:12.952 [0xf2ffe400] VERBOSE - Auth: Came in with a super-token, authorization succeeded.
Mar 16, 2019 21:22:12.952 [0xe0cff400] DEBUG - Request: [192.168.1.4:33538 (Subnet)] GET /diagnostics/logs (19 live) TLS GZIP Signed-in Token (moebiusone)
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * Host => 192-168-1-2.d6ff2b41fbb14e1284c93cc13025141c.plex.direct:32400
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * Connection => keep-alive
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * Upgrade-Insecure-Requests => 1
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * User-Agent => Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.75 Safari/537.36
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * Accept => text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * Referer => https://app.plex.tv/
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * Accept-Encoding => gzip, deflate, br
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * Accept-Language => en-GB,en;q=0.9
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * DNT => 1
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Mar 16, 2019 21:22:12.952 [0xe0cff400] VERBOSE - * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Mar 16, 2019 21:22:12.953 [0xe0cff400] DEBUG - Diagnostics: Building logfile zip```
