[mythtv-users] GetKeyframePositions(...) out of 1044 causing commflag to stall?

Brian J. Murrell brian at interlinx.bc.ca
Fri Oct 1 10:56:32 UTC 2010


I'm using branches/release-0-23-fixes [26407] on my master backend and
farming out commflagging jobs to a slave backend running
branches/release-0-23-fixes [26437] and have been seeing some commflag
jobs stalling (on the slave backend in this case on hand).

The slave backend log reports:

2010-09-30 20:00:56.199 ProgramInfo(): Updated pathname '':'' -> '2936_20100930200000.mpg'
2010-09-30 20:00:56.359 JobQueue: Commercial Flagging Starting for My Generation "Home Movies" recorded from channel 2936 at Thu Sep 30 20:00:00 2010
2010-09-30 20:00:56.364 commflag: Commercial Flagging Starting: My Generation "Home Movies" recorded from channel 2936 at Thu Sep 30 20:00:00 2010
2010-09-30 20:00:56.412 ProgramInfo(): Updated pathname '':'' -> '2936_20100930200000.mpg'
2010-09-30 20:00:56.507 Using runtime prefix = /usr
2010-09-30 20:00:56.507 Using configuration directory = /home/mythtv/.mythtv
2010-09-30 20:00:56.508 Empty LocalHostName.
2010-09-30 20:00:56.508 Using localhost value of pc
2010-09-30 20:00:56.516 New DB connection, total: 1
2010-09-30 20:00:56.533 Connected to database 'mythconverg' at host: pvr
2010-09-30 20:00:56.539 Closing DB connection named 'DBManager0'
2010-09-30 20:00:56.542 Connected to database 'mythconverg' at host: pvr
2010-09-30 20:00:56.548 ProgramInfo(): Updated pathname '':'' -> '2936_20100930200000.mpg'
2010-09-30 20:00:56.640 MythContext: Connecting to backend server: 10.75.22.2:6543 (try 1 of 5)
2010-09-30 20:00:56.641 Using protocol version 23056
2010-09-30 20:00:57.069 AFD: Opened codec 0xb5703df0, id(MPEG2VIDEO) type(Video)
2010-09-30 20:00:57.070 AFD: codec AC3 has 2 channels
2010-09-30 20:00:57.071 AFD: Opened codec 0xb5704890, id(AC3) type(Audio)
2010-09-30 20:00:57.134 MythContext: Connecting to backend server: 10.75.22.2:6543 (try 1 of 5)
2010-09-30 20:00:57.147 Using protocol version 23056
2010-09-30 20:08:33.863 RingBuf(/storage1/2936_20100930200000.mpg): Taking too long to be allowed to read..
2010-09-30 20:08:34.863 RingBuf(/storage1/2936_20100930200000.mpg): Taking too long to be allowed to read..
2010-09-30 20:08:35.864 RingBuf(/storage1/2936_20100930200000.mpg): Taking too long to be allowed to read..
2010-09-30 20:08:36.865 RingBuf(/storage1/2936_20100930200000.mpg): Taking too long to be allowed to read..
2010-09-30 20:08:37.865 RingBuf(/storage1/2936_20100930200000.mpg): Taking too long to be allowed to read..
2010-09-30 20:08:37.866 restarting readhead thread..
2010-09-30 21:01:02.100 ProgramInfo(): Updated pathname '':'' -> '2039_20100930210000.mpg'

I'd imagine it's the events starting at 2010-09-30 20:08:33.863 that
caused it to choke, so looking on the master backend's logs we see:

