[mythtv-users] Bad Recordings - Choppy - on .25

Gregory Moyer moyerg at syphr.com
Sat Mar 3 19:44:02 UTC 2012


On Fri, Mar 2, 2012 at 5:47 PM, Jon Heizer <jheizermythtv at gmail.com> wrote:
> On Fri, Mar 2, 2012 at 4:06 PM, Brian J. Murrell <brian at interlinx.bc.ca>
> wrote:
>>
>> On 12-03-02 04:59 PM, Scott & Nicole Harris wrote:
>> > I saw a similar issue when I upgraded my existing system from 0.24 to
>> > 0.25.
>> > When recording more than one show at a time (via 3 HDHR units), the
>> > recordings has moments where they were almost like a bad signal.  Lots
>> > of
>> > "pixelation" where the screen would get all "artifacty" and when that
>> > happened, the sound would get that metallic almost robotic twinges in
>> > it.  I
>> > don't believe it's a hardware issue because as soon as I switch back to
>> > 0.24, no problems what so ever.
>>
>> Interesting.  I occasionally get that too but it's usually during
>> periods where I am recording a number of shows so I was just writing it
>> off to resource strain.
>>
>> I wonder if there is more to it.
>>
>> Cheers,
>> b.
>>
>>
>
> Hmm, same thing here too.  From an original HDHR.  I assumed it was
> something interfering with the antenna randomly as I have not been able to
> reproduce it.  It only happens maybe twice a week over the last 3 weeks.
>
> Jon
>


This is happening to me as well on master (0.25). I have 2 HDHR and
one HDHR Prime (like the OP). The errors are happening at the
beginning of almost every CBS show here (Comcast, Philadelphia, PA
area). Rarely it occurs on other stations or the entire show on CBS. I
was ready to blame Comcast until I saw this thread.

It doesn't seem to matter which device or tuner is used. I get the
pixelated picture with robotic/metallic sound as previously described.
The recording is definitely damaged (the recording is identified in
MythTV as damaged and both mythfrontend and mplayer show errors).

In mythfrontend with -v playback,audio I see the following during
damaged parts (this is at the beginning of a recording):

