[mythtv-users] "Error opening jump program file" when switching tuners: is this a known problem and did I really fix it?

[David Lasker]

Reposting with a more accurate subject line in hope of getting a response.

Thanks...

Dave

-----Original Message-----
From: David Lasker [mailto:dave at altosdesign.com] 
Sent: Wednesday, July 14, 2010 4:02 PM
To: mythtv-users at mythtv.org
Cc: dave at altosdesign.com
Subject: hang when switching tuners: is this a known problem and did I
really fix it?

I am just getting started with MythTV. I am using mythbuntu 0.23+fixes
(Ubuntu 10.04). My display adapter is an Intel G43/X4500 GPU (no VDPAU). The
CPU
is an Intel E6300 (2.8Ghz) which runs at under 30% capacity, using the CPU+
profile.

I have a combined FE/BE with 2 TV tuner cards:

1) Hauppauge HVR-1250 with 1 digital tuner
2) Hauppauge HVR-1600 with 1 analog and 1 digital tuner

So I have a total of 2 digital + 1 analog tuners. The HVR-1250 has the
highest priority. I have 2 video sources: "digital" and "analog".

I scanned for digital channels using the HVR-1250.

When I first set up the system, I could watch digital TV on the HVR-1250 and
analog TV on the HVR-1600 just fine. But when I tried to switch to the 
HVR-1600's digital tuner, the front-end would fail with a pop-up dialog: 

"Error opening jump program file"

Once this happened, I couldn't start "Watch TV" without getting that error.
I had to kill and restart the FE and BE to watch TV again. I'm not sure if
the
backend was working and retrying the failed tuner, or if it was hung.

In order to diagnose the problem, I temporarily removed the HVR-1250 from
the "digital" video source, thus forcing the HVR-1600's digital tuner to be
used. It worked just fine. So I added the HVR-1250 back into the "digital"
video source.

At this point everything worked fine...the problem had gone away.

I am thinking that maybe something wasn't initialized correctly for the
HVR-1600's digital tuner, and forcing it be used fixed that?

Here are the logs from when the problem occurred. I Googled for all the
suspicious entries in the FE log, and got lots of hits, but nothing I found
sounded like my problem. The BE log looks clean to me. However, it looks
like the FE may have timed out before the BE finished starting the other
tuner. Is the NVP prebuffer wait timeout something I can (or should)
configure to make longer?

I saw some posts that blame some of the errors in my FE log on insufficient
CPU capacity. I don't think that is the problem, because my system was
failing 100% of the time in dozens of tests before my workaround, including
after several reboots, and has now worked 100% of the time in dozens of
tests afterward.

Has anyone seen this before? If it happens again, is there anything else I
should look for or try?

FE log:

2010-07-14 11:27:30.933 NVP(0): prebuffering pause
2010-07-14 11:27:31.474
RingBuf(/var/lib/mythtv/livetv/3071_20100714112317.mpg): Waited 1.0 seconds
for data to become available...
2010-07-14 11:27:31.474 Checking to see if there's a new livetv program to
switch to..
2010-07-14 11:27:31.609 NVP(0): Prebuffer wait timed out 10 times.
2010-07-14 11:27:32.291 NVP(0): Prebuffer wait timed out 20 times.
2010-07-14 11:27:32.475
RingBuf(/var/lib/mythtv/livetv/3071_20100714112317.mpg): Waited 2.0 seconds
for data to become available...
2010-07-14 11:27:32.475 Checking to see if there's a new livetv program to
switch to..
2010-07-14 11:27:32.956 NVP(0): Prebuffer wait timed out 30 times.
2010-07-14 11:27:33.622 NVP(0): Prebuffer wait timed out 40 times.
2010-07-14 11:27:34.287 NVP(0): Prebuffer wait timed out 50 times.
2010-07-14 11:27:34.476
RingBuf(/var/lib/mythtv/livetv/3071_20100714112317.mpg): Waited 4.0 seconds
for data to become available...
2010-07-14 11:27:34.477 Checking to see if there's a new livetv program to
switch to..
2010-07-14 11:27:34.952 NVP(0): Prebuffer wait timed out 60 times.
2010-07-14 11:27:35.617 NVP(0): Prebuffer wait timed out 70 times.
2010-07-14 11:27:36.283 NVP(0): Prebuffer wait timed out 80 times.
2010-07-14 11:27:36.965 NVP(0): Prebuffer wait timed out 90 times.
2010-07-14 11:27:37.630 NVP(0): Prebuffer wait timed out 100 times.
2010-07-14 11:27:37.630 NVP(0), Error: Timed out waiting for prebuffering
too long. Exiting..
2010-07-14 11:27:37.770 TV: Attempting to change from WatchingLiveTV to None
2010-07-14 11:27:38.583 TV: Changing from WatchingLiveTV to None
2010-07-14 11:27:38.604 TV: Attempting to change from None to None
2010-07-14 11:27:38.629 TV: Attempting to change from None to WatchingLiveTV
2010-07-14 11:27:38.629 MythContext: Connecting to backend server:
127.0.0.1:6543 (try 1 of 1)
2010-07-14 11:27:38.630 Using protocol version 56
2010-07-14 11:27:38.653 Spawning LiveTV Recorder -- begin
2010-07-14 11:27:38.701 Spawning LiveTV Recorder -- end
2010-07-14 11:27:38.705 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112738.mpg'
2010-07-14 11:27:38.707 We have a
playbackURL(/var/lib/mythtv/livetv/3071_20100714112738.mpg) &
cardtype(DUMMY)
2010-07-14 11:27:38.708 We have a RingBuffer
2010-07-14 11:27:38.760 playCtx, Error: Attempting to setup a player, but it
already exists.
2010-07-14 11:27:38.760 TV Error: LiveTV not successfully started

BE log:

2010-07-14 11:27:35.224 Error: offset>181, pes length & current can not be
queried
2010-07-14 11:27:37.820 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112317.mpg'
2010-07-14 11:27:37.837 TVRec(5): Changing from WatchingLiveTV to None
2010-07-14 11:27:37.851 ProgramInfo(3071_20100714112317.mpg): Recording
designated 720p because width was 1280
2010-07-14 11:27:37.913 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112317.mpg'
2010-07-14 11:27:38.546 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112317.mpg'
2010-07-14 11:27:38.571 Finished recording ABC 7 News at 11:00AM: channel
3071
2010-07-14 11:27:38.596 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112317.mpg'
2010-07-14 11:27:38.630 MainServer::ANN Playback
2010-07-14 11:27:38.641 adding: mythtv as a client (events: 0)
2010-07-14 11:27:38.655 TVRec(5): Changing from None to WatchingLiveTV
2010-07-14 11:27:38.668 TVRec(5): HW Tuner: 5->5
2010-07-14 11:27:38.704 AutoExpire: CalcParams(): Max required Free Space:
3.0 GB w/freq: 14 min
2010-07-14 11:27:38.738 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112738.mpg'
2010-07-14 11:27:38.761 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112317.mpg'
2010-07-14 11:27:38.764 ProgramInfo(): Updated pathname '':'' ->
'3071_20100714112738.mpg'
2010-07-14 11:27:38.785 TVRec(5): Changing from WatchingLiveTV to None

Thanks for the help!

Dave