search

fHDHR / fHDHR_plugin_origin_ceton

Do What The F*ck You Want To Public License
1 stars 4 forks source link

Stream Ended: Client has disconnected. #15

Closed JSylvia007 closed 3 years ago

JSylvia007 commented 3 years ago

So I've been away from watching TV, but I decided I actually wanted to tonight, and I've been running into a strange issue.

I believe I have updated everything, so I don't think I'm behind in versions of my plugins or fHDHR itself.

I use the Amazon FireTV Plex client, and after about 3 minutes, the below log happens, and it happens consistently between 2:50 and 3:40 minutes.

I'm not sure if this is a Plex issue or an fHDHR issue, as the last time I used fHDHR was a couple months ago.

EDIT: Note that I also tried the web interface for Plex and it did the exact same thing, so it's not the FireTV app. Maybe something changed in Plex?

Any insight?

[2021-10-23 19:22:53,192] INFO - Serving Chunk fHDHR/fHDHR#81: size 1152033
[2021-10-23 19:22:55,757] INFO - Serving Chunk fHDHR/fHDHR#82: size 1152033
[2021-10-23 19:22:55,837] INFO - Stream Ended: Client has disconnected.
[2021-10-23 19:22:55,839] INFO - Removing Tuner Lock
[2021-10-23 19:22:55,841] INFO - Tuner #0 Released.
[2021-10-23 19:22:55,843] INFO - Running ceton close_stream method.
[2021-10-23 19:22:55,846] INFO - Ceton tuner 0 to be stopped
[2021-10-23 19:22:56,017] INFO - 10.1.60.99 - - [2021-10-23 19:22:56] "GET /api/tuners?method=stream&channel=789&origin=ceton&stream_method=ffmpeg&accessed=http%3A//10.1.60.99%3A5004/hdhr/ceton/auto/v789 HTTP/1.1" 200 93315109 208.949447
deathbybandaid commented 3 years ago

@DanAustinGH might have thoughts, and I bet it's an issue connecting to ceton

DanAustinGH commented 3 years ago

The log suggests that Plex closed the stream. Can you use VLC to tune the same channel and see if it disconnects in the same way?

JSylvia007 commented 3 years ago

Interestingly enough, it doesnt make it as long when using VLC.

To find the channel, I clicked on channels on the fHDHR site, and used the link, for example:

https://fhdhr.mydomain.com/api/m3u?method=get&channel=2375e579-5cbe-4c61-9358-c97da04009ec&origin=ceton

And eventually (usually much shorter than was happening on Plex) it just stops playing, and the log indicates that chunks stop getting sent.

Is there a better way to tune the channel for VLC?

[2021-10-23 21:47:54,794] INFO - 10.1.60.99 - - [2021-10-23 21:47:54] "GET /api/m3u?method=get&channel=2375e579-5cbe-4c61-9358-c97da04009ec&origin=ceton HTTP/1.0" 200 2761 0.023711
[2021-10-23 21:47:54,832] INFO - Tuner #1 Acquired.
[2021-10-23 21:47:54,930] INFO - Selected Ceton tuner#: 1
[2021-10-23 21:47:54,933] INFO - Ceton tuner 1 to be started
[2021-10-23 21:47:55,158] INFO - Preparing Ceton tuner 1 on port: 44001
[2021-10-23 21:47:55,939] INFO - Initiate streaming channel 1410 from Ceton tuner#: 1
[2021-10-23 21:47:55,941] INFO - ceton Tuner #1 to be used for stream.
[2021-10-23 21:48:05,882] INFO - Serving Chunk #1: size 1152033
[2021-10-23 21:48:07,956] INFO - Serving Chunk #2: size 1152033
[2021-10-23 21:48:10,686] INFO - Serving Chunk #3: size 1152033
[2021-10-23 21:48:12,763] INFO - Serving Chunk #4: size 1152033
[2021-10-23 21:48:15,484] INFO - Serving Chunk #5: size 1152033
[2021-10-23 21:48:18,042] INFO - Serving Chunk #6: size 1152033
[2021-10-23 21:48:20,762] INFO - Serving Chunk #7: size 1152033
[2021-10-23 21:48:23,316] INFO - Serving Chunk #8: size 1152033
[2021-10-23 21:48:25,880] INFO - Serving Chunk #9: size 1152033
[2021-10-23 21:48:28,596] INFO - Serving Chunk #10: size 1152033
DanAustinGH commented 3 years ago

