Live TV regularly breaks when using Android app

Live TV & DVR
, , ,
1

I’ve been experiencing this issue for many months now, but only now have I gotten round to putting some effort in to debugging and reporting it.

I watch Live TV almost exclusively on my Nvidia Shield, running the Android Plex client. It will work fine when I first watch a channel, but 9 times out of 10 when I stop playback and switch to another channel I get the error “There was an error while attempting to tune the selected channel. Please check your connection and try again”. The channel I choose is not relevant. I am also able to consistently replicate this behaviour on my Android phone, however I cannot replicate it on the web app, so it seems likely to be triggered by the Android client.

If I try and watch something on the web app after I’ve triggered the error on Android, I get the same error on the web app .

Restarting the Plex server solves the problem until I change the channel again (this is what I’ve been doing for months now instead of actually solving the problem!).

Here’s an excerpt from the Plex logs when attempting to play a Live TV channel on the Android client:

Aug 03, 2021 22:52:41.694 [0x7fa4bf3e8b38] Debug — [Grabber/5fc76db4e3cd4a002dc5fc39-5fc705f4dd53a6002d8f9150-b81thz0zqilcorazebd136lx] Starting operation for 'Live TV - Session b81thz0zqilcorazebd136lx' on channel 5fc76db4e3cd4a002dc5fc39-5fc705f4dd53a6002d8f9150.
Aug 03, 2021 22:52:41.694 [0x7fa4bf3e8b38] Debug — [Grabber/5fc76db4e3cd4a002dc5fc39-5fc705f4dd53a6002d8f9150-b81thz0zqilcorazebd136lx] Activity: registered new activity b5a692d4-2106-439d-b181-d7d16b722300 - "Recording"
Aug 03, 2021 22:52:41.694 [0x7fa4bffb0b38] Debug — [Grabber/5fc76db4e3cd4a002dc5fc39-5fc705f4dd53a6002d8f9150-b81thz0zqilcorazebd136lx] HTTP requesting GET http://127.0.0.1:32600/devices/compound_device072dvb%23v4l%23%2fsys%2fdevices%2fpci0000%3a00%2f0000%3a00%3a14.0%2fusb3%2f3-4%2f3-4%3a1.0%3a0014109798
Aug 03, 2021 22:52:41.695 [0x7fa4bffb0b38] Error — [Grabber/5fc76db4e3cd4a002dc5fc39-5fc705f4dd53a6002d8f9150-b81thz0zqilcorazebd136lx] Error issuing curl_easy_perform(handle): 7
Aug 03, 2021 22:52:41.695 [0x7fa4bffb0b38] Warning — [Grabber/5fc76db4e3cd4a002dc5fc39-5fc705f4dd53a6002d8f9150-b81thz0zqilcorazebd136lx] HTTP error requesting GET http://127.0.0.1:32600/devices/compound_device072dvb%23v4l%23%2fsys%2fdevices%2fpci0000%3a00%2f0000%3a00%3a14.0%2fusb3%2f3-4%2f3-4%3a1.0%3a0014109798 (7, Couldn't connect to server) (Failed to connect to 127.0.0.1 port 32600: Connection refused)

Can anyone help me debug this issue? I’m happy to share more verbose logs if that will help.

Thanks in advance!

Server Version#: 1.23.6.4881 (Running in a docker container on Ubuntu 18.04)
Player Version#: 8.20.1.26670
Tuner Make/Model: WinTV-dualHD
Guide/Lineup name: Freeview UK
Using XMLTV?: No
Channel number/Name: Any

Edit: Since upgraded to Ubuntu 20.04, no improvement.

2

Found this in Plex Tuner Service.log around where the error occurs:

Aug 07, 2021 14:36:57.398 [0x7fdc57155848] INFO - [I] broker_t::start...
Aug 07, 2021 14:36:57.400 [0x7fdc57155848] INFO - [I] device_manager_t::init.
Aug 07, 2021 14:36:57.400 [0x7fdc57155848] INFO - [I] device_manager_t::init. Initialize provider manager
Aug 07, 2021 14:36:57.400 [0x7fdc57155848] INFO - [I] device_manager_t::init. Initialize all device auxes
Aug 07, 2021 14:36:57.400 [0x7fdc57155848] INFO - [I] dvb_device_factory_t::get_aux_list
Aug 07, 2021 14:36:57.401 [0x7fdc57155848] INFO - [I] tvbutler_aux_t::init
Aug 07, 2021 14:36:57.402 [0x7fdc57155848] INFO - [I] web_server_t::start. Starting web server on port 32600
Aug 07, 2021 14:36:57.402 [0x7fdc57155848] WARN - [E] web_server_t: bind: Address in use
Aug 07, 2021 14:36:57.402 [0x7fdc57155848] WARN - [E] web_server_t: port 32600 is not available
3

It is hard to tell from log excerpts, but it seems likely that your Plex Tuner Service process is either becoming unresponsive or crashing, but is not releasing port 32600. The tuner service log snippet you posted appears to show Plex attempting to restart the tuner service, but it isn’t able to allocate port 32600.

I also run on Linux, but bare metal, so I can’t provide any Docker specific insight. I wasn’t able to replicate the issue from my Android phone, but if this happened I would:

  • Look at older Plex Tuner Service logs (e.g. ‘Plex Tuner Service.1.log’, ‘Plex Tuner Service.2.log’, etc) to see if there is any additional detail about the process crashing/becoming unresponsive.

  • Look further back in your Plex Media Server logs to see if there is anything unusual after the successful tune and before the failed tune.

  • After the problem occurs, also try to identify the process that is hanging on to port 32600 by running either ‘sudo lsof -i :32600’ or ‘ps -ef | grep 32600’ from the command line. Most likely it will return the (presumably) zombie Plex Tuner Service, but it would be good to verify that some other process hasn’t grabbed that port.

4

Hi @hokierulz Thanks for the suggestions.

So I’ve just done some testing. I managed to play two different channels before it broke.

Immediately after launching the container, the output of lsof -i:32600 looks like this:

Plex\x20M 19117 jester   59u  IPv4 360665      0t0  TCP localhost:44136->localhost:32600 (ESTABLISHED)
Plex\x20T 19206 jester   10u  IPv4 159910      0t0  TCP localhost:32600 (LISTEN)
Plex\x20T 19206 jester   11u  IPv4 360666      0t0  TCP localhost:32600->localhost:44136 (ESTABLISHED)

While playing a LiveTV stream, the output was like this:

Plex\x20M 19117 jester   59u  IPv4 360665      0t0  TCP localhost:44136->localhost:32600 (ESTABLISHED)
Plex\x20T 19206 jester   10u  IPv4 159910      0t0  TCP localhost:32600 (LISTEN)
Plex\x20T 19206 jester   11u  IPv4 360666      0t0  TCP localhost:32600->localhost:44136 (ESTABLISHED)
Plex\x20T 19206 jester   13u  IPv4 360235      0t0  TCP localhost:32600->localhost:44220 (ESTABLISHED)
Plex\x20T 39829 jester    4u  IPv4 360870      0t0  TCP localhost:44220->localhost:32600 (ESTABLISHED)
Plex\x20T 39829 jester   59u  IPv4 360665      0t0  TCP localhost:44136->localhost:32600 (ESTABLISHED)

Once I’d stopped the playback the first time, the output of lsof -i :32600 returned to the first output above, during 2nd playback the output was similar to the 1st playback.

Once I’d stopped playback a second time, the output of lsof -i :32600 was empty, I presume this means there was now nothing listening on port 32600.

I’ve tried to isolate what I think is a playback that worked, and a playback that failed:
good.log (39.7 KB)
bad.log (22.7 KB)

I’ve had a look through the logs but not being too familiar with the inner workings of PMS I’m not sure I can fully diagnose what is going on myself. Would you mind taking a quick look through them when you have a chance?

Many thanks!

5

In the bad log I’m seeing indications your Plex Tuner Service isn’t running. Note the error that the connection is refused on port 32600:

Aug 07, 2021 19:34:55.086 [0x7f1c5d714b38] DEBUG - [Grabber/5fc76dbe55d518002ee72a85-5fc705d7104230002d14d500-e6054ff460216193-com-plexapp-android] HTTP requesting GET http://127.0.0.1:32600/devices/compound_device072dvb%23v4l%23%2fsys%2fdevices%2fpci0000%3a00%2f0000%3a00%3a14.0%2fusb3%2f3-4%2f3-4%3a1.0%3a0014109798
Aug 07, 2021 19:34:55.087 [0x7f1c5d714b38] ERROR - [Grabber/5fc76dbe55d518002ee72a85-5fc705d7104230002d14d500-e6054ff460216193-com-plexapp-android] Error issuing curl_easy_perform(handle): 7
Aug 07, 2021 19:34:55.087 [0x7f1c5d714b38] WARN - [Grabber/5fc76dbe55d518002ee72a85-5fc705d7104230002d14d500-e6054ff460216193-com-plexapp-android] HTTP error requesting GET http://127.0.0.1:32600/devices/compound_device072dvb%23v4l%23%2fsys%2fdevices%2fpci0000%3a00%2f0000%3a00%3a14.0%2fusb3%2f3-4%2f3-4%3a1.0%3a0014109798 (7, Couldn't connect to server) (Failed to connect to 127.0.0.1 port 32600: Connection refused)

Any chance you could post or DM your full debug level logs to me? If you want to investigate, we really need to look at the Plex Tuner Service logs both before and at the time of failure. The snipped you posted earlier suggests that Plex was trying to start the tuner service, but was not able to allocate port 32600 for some reason. I suspect your Plex Tuner Service is crashing but not releasing the port, but don’t have enough info to be sure. Then, if so, the big question is going to be finding why it is crashing.

Also if you want to investigate more, the lsof command I gave you actually just indicates that nothing is connected on 32600. Try “sudo netstat -tulpn | grep 32600” just after you have the tuning problem. If a process is listening on 32600, regardless of if there is a connection, it should show the listening process. For example, on my Plex server I ran this when no channels were being tuned and got:

tcp        0      0 127.0.0.1:32600         0.0.0.0:*               LISTEN      234581/Plex Tuner S

Which confirms that the Plex Tuner Service is running even when I’m not tuning a channel, and it is listening on 32600.
:

6

Thanks @hokierulz, I’ll DM you the full logs I took this morning.

I think you are correct in your assumption about the tuner service, netstat reports nothing listening on 32600 immediately prior to the tuning failure. In the logs I’m sending over it was again successful twice, but immediately after the 2nd playback the tuner service appears dead, and the 3rd playback attempt then fails.

7

@ChuckPa: Would you be able to suggest next steps for SuburbanMe, or who may be able to help? We switched to DM to exchange logs for security, and found that after a couple of channel tunes his tuner service is failing with a segfault, and then when it tries to restart the tuner service it fails because it can’t allocate port 32600. His implementation is Docker, and I’m unable to replicate using a direct install on Linux.

We can provide full logs via DM when we know the correct resource. Thank you in advance for your insight!

From the server logs when the tuner service stops:

Aug 08, 2021 07:58:26.213 [0x7f2ab44d7b38] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Tuner Service' exit code for process 436 is -11 (signal: Segmentation fault)

From the tuner service logs when it fails:

Aug 08, 2021 07:58:25.981 [0x7fb3754e0b38] INFO - [I] dvb_device_factory_t::get_device_list. Id dvb#v4l#0#/sys/devices/pci0000:00/0000:00:14.0/usb3/3-4/3-4:1.0:1, Name dualHD, Standards 3
Aug 08, 2021 07:58:25.989 [0x7fb3754e0b38] INFO - [I] device_manager_t::get_device_list. Device dualHD, id dvb#v4l#0#/sys/devices/pci0000:00/0000:00:14.0/usb3/3-4/3-4:1.0:0, tuners 1, state 2, standards 3
Aug 08, 2021 07:58:25.990 [0x7fb3754e0b38] INFO - [I] device_manager_t::get_device_list. Device dualHD, id dvb#v4l#0#/sys/devices/pci0000:00/0000:00:14.0/usb3/3-4/3-4:1.0:1, tuners 1, state 0, standards 3
Aug 08, 2021 07:58:25.993 [0x7fb3751d5b38] WARN - [E] http_streamer_t::handle_read: read_error: Connection reset by peer (104)
Aug 08, 2021 07:58:25.994 [0x7fb374fcfb38] WARN - [E] http_streamer_t: http write error
Aug 08, 2021 07:58:25.994 [0x7fb374794b38] INFO - [I] http_streamer_t::send_thread_func: removing http client
Aug 08, 2021 07:58:25.994 [0x7fb374794b38] INFO - [I] http_streamer_t::send_thread_func: all clients are deleted. Setting exit flag
Aug 08, 2021 07:58:26.003 [0x7fb374081b38] INFO - [I] streamer_container_t::control_thread. Removed disconnected streamer 938b32a6-f974-4c06-aece-3e2c828480fd
Aug 08, 2021 07:58:26.004 [0x7fb374081b38] INFO - [I] streamer_container_t::delete_streamer. Last streamer was deleted. Stop program streamer
Aug 08, 2021 07:58:26.004 [0x7fb374081b38] INFO - [I] dvb_program_streamer_t::stop. Stoping program streamer for channel triplet://9018:16516:17540
Aug 08, 2021 07:58:26.004 [0x7fb374081b38] INFO - [I] transponder_streamer::stop_channel. Stop request for channel triplet://9018:16516:17540
Aug 08, 2021 07:58:26.012 [0x7fb374186b38] INFO - [I] CTVSStreamSource::RemoveAllPids. Removing PIDs for client triplet://9018:16516:17540

Plex then realizes that the tuner service isn’t running and tries to start it again, but can’t allocate port 32600, presumably because the tuner service previously crashed without PID cleanup:

Aug 08, 2021 07:58:45.831 [0x7ff0bcf38b38] INFO - /usr/lib/plexmediaserver/Plex Tuner Service /usr/lib/plexmediaserver/Resources/Tuner/Private /usr/lib/plexmediaserver/Resources/Tuner/Shared 1.23.6.4881-e2e58f321 32600
Aug 08, 2021 07:58:45.830 [0x7ff0be2ff848] INFO - [I] broker_t::start...
Aug 08, 2021 07:58:45.833 [0x7ff0be2ff848] INFO - [I] device_manager_t::init.
Aug 08, 2021 07:58:45.833 [0x7ff0be2ff848] INFO - [I] device_manager_t::init. Initialize provider manager
Aug 08, 2021 07:58:45.833 [0x7ff0be2ff848] INFO - [I] device_manager_t::init. Initialize all device auxes
Aug 08, 2021 07:58:45.833 [0x7ff0be2ff848] INFO - [I] dvb_device_factory_t::get_aux_list
Aug 08, 2021 07:58:45.833 [0x7ff0be2ff848] INFO - [I] tvbutler_aux_t::init
Aug 08, 2021 07:58:45.834 [0x7ff0be2ff848] INFO - [I] web_server_t::start. Starting web server on port 32600
Aug 08, 2021 07:58:45.835 [0x7ff0be2ff848] WARN - [E] web_server_t: bind: Address in use
Aug 08, 2021 07:58:45.835 [0x7ff0be2ff848] WARN - [E] web_server_t: port 32600 is not available
1 Like
8

Yup, I’m seeing this too. Bumping this thread. My description and logs posted here: Playback Error and Tuner Service hang when changing to new channel in Live TV & DVR (tuner Segmentation Violation)

9

Over a month ago I was having my Live TV server lock up at random times. Everyting on the dashboard would stop working (unable to display statistics) and a forced restart would be necessary. I took all Android clients off my network and the issue automagically went away. Dunno if this is the same thing but I know the Android client is fubar.

10

Same problem here, but PMS is installed on bare metal (Arch Linux), I’m able to play Live TV only from the web interface, both Android tablet and mobile return the same error at the first try, and so does my Fire TV stick.

1 Like
11

The issue was solved for me recently by updating to PMS Version 1.24.1.4931. For the last day, changing channels no longer hangs the tuner.

12

I’m using 1.24.1.4931 and it is definitely still happening.

13

Withdrawn. It took longer than usual, but my tuner failed again when changing channels on Version 1.24.1.4931. I attached new logs to the post I made (linked above).

14

Yeah I’m on the 1.24.1.4931 version as well… using two HDHomeRun dual tuners… and running on a CentOS VM on an ESXi server in the basement. My main TV uses a Fire TV Stick to connect to the PLEX server. My RecordedTV library is a CIFS mount via the fstab at boot time. However, DVR programs and live TV recording (for time shifting) is local. The DVR programs are then moved over to that CIFS share once finished recording and commercials have been marked for skip.