2012-03-03 13:58:39.275509 I  Dec: Selected track #1 in the
Undetermined language(7695972)
2012-03-03 13:58:39.446254 I  ALSA: WriteAudio: buffer underrun
2012-03-03 13:58:39.572328 I  PreviewQueue: Requesting preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:39.572383 I  PreviewQueue: Requested preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:39.632249 E  AFD: Unknown audio decoding error
2012-03-03 13:58:39.635573 I  ALSA: WriteAudio: buffer underrun
2012-03-03 13:58:39.796915 I  PreviewQueue: Requesting preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:39.797053 I  PreviewQueue: Requested preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:39.836891 E  AFD: Unknown audio decoding error
2012-03-03 13:58:39.851199 E  AFD: Unknown audio decoding error
2012-03-03 13:58:39.972709 I  ScreenSaverX11Private: DPMS Deactivated 1
2012-03-03 13:58:39.975473 I  Player(0): Video Aspect ratio changed
from 1.33333 to 1.77778
2012-03-03 13:58:39.975492 I  Display Rect  left: 0, top: 0, width:
1366, height: 768, aspect: 1.77778
2012-03-03 13:58:39.975500 I  Video Rect    left: 0, top: 0, width:
1920, height: 1080, aspect: 1.77778
2012-03-03 13:58:39.975517 I  Player(0): Enabled deinterlacing
2012-03-03 13:58:40.010709 I  VideoOutput: Created YV12 OSD.
2012-03-03 13:58:40.020667 I  PreviewQueue: Requesting preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:40.020720 I  PreviewQueue: Requested preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:40.070599 I  Player(0): Video is 6.99793 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.070631 I  AO: Pause 1
2012-03-03 13:58:40.073381 I  Player(0): Video is 11.9916 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.073406 I  AO: Pause 1
2012-03-03 13:58:40.080987 I  AO: OutputAudioLoop: audio paused
2012-03-03 13:58:40.081004 I  ALSA: WriteAudio: buffer underrun
2012-03-03 13:58:40.086288 I  Player(0): Video is 15.4896 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.093242 I  Player(0): Video is 17.8659 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.104696 I  Player(0): Video is 19.3934 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.105921 I  Player(0): Video is 19.2203 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.107112 I  Player(0): Video is 18.8358 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.108295 I  Player(0): Video is 18.3001 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.109409 I  Player(0): Video is 17.6511 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.110482 I  Player(0): Video is 16.9096 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.111540 I  Player(0): Video is 16.1062 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.112895 I  Player(0): Video is 15.2565 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.114445 I  Player(0): Video is 14.3644 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.115830 I  Player(0): Video is 13.4481 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.117077 I  Player(0): Video is 12.5061 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.118360 I  Player(0): Video is 11.5524 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.120042 I  Player(0): Video is 10.5898 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.121488 I  Player(0): Video is 9.61318 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.122756 I  Player(0): Video is 8.63344 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.127177 I  Player(0): Video is 7.65139 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.127282 I  Player(0): Waiting for video buffers...
2012-03-03 13:58:40.132690 I  Player(0): Video is 6.66011 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.132753 I  Player(0): Waiting for video buffers...
2012-03-03 13:58:40.142455 I  Player(0): Video is 5.6694 frames behind
audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.142520 I  Player(0): Waiting for video buffers...
2012-03-03 13:58:40.146127 E  AFD: Unknown audio decoding error
2012-03-03 13:58:40.148225 I  Player(0): Video is 4.67911 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.148588 I  Player(0): Waiting for video buffers...
2012-03-03 13:58:40.157730 I  Player(0): Video is 3.68166 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:40.157816 I  Player(0): Waiting for video buffers...
2012-03-03 13:58:40.198557 I  AO: Pause 0
2012-03-03 13:58:40.292075 E  AFD: Unknown audio decoding error
2012-03-03 13:58:40.346112 I  AO: OutputAudioLoop: Play Event
2012-03-03 13:58:40.407134 E  AFD: Unknown audio decoding error
2012-03-03 13:58:40.487632 E  AFD: Unknown audio decoding error
2012-03-03 13:58:40.575678 I  Player(0): Video is 3.4722 frames ahead of audio,
			doubling video frame interval to slow down.
2012-03-03 13:58:40.621071 E  AFD: Unknown audio decoding error
2012-03-03 13:58:40.635887 I  PreviewQueue: Requesting preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:40.635928 I  PreviewQueue: Requested preview for
'77002_20120223210000.mpg_0x0_-1s'
2012-03-03 13:58:41.691536 I  Player(0): Video is 4.06584 frames
behind audio (too slow), dropping frame to catch up.
2012-03-03 13:58:41.691549 I  AO: Pause 1





There is a video aspect change in there. I have wondered if that may
be contributing to the problem when the backend was recording. I tried
the recording in mplayer and I see a lot of logging like this:

[mpeg2video @ 0x7fc2ef06f5e0]ac-tex damaged at 0 60
[mpeg2video @ 0x7fc2ef06f5e0]ac-tex damaged at 0 61
[mpeg2video @ 0x7fc2ef06f5e0]ac-tex damaged at 0 62
[mpeg2video @ 0x7fc2ef06f5e0]invalid mb type in I Frame at 0 63
[mpeg2video @ 0x7fc2ef06f5e0]invalid mb type in I Frame at 0 64
[mpeg2video @ 0x7fc2ef06f5e0]skipped MB in I frame at 1 65
[mpeg2video @ 0x7fc2ef06f5e0]invalid mb type in I Frame at 1 66
[mpeg2video @ 0x7fc2ef06f5e0]ac-tex damaged at 0 67
[mpeg2video @ 0x7fc2ef06f5e0]concealing 6360 DC, 6360 AC, 6360 MV errors
A:26740.6 V:26739.5 A-V:  1.147 ct:  0.552 3641/3641 85%  0% 12.2% 128 0
[mpeg2video @ 0x7fc2ef06f5e0]00 motion_type at 77 32
[mpeg2video @ 0x7fc2ef06f5e0]concealing 2860 DC, 2860 AC, 2860 MV errors
A:26740.6 V:26739.5 A-V:  1.157 ct:  0.555 3642/3642 85%  0% 12.1% 129 0
[mpeg2video @ 0x7fc2ef06f5e0]invalid mb type in P Frame at 77 58
[mpeg2video @ 0x7fc2ef06f5e0]00 motion_type at 20 55
[mpeg2video @ 0x7fc2ef06f5e0]slice mismatch
[mpeg2video @ 0x7fc2ef06f5e0]invalid mb type in P Frame at 6 57
[mpeg2video @ 0x7fc2ef06f5e0]ac-tex damaged at 5 58
[mpeg2video @ 0x7fc2ef06f5e0]00 motion_type at 11 59
[mpeg2video @ 0x7fc2ef06f5e0]00 motion_type at 7 60
[mpeg2video @ 0x7fc2ef06f5e0]00 motion_type at 11 61