2010-09-30 19:59:33.440 TVRec(2): ASK_RECORDING 2 27 0 0
2010-09-30 19:59:33.441 TVRec(2): ASK_RECORDING 2 27 0 0
2010-09-30 19:59:33.442 TVRec(2): ASK_RECORDING 2 27 0 0
2010-09-30 19:59:33.441 TVRec(3): ASK_RECORDING 3 27 0 0
2010-09-30 19:59:33.444 TVRec(3): ASK_RECORDING 3 27 0 0
2010-09-30 19:59:33.445 TVRec(3): ASK_RECORDING 3 27 0 0
2010-09-30 19:59:33.628 TVRec(1): ASK_RECORDING 1 27 0 0
2010-09-30 19:59:33.629 TVRec(1): ASK_RECORDING 1 27 0 0
2010-09-30 19:59:33.630 TVRec(1): ASK_RECORDING 1 27 0 0
2010-09-30 20:00:00.861 TVRec(1): Changing from RecordingOnly to None
...
2010-09-30 20:00:15.424 TVRec(3): Changing from None to RecordingOnly
2010-09-30 20:00:15.429 TVRec(3): HW Tuner: 3->3
2010-09-30 20:00:15.587 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 4 min
2010-09-30 20:00:15.588 Started recording: My Generation "Home Movies": channel 2936 on cardid 3, sourceid 2
2010-09-30 20:00:15.593 scheduler: Started recording: My Generation "Home Movies": channel 2936 on cardid 3, sourceid 2
2010-09-30 20:00:15.802 TVRec(3): rec->GetFileName(): '/storage1/2936_20100930200000.mpg'
2010-09-30 20:00:16.669 Reschedule requested for id 0.
2010-09-30 20:00:17.487 AFD: Opened codec 0x8fd9550, id(MPEG2VIDEO) type(Video)
2010-09-30 20:00:17.496 AFD: Opened codec 0x8de72b0, id(MPEG2VIDEO) type(Video)
2010-09-30 20:00:17.499 AFD: codec AC3 has 2 channels
2010-09-30 20:00:17.501 AFD: Opened codec 0x8fec2b0, id(AC3) type(Audio)
2010-09-30 20:00:17.503 AFD: codec AC3 has 2 channels
2010-09-30 20:00:17.506 AFD: Opened codec 0x8dfa000, id(AC3) type(Audio)
2010-09-30 20:00:17.511 AFD: codec AC3 has 2 channels
2010-09-30 20:00:17.512 AFD: codec AC3 has 2 channels
2010-09-30 20:00:17.513 AFD: Opened codec 0x8dfa700, id(AC3) type(Audio)
2010-09-30 20:00:17.513 AFD: Opened codec 0x8fec9f0, id(AC3) type(Audio)
...
2010-09-30 20:00:57.163 RecBase(3:/dev/dvb/adapter0/frontend0): GetKeyframePositions(781,9223372036854775807,#17) out of 91
2010-09-30 20:08:30.962 RecBase(1:/dev/dvb/adapter0/frontend0): GetKeyframePositions(388,9223372036854775807,#1044) out of 1080
2010-09-30 20:08:31.355 RecBase(2:/dev/dvb/adapter0/frontend0): GetKeyframePositions(352,9223372036854775807,#1028) out of 1060
2010-09-30 20:08:53.148 RecBase(2:/dev/dvb/adapter0/frontend0): GetKeyframePositions(11944,9223372036854775807,#48) out of 1108
2010-09-30 20:08:53.212 RecBase(1:/dev/dvb/adapter0/frontend0): GetKeyframePositions(12394,9223372036854775807,#45) out of 1125
2010-09-30 20:08:54.223 RecBase(2:/dev/dvb/adapter0/frontend0): GetKeyframePositions(12481,9223372036854775807,#2) out of 1110
2010-09-30 20:08:54.227 Dec: DoFastForward(): desiredFrame(12507) > last_frame(12504)
2010-09-30 20:08:54.442 RecBase(1:/dev/dvb/adapter0/frontend0): GetKeyframePositions(12925,9223372036854775807,#3) out of 1128
2010-09-30 20:08:54.443 Dec: DoFastForward(): desiredFrame(12979) > last_frame(12960)

Any ideas what the problem is?

b.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 198 bytes
Desc: This is a digitally signed message part
URL: <http://mythtv.org/pipermail/mythtv-users/attachments/20101001/e2730a79/attachment.pgp>


More information about the mythtv-users mailing list