Not one that is as easy. You can use the Ceton web interface to tuner a channel and start a stream that you can then force VLC to connect to, but it is hacky and not worth the effort. Do you see an active tuner in fHDR's main status page or under the Tuners page?

Also please confirm the fhdr version and ceton plugin version. I have not updated in 2~3 months and do not see this issue. None of the changes in that time look like they would be related, but It would be interesting to check that.

JSylvia007 commented 3 years ago

Not one that is as easy. You can use the Ceton web interface to tuner a channel and start a stream that you can then force VLC to connect to, but it is hacky and not worth the effort. Do you see an active tuner in fHDR's main status page or under the Tuners page?

Also please confirm the fhdr version and ceton plugin version. I have not updated in 2~3 months and do not see this issue. None of the changes in that time look like they would be related, but It would be interesting to check that.

No, when this happens, the tuner closes properly. I initially thought that it always stopped at 84 segments, but multiple runs say that its anywhere from 70-84, but there are outliers.

Version Info:

Type | Name | Version | Online Version -- | -- | -- | -- fHDHR | fHDHR | v0.9.1-beta | v0.9.1-beta fHDHR | fHDHR_web | v0.9.1-beta | v0.9.1-beta env | CPU Type | x86_64 | N/A env | Docker | False | N/A env | Operating System | Linux | N/A env | Python | 3.8.10 (default, Sep 28 2021, 16:10:42) [GCC 9.3.0] | N/A env | Virtualenv | True | N/A env | ffmpeg | 4.4-1ubuntu0~20.04.sav0.1 | N/A plugin | fHDHR_plugin_interface_hdhr | v0.6.0-beta | v0.6.0-beta plugin | fHDHR_plugin_origin_ceton | v0.6.0-beta | v0.6.0-beta plugin | fHDHR_plugin_stream_ffmpeg | v0.6.0-beta | v0.6.0-beta
DanAustinGH commented 3 years ago

Can you run a test with DEBUG logging and post that? I will setup a new install with the same versions and see if I can reproduce it in the mean time.

JSylvia007 commented 3 years ago

Can you run a test with DEBUG logging and post that? I will setup a new install with the same versions and see if I can reproduce it in the mean time.

Absolutely. I'm on the road for work, but when I get to the hotel later tonight I will give it a shot. The wonders of VPN. Haha

deathbybandaid commented 3 years ago

The issue thread started with Client has disconnected.

Is it possible your VPN connection isn't as stable as you'd like?

JSylvia007 commented 3 years ago

Oh... No, I'm doing all the testing in-house. I only just left this morning. All actual servers and client are co-located on a 10Gig Unifi network. The network is definitely stable. Haha

Even when I VPN in, I'm still going to be then connecting to a local machine to actually perform the testing. VPN only gets my access, not for running the actual streaming.

DanAustinGH commented 3 years ago

Of course my dev system was doing a raid resync this am that slowed the channel import down (1 every 45 seconds, 3_ hours total). That system has the versions as you and I cannot get it to fail so far. Trying a mix of SD and HD channels...

JSylvia007 commented 3 years ago

So... I came home from my trip, and was greeted with "hey, there's an update to your Plex app on FireTV." I ran the update on Saturday night when I got home. And from that point, I couldn't get it to fail again. It worked beautifully, and continues to work beautifully... I changed literally nothing else.

STARTS TEARING HAIR OUT - GET IT TOGETHER PLEX!!!!

