Opened 18 years ago

Closed 18 years ago

#714 closed defect (fixed)

Changes to TFW after 7738 cause IOBOUND to damage files.

Reported by: bjm Owned by: danielk
Priority: major Milestone: 0.19
Component: mythtv Version: head
Severity: high Keywords:
Cc: Ticket locked: no

Description

Recently I've had several recordings damaged in a way that prevents files from being read past a certain point. In examining the backend logs, the following message always appears in the logs at the same point in the recording as the point where playback fails.

2005-11-25 19:30:00.481 TFW, Error: Write() -- IOBOUND begin cnt(11493) free(11143)

...with only the time, cnt and free values varying. This happens on both master an slave and occurs during about 1 in 20 recordings. The logs also show the commflagger failing to read the file within two minutes after the error. IOBOUND errors have always cropped up every few days but it had never resulted in damaged files until jumping from pre-live disable to live TV enabled again. The changes to TFW were [7796], [7802], [7816], and [7846].

Master log:
grep '\(IOBOUND\|mpeg4\)' /video/mythtv/mb.log
2005-10-09 22:56:55.804 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-11 22:31:13.822 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-12 20:58:49.282 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-12 23:43:05.571 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-13 15:59:55.061 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-13 21:29:00.523 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-15 14:13:35.288 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-18 18:02:08.022 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-18 18:59:19.080 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-21 18:35:08.897 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-23 17:13:57.214 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-24 03:15:37.897 IOBOUND - blocking in ThreadedFileWriter::Write()
[mpeg4 @ 0xb76df924]insufficient thread locking around avcodec_open/close()
2005-10-24 14:49:36.599 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-25 22:45:30.213 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-27 21:16:50.309 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-27 22:38:19.963 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-31 20:24:46.153 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-31 23:37:35.732 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-01 21:05:16.501 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-03 17:40:31.760 IOBOUND - blocking in ThreadedFileWriter::Write()
[mpeg4 @ 0xb77005a4]insufficient thread locking around avcodec_open/close()
2005-11-04 11:22:14.566 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-04 12:24:26.962 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-11 00:59:57.458 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-11 23:21:06.109 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-16 18:30:04.766 TFW, Error: Write() -- IOBOUND begin cnt(23738) free(18330)
2005-11-16 18:30:04.901 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb76554c4]ac-tex damaged at 28 5
[mpeg4 @ 0xb76554c4]Error at MB: 183
[mpeg4 @ 0xb76554c4]concealing 773 DC, 773 AC, 773 MV errors
2005-11-19 17:06:00.078 TFW, Error: Write() -- IOBOUND begin cnt(19289) free(647)
2005-11-19 17:06:00.867 TFW, Error: Write() -- IOBOUND end
2005-11-19 17:42:07.947 TFW, Error: Write() -- IOBOUND begin cnt(20545) free(3501)
2005-11-19 17:42:08.535 TFW, Error: Write() -- IOBOUND end
2005-11-21 18:59:21.348 TFW, Error: Write() -- IOBOUND begin cnt(35215) free(9931)
2005-11-21 18:59:21.598 TFW, Error: Write() -- IOBOUND end
2005-11-24 09:16:31.369 TFW, Error: Write() -- IOBOUND begin cnt(17257) free(8717)
2005-11-24 09:16:32.344 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb76deee4]1. marker bit missing in 3. esc
[mpeg4 @ 0xb76deee4]Error at MB: 146
[mpeg4 @ 0xb76deee4]concealing 807 DC, 807 AC, 807 MV errors
2005-11-25 11:55:50.924 TFW, Error: Write() -- IOBOUND begin cnt(20143) free(20010)
2005-11-25 11:55:51.315 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb762bee4]slice end not reached but screenspace end (4502 left 7D04CC, score= -46358)
[mpeg4 @ 0xb762bee4]concealing 900 DC, 900 AC, 900 MV errors

The 'insufficient thread locking' never resulted in a damaged file. Not every show was commflaged to log the mpeg4 errors while reading but I believe each file with "TFW, Error: Write() -- IOBOUND" had been unreadable past the point of the error, That is, when playing or seeking forward, playback treats this point as the end of file and exits to the deletion popup.

