Opened 9 years ago

Closed 8 years ago

Last modified 8 years ago

#7870 closed defect (invalid)

random zero size recordings "the file for this recording cannot be found"

Reported by: moores.martin@… Owned by: Janne Grunau
Priority: minor Milestone: 0.23
Component: MythTV - DVB Version: 0.22-fixes
Severity: medium Keywords:
Cc: Ticket locked: yes

Description

This problem has plagued me since I started messing with Myth, on several occasions, I thought it had been fixed, but it just keeps on coming back!

The box will be working fine, recordings and livetv, then, randomly, livetv fails and recordings also start to fail, showing as 0B in Mythweb. Restarting the backend fixes this

I found some info on my card, Nova-T 500, about the LNA that needed enabling under Ubuntu 9.10, otherwise it can't pick up channels. This involved creating /etc/modprobe.d/options.conf and adding the following line:

options dvb_usb_dib0700 force_lna_activation=1

Which works fine fine. So I assumed this was causing the failed recordings, if the LNA was just turning off again?!

Secondly, I have added another line to that file which prevents the USB tuners going to sleep, which is another cause of failed recordings

options usbcore autosuspend=-1

But the problem still occurs

Backend log from failed recording:

2010-01-07 12:30:03.235 TVRec(1): Changing from None to Watching RecordingOnly
2010-01-07 12:30:03.347 TVRec(1): HW Tuner: 1->1
2010-01-07 12:30:04.299 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 12:30:04.366 Started recording: Loose Women: channel 2003 on cardid 1, sourceid 2
2010-01-07 12:30:05.410 Reschedule requested for id -1.
2010-01-07 12:30:05.682 Scheduled 41 items in 0.3 = 0.04 match + 0.23 place
2010-01-07 12:32:11.012 Reschedule requested for id -1.
2010-01-07 12:32:11.280 Scheduled 41 items in 0.3 = 0.05 match + 0.22 place
2010-01-07 12:35:05.452 Reschedule requested for id -1.
2010-01-07 12:35:05.726 Scheduled 41 items in 0.3 = 0.06 match + 0.21 place
2010-01-07 12:37:18.188 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 12:40:06.884 Reschedule requested for id -1.
2010-01-07 12:40:07.145 Scheduled 41 items in 0.3 = 0.05 match + 0.21 place
2010-01-07 12:45:08.207 Reschedule requested for id -1.
2010-01-07 12:45:08.455 Scheduled 41 items in 0.2 = 0.04 match + 0.20 place
2010-01-07 12:51:11.555 Reschedule requested for id -1.
2010-01-07 12:51:11.791 Scheduled 41 items in 0.2 = 0.04 match + 0.20 place
2010-01-07 12:52:18.278 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 12:53:14.108 UPnpMedia: BuildMediaMap - no VideoStartupDir set,  skipping scan.
2010-01-07 12:56:54.250 Reschedule requested for id -1.
2010-01-07 12:56:54.516 Scheduled 41 items in 0.3 = 0.06 match + 0.21 place
2010-01-07 13:00:02.871 Reschedule requested for id -1.
2010-01-07 13:00:03.131 Scheduled 41 items in 0.3 = 0.05 match + 0.21 place
2010-01-07 13:04:31.641 Reschedule requested for id -1.
2010-01-07 13:04:32.015 Scheduled 41 items in 0.4 = 0.07 match + 0.30 place
2010-01-07 13:07:18.369 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 13:09:28.102 Reschedule requested for id -1.
2010-01-07 13:09:28.375 Scheduled 41 items in 0.3 = 0.05 match + 0.22 place
2010-01-07 13:15:59.501 Reschedule requested for id -1.
2010-01-07 13:15:59.744 Scheduled 41 items in 0.2 = 0.04 match + 0.20 place
2010-01-07 13:17:02.140 MainServer::ANN Monitor
2010-01-07 13:17:02.215 adding: MYTHTV1 as a client (events: 0)
2010-01-07 13:18:43.548 Reschedule requested for id -1.
2010-01-07 13:18:43.931 Scheduled 41 items in 0.4 = 0.05 match + 0.33 place
2010-01-07 13:22:18.489 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 13:23:14.158 UPnpMedia: BuildMediaMap - no VideoStartupDir set,  skipping scan.
2010-01-07 13:24:10.900 Reschedule requested for id -1.
2010-01-07 13:24:11.144 Scheduled 41 items in 0.2 = 0.05 match + 0.19 place
2010-01-07 13:29:38.317 Reschedule requested for id -1.
2010-01-07 13:29:38.578 Scheduled 41 items in 0.3 = 0.04 match + 0.21 place
2010-01-07 13:30:00.712 TVRec(1): Changing from Watching RecordingOnly to None
2010-01-07 13:30:00.847 Finished recording Loose Women: channel 2003

Log when going to the recordings page in Mythweb