Here is the backend log I saw while recording three channels on 2/23
at 8PM EST (The Big Bang Theory - entirely corrupted and unwatchable,
E.T. - no corruption, and The Bridge on the River Kwai - a few moments
of corruption):


2012-02-23 19:59:24.045785 I [28372/30305] TVRecEvent tv_rec.cpp:1521
(HandlePendingRecordings) - TVRec(13): ASK_RECORDING 13 29 0
 0
2012-02-23 19:59:24.130947 I [28372/30450] TVRecEvent tv_rec.cpp:1521
(HandlePendingRecordings) - TVRec(15): ASK_RECORDING 15 29 0
 0
2012-02-23 19:59:24.234725 I [28372/30100] TVRecEvent tv_rec.cpp:1521
(HandlePendingRecordings) - TVRec(1): ASK_RECORDING 1 29 0 0
2012-02-23 19:59:54.108806 I [28372/30100] TVRecEvent tv_rec.cpp:1014
(HandleStateChange) - TVRec(1): Changing from None to Record
ingOnly
2012-02-23 19:59:54.113906 I [28372/30100] TVRecEvent tv_rec.cpp:3459
(TuningCheckForHWChange) - TVRec(1): HW Tuner: 1->1
2012-02-23 19:59:54.294030 N [28372/31272] Scheduler
autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max
required Free
 Space: 6.0 GB w/freq: 14 min
2012-02-23 19:59:54.294087 I [28372/31272] Scheduler
scheduler.cpp:2447 (HandleRecordingStatusChange) - Tuning recording:
"The Big
 Bang Theory":"The Werewolf Transformation": channel 77003 on cardid
1, sourceid 7
2012-02-23 19:59:54.520728 I [28372/30305] TVRecEvent tv_rec.cpp:1014
(HandleStateChange) - TVRec(13): Changing from None to Recor
dingOnly
2012-02-23 19:59:54.520792 I [28372/30305] TVRecEvent mythdbcon.cpp:75
(MSqlDatabase) - Database connection created: DBManager355
2012-02-23 19:59:54.520814 I [28372/30305] TVRecEvent
mythdbcon.cpp:395 (PurgeIdleConnections) - New DB connection, total:
40
2012-02-23 19:59:54.520950 I [28372/30305] TVRecEvent mythdbcon.cpp:94
(~MSqlDatabase) - Database connection deleted: DBManager328
2012-02-23 19:59:54.528481 I [28372/30305] TVRecEvent
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at ho
st: oracle
2012-02-23 19:59:54.534003 I [28372/30305] TVRecEvent tv_rec.cpp:3459
(TuningCheckForHWChange) - TVRec(13): HW Tuner: 13->13
2012-02-23 19:59:54.671124 N [28372/31272] Scheduler
autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max
required Free
 Space: 6.0 GB w/freq: 7 min
2012-02-23 19:59:54.671157 I [28372/31272] Scheduler
scheduler.cpp:2447 (HandleRecordingStatusChange) - Tuning recording:
"E.T. th
e Extra-Terrestrial": channel 10238 on cardid 13, sourceid 10
2012-02-23 19:59:54.901377 I [28372/30450] TVRecEvent tv_rec.cpp:1014
(HandleStateChange) - TVRec(15): Changing from None to Recor
dingOnly