s66jones commented 3 years ago

I am running into the same problem with USTVGo, fHDHR, and Plex. I can pull up vlc steam and plex stream side by side; plex will stop but vlc keeps going. fHDHR logs show: Stream Ended: Client has disconnected and plex logs show Streaming Resource: Terminated session xxx with reason Client stopped playback.

Plex Logs:

Nov 11, 2021 18:12:42.530 [0x7f2a5f61eb38] DEBUG - [Now] Adding 0 sessions.
Nov 11, 2021 18:12:42.530 [0x7f2a5f61eb38] VERBOSE - It took 0.0 sec to serialize a list with 0 elements.
Nov 11, 2021 18:12:42.530 [0x7f2a61410b38] DEBUG - Completed: [172.16.32.57:23949] 200 GET /status/sessions (7 live) TLS GZIP 0ms 475 bytes (pipelined: 4)
Nov 11, 2021 18:12:42.559 [0x7f2a5fd6cb38] DEBUG - Request: [172.16.32.57:23949 (Subnet)] GET /:/timeline?ratingKey=30&key=%2Flivetv%2Fsessions%2Fc1843360-b04f-471c-acd0-68cc2b54fe38&playbackTime=180387&state=stopped&hasMDE=1&airingID=3&time=180000&duration=4294967296000 (7 live) TLS GZIP Signed-in Token (s66jones) / Accept => application/json,application/xml / Accept-Encoding => gzip, deflate, br / Accept-Language => en / Connection => keep-alive / Host => 172-16-32-100.e2acb92b82354fa69280ef22510b6d8a.plex.direct:32400 / Origin => https://app.plex.tv / Referer => https://app.plex.tv/ / Sec-Fetch-Dest => empty / Sec-Fetch-Mode => cors / Sec-Fetch-Site => cross-site / User-Agent => Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:94.0) Gecko/20100101 Firefox/94.0 / X-Plex-Client-Identifier => kh8nyn4ha9syhjqn927dnmof / X-Plex-Device => Windows / X-Plex-Device-Name => Firefox / X-Plex-Device-Screen-Resolution => 1783x906,1920x1080 / X-Plex-Drm => widevine / X-Plex-Features => external-media,indirect-media / X-Plex-Language => en / X-Plex-Model => hosted / X-Plex-Platform => Firefox / X-Plex-Platform-Version => 94.0 / X-Plex-Product => Plex Web / X-Plex-Provider-Version => 3.2 / X-Plex-Session-Identifier => 40h15jnxn9thvf5adbli19j8 / X-Plex-Sync-Version => 2 / X-Plex-Text-Format => plain / X-Plex-Token => xxxxxxxxxxxxxxxxxxxx / X-Plex-Version => 4.69.1
Nov 11, 2021 18:12:42.559 [0x7f2a5fd6cb38] WARN - Could not convert "duration" ("4294967296000") to the correct type
Nov 11, 2021 18:12:42.559 [0x7f2a61433b38] DEBUG - Completed: [172.16.32.57:23949] 400 GET /:/timeline?ratingKey=30&key=%2Flivetv%2Fsessions%2Fc1843360-b04f-471c-acd0-68cc2b54fe38&playbackTime=180387&state=stopped&hasMDE=1&airingID=3&time=180000&duration=4294967296000 (7 live) TLS GZIP 0ms 509 bytes (pipelined: 5)
Nov 11, 2021 18:12:42.911 [0x7f2a6053cb38] DEBUG - DVR:Segmenter: Stopping idle session: http://172.16.32.100:5004/hdhr/ustvgo/auto/v1.
Nov 11, 2021 18:12:44.157 [0x7f2a5fa7fb38] DEBUG - Subscription: Destroying rolling subscription session 40h15jnxn9thvf5adbli19j8 for channel 5fc770f3b63dc0002d1ea886-5fc70600a05ef8002e616464.
Nov 11, 2021 18:12:44.157 [0x7f2a5fa7fb38] DEBUG - Deleting media item 29.
Nov 11, 2021 18:12:44.158 [0x7f2a5fa7fb38] DEBUG - Was connected to metadata item 30, count is now 0.
Nov 11, 2021 18:12:44.159 [0x7f2a5fa7fb38] DEBUG - Destroying metadata item 30 (The Young and the Restless)
Nov 11, 2021 18:12:44.160 [0x7f2a5fa7fb38] VERBOSE - BPQ: onLibrarySectionChanged for library section -4: ItemsDeleted
Nov 11, 2021 18:12:44.161 [0x7f2a5fa7fb38] DEBUG - Transcoder: Cleaning old transcode directories.
Nov 11, 2021 18:12:44.161 [0x7f2a5fa7fb38] DEBUG - Whacked session c1843360-b04f-471c-acd0-68cc2b54fe38, 0 remaining.
Nov 11, 2021 18:12:44.161 [0x7f2a5fa7fb38] VERBOSE - [IDLE] Removing (1->0) work item transcoder - c1843360-b04f-471c-acd0-68cc2b54fe38
Nov 11, 2021 18:12:44.161 [0x7f2a5fa7fb38] VERBOSE - [IDLE] * http_download - /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1&X-Plex-Product=Plex%20Web&X-Plex-Version=4.63.0&X-Plex-Client-Identifier=oi6ruth3nocnylbdb2v4joa8&X-Plex-Platform=Firefox&X-Plex-Platform-Version=94.0&X-Plex-Sync-Version=2&X-Plex-Features=external-media%2Cindirect-media&X-Plex-Model=bundled&X-Plex-Device=Windows&X-Plex-Device-Name=Firefox&X-Plex-Device-Screen-Resolution=1783x906%2C1920x1080&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&X-Plex-Language=en - 1 active item(s)
Nov 11, 2021 18:12:44.161 [0x7f2a5fa7fb38] VERBOSE - [IDLE] * http_download - /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1&X-Plex-Product=Plex%20Web&X-Plex-Version=4.69.1&X-Plex-Client-Identifier=kh8nyn4ha9syhjqn927dnmof&X-Plex-Platform=Firefox&X-Plex-Platform-Version=94.0&X-Plex-Sync-Version=2&X-Plex-Features=external-media%2Cindirect-media&X-Plex-Model=hosted&X-Plex-Device=Windows&X-Plex-Device-Name=Firefox&X-Plex-Device-Screen-Resolution=1783x906%2C1920x1080&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&X-Plex-Language=en - 1 active item(s)
Nov 11, 2021 18:12:44.162 [0x7f2a5fa7fb38] DEBUG - Streaming Resource: Terminated session 0x7f2a60e9ac88:c1843360-b04f-471c-acd0-68cc2b54fe38 with reason Client stopped playback.
Nov 11, 2021 18:12:44.162 [0x7f2a5fa7fb38] DEBUG - Streaming Resource: Removing session 0x7f2a60e9ac88:c1843360-b04f-471c-acd0-68cc2b54fe38
Nov 11, 2021 18:12:45.933 [0x7f2a61433b38] VERBOSE - WebSocket: processed 1 frame(s)
Nov 11, 2021 18:12:50.486 [0x7f2a61410b38] VERBOSE - WebSocket: processed 1 frame(s)
deathbybandaid commented 3 years ago

Looks to be a problem with your plex end of things.

"Client has disconnected" and "Client stopped playback" mean the same thing. Your client is ending the stream, not fHDHR or PlexMediaServer

s66jones commented 3 years ago

I'm playing plex direct on the server. Is there any debugging I can do on the hdhr interface?

deathbybandaid commented 3 years ago

Not much. You can switch logging to debug, but that message should only show whenbyour client stops the stream.

s66jones commented 3 years ago

Thanks for your help. Looks like its an issue with the linux plex version. Stood up a windows plex server and am not seeing the issue.