2010-01-07 15:05:24.324 MainServer::ANN Monitor
2010-01-07 15:05:24.352 adding: MYTHTV1 as a client (events: 1)
2010-01-07 15:05:24.457 MainServer::ANN Monitor
2010-01-07 15:05:24.503 adding: MYTHTV1 as a client (events: 1)
2010-01-07 15:05:24.551 ProgramInfo, Error: GetPlaybackURL: '2003_20100107123000.mpg' should be local, but it can not be found.
2010-01-07 15:05:24.914 MainServer::ANN Monitor
2010-01-07 15:05:24.967 adding: MYTHTV1 as a client (events: 1)
2010-01-07 15:05:26.303 ProgramInfo, Error: GetPlaybackURL: '2003_20100107123000.mpg' should be local, but it can not be found.
2010-01-07 15:05:26.342 ProgramInfo, Error: GetPlaybackURL: '2003_20100107123000.mpg' should be local, but it can not be found.
2010-01-07 15:05:26.375 Preview Error: Run() file not local: '2003_20100107123000.mpg'

Log when trying to watch livetv

2010-01-07 15:06:30.487 MainServer::ANN Playback
2010-01-07 15:06:30.523 adding: MYTHTV1 as a client (events: 0)
2010-01-07 15:06:30.638 TVRec(1): Changing from None to Watching WatchingLiveTV
2010-01-07 15:06:30.670 TVRec(1): HW Tuner: 1->1
2010-01-07 15:06:31.550 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 15:07:19.316 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 15:07:35.024 TVRec(1): Changing from Watching WatchingLiveTV to None
2010-01-07 15:07:35.311 Finished recording King Solomon's Mines: channel 2004
2010-01-07 15:07:58.083 MainServer::ANN Playback
2010-01-07 15:07:58.140 adding: MYTHTV1 as a client (events: 0)
2010-01-07 15:07:58.183 TVRec(1): Changing from None to Watching WatchingLiveTV
2010-01-07 15:07:58.259 TVRec(1): HW Tuner: 1->1
2010-01-07 15:07:58.389 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 15:08:00.837 TVRec(1): PauseRecorder() called with no recorder
2010-01-07 15:08:00.911 TVRec(1): HW Tuner: 1->1
2010-01-07 15:08:01.572 Finished recording King Solomon's Mines: channel 2004
2010-01-07 15:08:03.013 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 15:08:38.887 TVRec(1): PauseRecorder() called with no recorder
2010-01-07 15:08:38.999 TVRec(1): HW Tuner: 1->1
2010-01-07 15:08:39.356 Finished recording Big and Small "There's Space for Small": channel 2001
2010-01-07 15:08:40.973 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 15:08:53.541 Reschedule requested for id -1.
2010-01-07 15:08:54.265 TVRec(1): Changing from Watching WatchingLiveTV to None
2010-01-07 15:08:54.394 Scheduled 40 items in 0.8 = 0.05 match + 0.78 place
2010-01-07 15:08:54.544 Finished recording Dickinson's Real Deal: channel 2003
2010-01-07 15:08:56.001 MainServer::ANN Playback
2010-01-07 15:08:56.053 adding: MYTHTV1 as a client (events: 0)
2010-01-07 15:08:56.121 TVRec(1): Changing from None to Watching WatchingLiveTV
2010-01-07 15:08:56.165 TVRec(1): HW Tuner: 1->1
2010-01-07 15:08:56.325 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 15:09:02.660 TVRec(1): PauseRecorder() called with no recorder
2010-01-07 15:09:02.782 TVRec(1): HW Tuner: 1->1
2010-01-07 15:09:04.450 Finished recording King Solomon's Mines: channel 2004
2010-01-07 15:09:04.596 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
2010-01-07 15:09:04.918 TVRec(1): Changing from Watching WatchingLiveTV to None

Basically, I can't see any errors, which is as described when I was reading about the USB tuners suspending, Mythtv doesn't know they aren't working, so doesn't report a problem

I have also just found a thread on this here:

http://ubuntuforums.org/showthread.php?t=699603

but replies are old and not solved

Change History (7)

comment:1 Changed 9 years ago by moores.martin@…

Quick update:

enabled quick tuning, set to always on both tuners on suggestion here: http://www.mythtvtalk.com/forum/general/11528-mythtv-randomly-fails-record-4.html

Still had missed recordings since making that change.

Just now, 2 programmes started recording at 21:00, one failed, one worked fine. So have ruled out an issue with the backend for example (I assume anyway)! So possible hardware and firmware issue?!

In the thread mentioned, this is happening to people with other types of tuners though

comment:2 Changed 8 years ago by stuartm

Resolution: invalid
Status: newclosed

Definitely a driver/firmware issue.

comment:3 Changed 8 years ago by sphery

Regarding the missing files, see #3872

comment:4 Changed 8 years ago by moores.martin@…

stuartm and mdean

Many thanks for the replies, the the suggestion of it being a firmware/driver issue got me thinking and as a result, solved the problem!

I had, when setting up the machine, installed the "Firmware for DVB cards" in "Hardware Drivers". On your suggestions, I disabled these and the machine hasn't missed a recording since!!!

I guess the bug lies in that firmware, not sure if I am at other dis-advantages by not having in enabled, but am very happy to be recording successfully now.

Thanks

comment:5 Changed 8 years ago by moores.martin@…

well, of course, spoke to soon, same issue last night, missed a recording. No idea what to try next

comment:6 Changed 8 years ago by GlemSom

I can report the same using two TT-1501 cards.
At random times, mythtv failes to record shown.
There's NO way to rules out it might be a signal error at exactly that second, but anyway - if MythTV is unable to start a recording - it should at least retry a minute later!

comment:7 Changed 8 years ago by robertm

Ticket locked: set
Note: See TracTickets for help on using tickets.