2012-02-23 19:59:54.906529 I [28372/30450] TVRecEvent tv_rec.cpp:3459
(TuningCheckForHWChange) - TVRec(15): HW Tuner: 15->15
2012-02-23 19:59:54.926000 I [28372/30100] TVRecEvent tv_rec.cpp:3953
(TuningNewRecorder) - TVRec(1): rec->GetPathname():
'/mnt/raid/media/recordings/77003_20120223200000.mpg'
2012-02-23 19:59:54.943713 E [28372/30100] TVRecEvent
recorderbase.cpp:162 (SetStrOption) - RecBase(1:1011D696-0):
SetStrOption(...recordingtype): Option not in profile.
2012-02-23 19:59:55.066850 N [28372/31272] Scheduler
autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max
required Free Space: 6.0 GB w/freq: 4 min
2012-02-23 19:59:55.066884 I [28372/31272] Scheduler
scheduler.cpp:2447 (HandleRecordingStatusChange) - Tuning recording:
"The Bridge on the River Kwai": channel 10890 on cardid 15, sourceid
10
2012-02-23 19:59:55.088540 I [28372/28386] HDHRStreamHandler
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager356
2012-02-23 19:59:55.088584 I [28372/28386] HDHRStreamHandler
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 41
2012-02-23 19:59:55.096705 I [28372/28386] HDHRStreamHandler
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 19:59:55.248099 I [28372/31272] Scheduler
scheduler.cpp:2447 (HandleRecordingStatusChange) - Started recording:
"The Big Bang Theory":"The Werewolf Transformation": channel 77003 on
cardid 1, sourceid 7
2012-02-23 19:59:55.317279 E [28372/28390] HDHRStreamHandler
dtvsignalmonitor.cpp:321 (HandlePAT) - DTVSM(13114644-0): Program #0
not found in PAT!
Program Association Section
 PSIP tableID(0x0) length(13) extension(0x0)
      version(26) current(1) section(0) last_section(0)
      tsid(0) programCount(1)
  program number     2 has PID 0x0031

2012-02-23 19:59:55.317296 E [28372/28390] HDHRStreamHandler
dtvsignalmonitor.cpp:326 (HandlePAT) - DTVSM(13114644-0): But there is
only one program in the PAT, so we'll just use it
2012-02-23 19:59:55.435417 N [28372/28390] HDHRStreamHandler
dtvsignalmonitor.cpp:354 (HandlePMT) - DTVSM(13114644-0): PMT says
program 2 is encrypted
2012-02-23 19:59:55.622023 I [28372/31272] Scheduler
scheduler.cpp:2447 (HandleRecordingStatusChange) - Started recording:
"E.T. the Extra-Terrestrial": channel 10238 on cardid 13, sourceid 10
2012-02-23 19:59:55.635031 E [28372/28391] HDHRStreamHandler
dtvsignalmonitor.cpp:321 (HandlePAT) - DTVSM(13114644-1): Program #0
not found in PAT!

Program Association Section
 PSIP tableID(0x0) length(13) extension(0x0)
      version(6) current(1) section(0) last_section(0)
      tsid(0) programCount(1)
  program number     1 has PID 0x0030