Slave log:
grep '\(IOBOUND\|mpeg4\)' /video/mythtv/mb.log
2005-10-06 20:05:11.537 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-07 08:06:38.127 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-10-07 16:11:18.397 IOBOUND - blocking in ThreadedFileWriter::Write()

...about two per day ubtil...

2005-11-17 21:00:57.362 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-17 21:37:19.809 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-17 23:03:11.831 IOBOUND - blocking in ThreadedFileWriter::Write()
2005-11-19 17:02:56.153 TFW, Error: Write() -- IOBOUND begin cnt(21726) free(15171)
2005-11-19 17:02:56.556 TFW, Error: Write() -- IOBOUND end
2005-11-19 19:37:16.062 TFW, Error: Write() -- IOBOUND begin cnt(20687) free(7619)
2005-11-19 19:37:16.921 TFW, Error: Write() -- IOBOUND end
2005-11-21 03:17:06.558 TFW, Error: Write() -- IOBOUND begin cnt(15610) free(11815)
2005-11-21 03:17:07.879 TFW, Error: Write() -- IOBOUND end
2005-11-21 20:26:41.210 TFW, Error: Write() -- IOBOUND begin cnt(12579) free(4728)
2005-11-21 20:26:41.436 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb76f3ee4]ac-tex damaged at 12 8
[mpeg4 @ 0xb76f3ee4]Error at MB: 260
[mpeg4 @ 0xb76f3ee4]concealing 697 DC, 697 AC, 697 MV errors
2005-11-22 21:09:21.474 TFW, Error: Write() -- IOBOUND begin cnt(11020) free(6820)
2005-11-22 21:09:22.811 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb763dee4]ac-tex damaged at 17 16
[mpeg4 @ 0xb763dee4]Error at MB: 433
[mpeg4 @ 0xb763dee4]concealing 391 DC, 391 AC, 391 MV errors
[mpeg4 @ 0xb7721ee4]insufficient thread locking around avcodec_open/close()
2005-11-24 20:28:33.093 TFW, Error: Write() -- IOBOUND begin cnt(12718) free(2083)
2005-11-24 20:28:40.713 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb7697ee4]slice end not reached but screenspace end (30886 left 7D04CC, score= -51406)
[mpeg4 @ 0xb7697ee4]concealing 900 DC, 900 AC, 900 MV errors
2005-11-24 21:08:03.086 TFW, Error: Write() -- IOBOUND begin cnt(13486) free(11761)
2005-11-24 21:08:03.420 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb765aee4]concealing 587 DC, 587 AC, 587 MV errors
2005-11-25 19:30:00.481 TFW, Error: Write() -- IOBOUND begin cnt(11493) free(11143)
2005-11-25 19:30:00.595 TFW, Error: Write() -- IOBOUND end
[mpeg4 @ 0xb766aee4]header damaged
[mpeg4 @ 0xb766aee4]header damaged

Attachments (1)

diskloop-rv.patch (3.8 KB) - added by danielk 18 years ago.
backs out diskloop changes

Download all attachments as: .zip

Change History (5)

comment:1 Changed 18 years ago by danielk

Try reverting [7846], the others in your list are unlikely to cause any problems.

I'm planning to back it out whether it is the cause of your problem or not. But if it is the cause, I'll back it out sooner rather than later.

Changed 18 years ago by danielk

Attachment: diskloop-rv.patch added

backs out diskloop changes

comment:2 Changed 18 years ago by danielk

I've attached a small patch that backs out the diskloop changes in 7846. Give it a try.

comment:3 Changed 18 years ago by bjm <bjm@…>

Applied, though I can't reproduce this on demand so I'll have to watch for a few days to see if I get IOBOUND without damage.

comment:4 Changed 18 years ago by bjm

Resolution: fixed
Status: newclosed

(In [8050]) Closes #714

Applying danielk's diskloop-rv.patch. I've had two IOBOUND incidents in the past 24hours and neither of them resulted in any decode errors. One showed some resyncing after some dropped frames and the other, with a shorter duration, showed no flaws and both played past the point with no problems.

Note: See TracTickets for help on using tickets.