I generally have to restart the plexmediaserver service once a day to get live TV working again. This afternoon when I attempted to tune a channel and it failed, I checked and port 32600 wasn’t open/listening, although ps shows the tuner service running. I did see log entries about being unable to bind to port 32600 as mentioned above in other posts.

The log this morning shows me tuning a channel successfully around 4:50am… Then I see this line about every 3-4 seconds from 4:51am until 6:45am:

Sep 03, 2021 06:42:30.227 [0x7f875ce85b38] INFO - [I] web_service_t::process_device_status

The next lines in the tuner log are these:

Sep 03, 2021 06:45:08.821 [0x7f875ce85b38] WARN - [E] http_streamer_t: http write error
Sep 03, 2021 06:45:08.821 [0x7f875c33bb38] INFO - [I] http_streamer_t::send_thread_func: removing http client
Sep 03, 2021 06:45:08.826 [0x7f875c33bb38] INFO - [I] http_streamer_t::send_thread_func: all clients are deleted. Setting exit flag
Sep 03, 2021 06:45:08.828 [0x7f875bbb3b38] INFO - [I] streamer_container_t::control_thread. Removed disconnected streamer e19bb267-789f-4d18-b4c2-dcc4628834fc
Sep 03, 2021 06:45:08.839 [0x7f875bbb3b38] INFO - [I] streamer_container_t::delete_streamer. Last streamer was deleted. Stop program streamer
Sep 03, 2021 06:45:08.840 [0x7f875bbb3b38] INFO - [I] dvb_program_streamer_t::stop. Stoping program streamer for channel triplet://0:3007:3
Sep 03, 2021 06:45:08.840 [0x7f875bbb3b38] INFO - [I] transponder_streamer::stop_channel. Stop request for channel triplet://0:3007:3
Sep 03, 2021 06:45:08.847 [0x7f875bcb6b38] INFO - [I] CTVSStreamSource::RemoveAllPids. Removing PIDs for client triplet://0:3007:3
Sep 03, 2021 06:45:08.847 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 0
Sep 03, 2021 06:45:08.848 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 1
Sep 03, 2021 06:45:08.849 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 16
Sep 03, 2021 06:45:08.850 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 17
Sep 03, 2021 06:45:08.851 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 18
Sep 03, 2021 06:45:08.851 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 48
Sep 03, 2021 06:45:08.852 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 49
Sep 03, 2021 06:45:08.853 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 52
Sep 03, 2021 06:45:08.853 [0x7f875bcb6b38] INFO - [I] HDHR delete_pid. Deleting pid 53
Sep 03, 2021 06:45:08.854 [0x7f875bbb3b38] INFO - [I] transponder_streamer::start_idle_timer
Sep 03, 2021 06:45:08.971 [0x7f875d293b38] WARN - [E] http_streamer_t::handle_read: read_error: Connection reset by peer (104)
Sep 03, 2021 06:45:08.972 [0x7f875d293b38] ERROR - Error. Received SIGSEGV: Segmentation Violation.

Edit: added code blocks for log entries…

15

Sane thing over here. Running PMS on Ubuntu 20.04.3
However I don’t think this issue is specific to Android clients only. I get this using the Windows client and Android clients.
Any resolution to this other then restarting the service every time this happens?

16

In this thread that appears to be the same problem the issue has been referenced to the Development team.

17

Any update on this from Plex?

18

I’m also waiting for a reply to many issues that have been posted. But sadly Plex seems to be looking for a buyer, and will never respond to someone who actually paid into their ecosystem. I’m sure I’m not the only one to regret my decision to buy in to the Lifetime plan…

1 Like
19

But sadly Plex seems to be looking for a buyer

Wait… What? Are they really? May I ask for a source? That could be potentially great news since I can’t imagine that new management could possibly be any worse than what they currently have.

20

No, they aren’t.

What I read from his comment is that they are looking to sell Plex passes and once you have done so they ignore you… which isn’t true.

Yes, getting traction on issues can be frustrating. Roku works good on the Live TV front. I stopped using Android over a year ago because the development team seems… not good…