2012-02-23 19:59:55.635052 E [28372/28391] HDHRStreamHandler
dtvsignalmonitor.cpp:326 (HandlePAT) - DTVSM(13114644-1): But there is
only one program in the PAT, so we'll just use it
2012-02-23 19:59:55.669805 E [28372/28390] HDHRStreamHandler
hdhrstreamhandler.cpp:206 (UpdateFilters) - HDHRSH(13114644-0):
UpdateFilters called in wrong tune mode
2012-02-23 19:59:55.686967 I [28372/30305] TVRecEvent tv_rec.cpp:3953
(TuningNewRecorder) - TVRec(13): rec->GetPathname():
'/mnt/raid/media/recordings/10238_20120223200000.mpg'
2012-02-23 19:59:55.687396 E [28372/30305] TVRecEvent
recorderbase.cpp:162 (SetStrOption) - RecBase(13:13114644-0):
SetStrOption(...recordingtype): Option not in profile.
2012-02-23 19:59:55.752900 N [28372/28391] HDHRStreamHandler
dtvsignalmonitor.cpp:354 (HandlePMT) - DTVSM(13114644-1): PMT says
program 1 is encrypted
2012-02-23 19:59:55.776595 I [28372/28395] HDHRStreamHandler
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager357
2012-02-23 19:59:55.776631 I [28372/28395] HDHRStreamHandler
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 42
2012-02-23 19:59:55.784814 I [28372/28395] HDHRStreamHandler
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 19:59:55.895861 I [28372/31272] Scheduler
scheduler.cpp:2447 (HandleRecordingStatusChange) - Started recording:
"The Bridge on the River Kwai": channel 10890 on cardid 15, sourceid
10
2012-02-23 19:59:55.944985 E [28372/28391] HDHRStreamHandler
hdhrstreamhandler.cpp:206 (UpdateFilters) - HDHRSH(13114644-1):
UpdateFilters called in wrong tune mode
2012-02-23 19:59:55.964468 I [28372/30450] TVRecEvent tv_rec.cpp:3953
(TuningNewRecorder) - TVRec(15): rec->GetPathname():
'/var/lib/mythtv/recordings/10890_20120223200000.mpg'
2012-02-23 19:59:55.978796 E [28372/30450] TVRecEvent
recorderbase.cpp:162 (SetStrOption) - RecBase(15:13114644-1):
SetStrOption(...recordingtype): Option not in profile.
2012-02-23 19:59:57.529047 I [28372/28399] HDHRStreamHandler
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager358
2012-02-23 19:59:57.529275 I [28372/28399] HDHRStreamHandler
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 43

