[mythtv-commits] Ticket #2335: LiveTV hangs when a recording is finished and a new on starts (no channel change)
MythTV
mythtv at cvs.mythtv.org
Wed Jul 18 04:28:32 UTC 2007
#2335: LiveTV hangs when a recording is finished and a new on starts (no channel
change)
-----------------------------------------+----------------------------------
Reporter: tino.keitel+mythtv at tikei.de | Owner: ijr
Type: defect | Status: reopened
Priority: minor | Milestone: unknown
Component: mythtv | Version: head
Severity: medium | Resolution:
Mlocked: 0 |
-----------------------------------------+----------------------------------
Comment(by Nick Morrott <<knowledgejunkie [at] gmail [dot] com>>):
Sadly another me-too with LiveTV/ivtv card. Relevant mythackend/frontend
log data follows with some general wonderings afterwards:
Backend:
{{{
2007-07-17 22:19:21.912 TVRec(6): HW Tuner: 6->6
2007-07-17 22:19:22.943 ret_pid(0) child(2717) status(0x0)
2007-07-17 22:19:23.951 ret_pid(0) child(2717) status(0x0)
2007-07-17 22:19:24.959 ret_pid(0) child(2717) status(0x0)
2007-07-17 22:19:25.967 ret_pid(0) child(2717) status(0x0)
2007-07-17 22:19:26.971 ret_pid(2717) child(2717) status(0x0)
2007-07-17 22:19:26.972 External Tuning program exited with no error
2007-07-17 22:19:27.299 MPEGRec(/dev/video1) Warning: Stream type 'DVD-
Special 2'
is not supported by ivtv driver, using 'DVD'
instead.
2007-07-17 22:19:27.308 MPEGRec(/dev/video1) Warning: VBI recording with
broken drivers.
Upgrade to ivtv 0.10.0 if you experience problems.
2007-07-17 22:19:41.900 ret_pid(0) child(2746) status(0x0)
2007-07-17 22:19:42.915 ret_pid(0) child(2746) status(0x0)
2007-07-17 22:19:43.920 ret_pid(0) child(2746) status(0x0)
2007-07-17 22:19:44.928 ret_pid(0) child(2746) status(0x0)
2007-07-17 22:19:45.932 ret_pid(2746) child(2746) status(0x0)
2007-07-17 22:19:45.933 External Tuning program exited with no error
2007-07-17 22:19:45.951 Finished recording Search For The SS Republic:
channel 4032
2007-07-17 22:19:45.958 scheduler: Finished recording: Search For The SS
Republic: channel 4032
2007-07-17 22:19:46.102 Finished recording Search For The SS Republic:
channel 4032
[mpeg @ 0x182aa0]Parser not found for Codec Id: 94210 !
0: start_time: -9223372036854.775 duration: -9223372036854.775
1: start_time: -9223372036854.775 duration: -9223372036854.775
2: start_time: -9223372036854.775 duration: -9223372036854.775
stream: start_time: -9223372036854.775 duration: -9223372036854.775
bitrate=6256 kb/s
0: start_time: 0.036 duration: 1.030
1: start_time: 12.364 duration: 1.066
2: start_time: 0.025 duration: 1.004
stream: start_time: 0.276 duration: 148.945 bitrate=383 kb/s
2007-07-17 22:19:46.205 AFD: Opened codec 0xa045ae0, id(MPEG2VIDEO)
type(Video)
2007-07-17 22:19:46.207 AFD: Opened codec 0xa045380, id(MP2) type(Audio)
2007-07-17 22:19:46.227 TVRec(6): RingBufferChanged()
2007-07-17 22:19:46.236 Finished recording Search For The SS Republic:
channel 4032
2007-07-17 23:00:00.852 Finished recording Law and Order: Special Victims
Unit "Vulnerable": channel 4019
2007-07-17 23:00:00.859 scheduler: Last message repeated 2 times: Finished
recording: Search For The SS Republic: channel 4032
2007-07-17 23:00:00.878 scheduler: Finished recording: Law and Order:
Special Victims Unit "Vulnerable": channel 4019
[mpeg @ 0x182aa0]Parser not found for Codec Id: 94210 !
2007-07-17 23:00:01.295 TVRec(6): RingBufferChanged()
2007-07-17 23:00:01.383 Finished recording Law and Order: Special Victims
Unit "Vulnerable": channel 4019
0: start_time: -9223372036854.775 duration: -9223372036854.775
1: start_time: -9223372036854.775 duration: -9223372036854.775
2: start_time: -9223372036854.775 duration: -9223372036854.775
stream: start_time: -9223372036854.775 duration: -9223372036854.775
bitrate=6256 kb/s
0: start_time: 1.138 duration: 217.789
1: start_time: 13.851 duration: 217.466
2: start_time: 1.103 duration: 217.801
stream: start_time: 12.252 duration: 2557.942 bitrate=4766 kb/s
2007-07-17 23:00:01.480 AFD: Opened codec 0xa1261a0, id(MPEG2VIDEO)
type(Video)
2007-07-17 23:00:01.489 AFD: Opened codec 0xa12d440, id(MP2) type(Audio)
2007-07-17 23:01:01.897 TVRec(6): Changing from WatchingLiveTV to None
2007-07-17 23:01:02.145 Finished recording Law and Order: Criminal Intent
"Happy Family": channel 4019
2007-07-17 23:01:02.155 scheduler: Last message repeated 1 times: Finished
recording: Law and Order: Special Victims Unit "Vulnerable": chan
nel 4019
2007-07-17 23:01:02.161 scheduler: Finished recording: Law and Order:
Criminal Intent "Happy Family": channel 4019
}}}
Frontend:
{{{
2007-07-17 23:00:18.827 NVP: prebuffering pause
2007-07-17 23:00:19.158 RingBuf(/recordings/4019_20070717230000.mpg):
Waited 1.0 seconds for data to become available...
2007-07-17 23:00:19.158 Checking to see if there's a new livetv program to
switch to..
2007-07-17 23:00:20.182 RingBuf(/recordings/4019_20070717230000.mpg):
Waited 2.0 seconds for data to become available...
2007-07-17 23:00:20.182 Checking to see if there's a new livetv program to
switch to..
2007-07-17 23:00:20.502 NVP: Prebuffer wait timed out 10 times.
2007-07-17 23:00:22.142 NVP: Prebuffer wait timed out 10 times.
2007-07-17 23:00:22.230 RingBuf(/recordings/4019_20070717230000.mpg):
Waited 4.0 seconds for data to become available...
2007-07-17 23:00:22.230 Checking to see if there's a new livetv program to
switch to..
2007-07-17 23:00:23.782 NVP: Prebuffer wait timed out 10 times.
2007-07-17 23:00:25.422 NVP: Prebuffer wait timed out 10 times.
2007-07-17 23:00:26.330 RingBuf(/recordings/4019_20070717230000.mpg):
Waited 8.0 seconds for data to become available...
2007-07-17 23:00:26.330 Checking to see if there's a new livetv program to
switch to..
2007-07-17 23:00:27.062 NVP: Prebuffer wait timed out 10 times.
2007-07-17 23:00:28.702 NVP: Prebuffer wait timed out 10 times.
2007-07-17 23:00:30.342 NVP: Prebuffer wait timed out 10 times.
2007-07-17 23:00:31.982 NVP: Prebuffer wait timed out 10 times.
}}}
LiveTV was started at 22:19 and the channel was initially set to The
History Channel (program: Search For The SS Republic). We then changed
channel successfully to Hallmark to catch Law and Order (program: Law and
Order: Special Victims Unit "Vulnerable") which was scheduled to finish at
2300. At the scheduler program boundary, the log showed:
{{{
2007-07-17 23:00:00.852 Finished recording Law and Order: Special Victims
Unit "Vulnerable": channel 4019
2007-07-17 23:00:00.859 scheduler: Last message repeated 2 times: Finished
recording: Search For The SS Republic: channel 4032
}}}
Note the erroneous inclusion of the program that was recorded when LiveTV
was entered, but finished recording some 41 minutes before.
At this time, video playback froze and we backed out of LiveTV, which took
several seconds after pressing Back/Exit. The logfile showed scheduler
information for both programs that spanned the failed program boundary:
{{{
2007-07-17 23:01:02.145 Finished recording Law and Order: Criminal Intent
"Happy Family": channel 4019
2007-07-17 23:01:02.155 scheduler: Last message repeated 1 times: Finished
recording: Law and Order: Special Victims Unit "Vulnerable": chan
nel 4019
}}}
It is interesting that again, 2 programs are listed as having finished
recording at the same time, over a minute after the actual program change,
although unlike above, these were the two consecutive programs spanning
the program boundary. Why the scheduler thought it was still recording The
History Channel until 2300 is anyone's guess.
Needless to say, WAF has been dramatically lowered since this bug was
introduced...
Nick
--
Ticket URL: <http://svn.mythtv.org/trac/ticket/2335#comment:57>
MythTV <http://svn.mythtv.org/trac>
MythTV
More information about the mythtv-commits
mailing list