2012-02-23 19:59:57.537143 I [28372/28399] HDHRStreamHandler
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 20:00:12.743608 I [28372/31273] HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-02-23 20:00:52.281049 I [28372/28539] Commflag_4024
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager359
2012-02-23 20:00:52.281126 I [28372/28539] Commflag_4024
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 44
2012-02-23 20:00:52.290150 I [28372/28539] Commflag_4024
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 20:00:52.290827 I [28372/28539] Commflag_4024
jobqueue.cpp:2273 (DoFlagCommercialsThread) - JobQueue: Commercial
Detection Starting for "The Big Bang Theory":"The Werewolf
Transformation" recorded from channel 77003 at 2012-02-23T20:00:00
2012-02-23 20:00:53.165407 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Playback
2012-02-23 20:00:53.165422 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:00:53.167799 I [28372] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:00:53.167824 I [28372] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:00:53.493875 I [28372/23710] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Playback
2012-02-23 20:00:53.493901 I [28372/23710] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:00:53.495463 I [28372] ProcessRequest
recorderbase.cpp:381 (GetKeyframePositions) - RecBase(1:1011D696-0):
GetKeyframePositions(1591,9223372036854775807,#10) out of 117
2012-02-23 20:00:57.321487 I [28372/28577] Metadata_4025
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager360
2012-02-23 20:00:57.321849 I [28372/28577] Metadata_4025
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 45
2012-02-23 20:00:57.332629 I [28372/28577] Metadata_4025
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 20:00:57.333102 I [28372/28577] Metadata_4025
jobqueue.cpp:2149 (DoMetadataLookupThread) - JobQueue: Metadata Lookup
Starting for "E.T. the Extra-Terrestrial" recorded from channel 10238
at 2012-02-23T20:00:00
2012-02-23 20:01:02.389935 I [28372/28607] Metadata_4027
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager361
2012-02-23 20:01:02.390142 I [28372/28607] Metadata_4027
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 46
2012-02-23 20:01:02.399373 I [28372/28607] Metadata_4027
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle

2012-02-23 20:01:02.399522 I [28372/28607] Metadata_4027
jobqueue.cpp:2149 (DoMetadataLookupThread) - JobQueue: Metadata Lookup
Starting for "The Bridge on the River Kwai" recorded from channel
10890 at 2012-02-23T20:00:00
2012-02-23 20:01:02.724750 I [28372/23710] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:01:02.724768 I [28372/23710] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:01:02.727848 I [28372] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:01:02.727973 I [28372] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:01:08.082890 I [28372/23710] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:01:08.082910 I [28372/23710] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:01:08.098157 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:01:08.098168 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:02:07.444133 I [28372/28831] Commflag_4026
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager362
2012-02-23 20:02:07.444309 I [28372/28831] Commflag_4026
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 47
2012-02-23 20:02:07.452186 I [28372/28831] Commflag_4026
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 20:02:07.452555 I [28372/28831] Commflag_4026
jobqueue.cpp:2273 (DoFlagCommercialsThread) - JobQueue: Commercial
Detection Starting for "E.T. the Extra-Terrestrial" recorded from
channel 10238 at 2012-02-23T20:00:00
2012-02-23 20:02:07.963883 I [28372/23710] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Playback
2012-02-23 20:02:07.963936 I [28372/23710] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:02:07.967036 I [28372] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:02:07.967061 I [28372] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:02:08.162126 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Playback
2012-02-23 20:02:08.162144 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:02:08.163120 I [28372] ProcessRequest
recorderbase.cpp:381 (GetKeyframePositions) - RecBase(13:13114644-0):
GetKeyframePositions(3703,9223372036854775807,#6) out of 120
2012-02-23 20:02:12.749878 I [28372/28850] Commflag_4028
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager363

2012-02-23 20:02:12.749969 I [28372/28850] Commflag_4028
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 48
2012-02-23 20:02:12.757667 I [28372/28850] Commflag_4028
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 20:02:12.757915 I [28372/28850] Commflag_4028
jobqueue.cpp:2273 (DoFlagCommercialsThread) - JobQueue: Commercial
Detection Starting for "The Bridge on the River Kwai" recorded from
channel 10890 at 2012-02-23T20:00:00
2012-02-23 20:02:13.317115 I [28372/23710] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Playback
2012-02-23 20:02:13.317153 I [28372/23710] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:02:13.318749 I [28372] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:02:13.318907 I [28372] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:02:13.576809 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Playback
2012-02-23 20:02:13.576827 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:02:13.577925 I [28372] ProcessRequest
recorderbase.cpp:381 (GetKeyframePositions) - RecBase(15:13114644-1):
GetKeyframePositions(3775,9223372036854775807,#5) out of 92
2012-02-23 20:05:18.763475 I [28372/31273] HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-02-23 20:06:28.184493 N [28372/31274] Expire autoexpire.cpp:263
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0
GB w/freq: 4 min
2012-02-23 20:06:28.310852 N [28372/31274] Expire autoexpire.cpp:624
(SendDeleteMessages) - Expiring 5688 MB for 10224 at
2012-02-14T21:00:00 => "Dirty Jobs":"Onion Processor"
2012-02-23 20:06:31.430730 I [28372/29536] DeleteThread
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager364
2012-02-23 20:06:31.430784 I [28372/29536] DeleteThread
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 49
2012-02-23 20:06:31.439022 I [28372/29536] DeleteThread
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 20:06:35.626618 I [28372/31272] Scheduler
scheduler.cpp:1998 (HandleReschedule) - Reschedule requested for id 0.
2012-02-23 20:07:16.813576 I [28372/31272] Scheduler
scheduler.cpp:2056 (HandleReschedule) - Scheduled 2133 items in 41.0 =
0.01 match + 41.00 place
2012-02-23 20:09:54.351828 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:09:54.351865 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:09:54.352744 I [28372] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor

2012-02-23 20:09:54.352784 I [28372] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:09:54.400215 I [28372/23710] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:09:54.400677 I [28372/23710] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:09:54.404168 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:09:54.404199 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:09:59.154843 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:09:59.154865 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:09:59.155726 I [28372] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:09:59.155753 I [28372] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:10:00.737692 I [28372] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Playback
2012-02-23 20:10:00.737709 I [28372] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: helios as a client
(events: 0)
2012-02-23 20:10:00.738928 I [28372] ProcessRequest
mainserver.cpp:1473 (HandleAnnounce) - MainServer::HandleAnnounce
FileTransfer
2012-02-23 20:10:00.738946 I [28372] ProcessRequest
mainserver.cpp:1475 (HandleAnnounce) - adding: helios as a remote file
transfer
2012-02-23 20:10:20.791055 I [28372/31273] HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-02-23 20:11:06.405437 I [28372] ProcessRequest
recorderbase.cpp:381 (GetKeyframePositions) - RecBase(1:1011D696-0):
GetKeyframePositions(1741,9223372036854775807,#1206) out of 1323
2012-02-23 20:11:28.311182 N [28372/31274] Expire autoexpire.cpp:263
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0
GB w/freq: 4 min
2012-02-23 20:11:29.336018 I [28372/22721] ProcessRequest
recorderbase.cpp:381 (GetKeyframePositions) - RecBase(13:13114644-0):
GetKeyframePositions(3925,9223372036854775807,#494) out of 614
2012-02-23 20:11:46.803295 I [28372/22721] ProcessRequest
recorderbase.cpp:381 (GetKeyframePositions) - RecBase(15:13114644-1):
GetKeyframePositions(4039,9223372036854775807,#347) out of 439
2012-02-23 20:15:21.808792 I [28372/31273] HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-02-23 20:16:28.437444 N [28372/31274] Expire autoexpire.cpp:263
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0
GB w/freq: 4 min
2012-02-23 20:20:23.830884 I [28372/31273] HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-02-23 20:21:28.560450 N [28372/31274] Expire autoexpire.cpp:263
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0
GB w/freq: 4 min
2012-02-23 20:25:01.041665 I [28372/32291] ProcessRequest
mythdbcon.cpp:75 (MSqlDatabase) - Database connection created:
DBManager365
2012-02-23 20:25:01.041708 I [28372/32291] ProcessRequest
mythdbcon.cpp:298 (popConnection) - New DB connection, total: 50
2012-02-23 20:25:01.054743 I [28372/32291] ProcessRequest
mythdbcon.cpp:179 (OpenDatabase) - Connected to database 'mythconverg'
at host: oracle
2012-02-23 20:25:28.854314 I [28372/31273] HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-02-23 20:26:28.666174 N [28372/31274] Expire autoexpire.cpp:263
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0
GB w/freq: 4 min
2012-02-23 20:30:33.875586 I [28372/31273] HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-02-23 20:31:28.808695 N [28372/31274] Expire autoexpire.cpp:263
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0
GB w/freq: 4 min
2012-02-23 20:31:41.027932 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:31:41.027975 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:31:41.045398 I [28372/23710] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:31:41.045521 I [28372/23710] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:31:52.529044 I [28372/32291] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:31:52.529062 I [28372/32291] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 0)
2012-02-23 20:31:52.542771 I [28372/22721] ProcessRequest
mainserver.cpp:1358 (HandleAnnounce) - MainServer::ANN Monitor
2012-02-23 20:31:52.542787 I [28372/22721] ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) - adding: pluto as a client
(events: 1)
2012-02-23 20:32:30.069368 I [28372/30100] TVRecEvent tv_rec.cpp:1014
(HandleStateChange) - TVRec(1): Changing from RecordingOnly to None
2012-02-23 20:32:30.177114 I [28372/28386] HDHRStreamHandler
mythdbcon.cpp:453 (CloseDatabases) - Closing DB connection named
'DBManager356'
2012-02-23 20:32:30.331037 I [28372/28385] RecThread mythdbcon.cpp:75
(MSqlDatabase) - Database connection created: DBManager366
2012-02-23 20:32:30.331224 I [28372/28385] RecThread mythdbcon.cpp:298
(popConnection) - New DB connection, total: 50
2012-02-23 20:32:30.339326 I [28372/28385] RecThread mythdbcon.cpp:179
(OpenDatabase) - Connected to database 'mythconverg' at host: oracle
2012-02-23 20:32:30.374904 I [28372/28385] RecThread mythdbcon.cpp:453
(CloseDatabases) - Closing DB connection named 'DBManager36
6'
2012-02-23 20:32:30.398775 I [28372/30100] TVRecEvent tv_rec.cpp:812
(FinishedRecording) - TVRec::FinishedRecording(The Big Bang Theory)
damaged recq:<RecordingQuality overall_score="0.8"
key="77003_2012-02-23T20:00:00" countinuity_error_count="28216"
packet_count="16976479" />

2012-02-23 20:32:30.419550 I [28372/28372] CoreContext
scheduler.cpp:620 (UpdateRecStatus) - Updating status for "The Big
Bang Theory":"The Werewolf Transformation" on cardid 1 (Recording =>
Recorded)


You can see at the end that MythTV realizes that the recording of The
Big Bang Theory is damaged.


More information about the mythtv-users mailing list