Opened 9 years ago

Closed 9 years ago

#9709 closed Bug Report - General (Fixed)

TFW IOBOUND

Reported by: spamme@… Owned by: danielk
Priority: minor Milestone: 0.25
Component: MythTV - Recording Version: Master Head
Severity: medium Keywords:
Cc: Ticket locked: yes

Description

I keep getting these messages at the start of recordings. Between 1 and 5 (sometimes more) occurences at the beginning of every recording.

TFW IOBOUND 5169 free(0) size (4194304) cnr(1)

Normally, I assume that this message means your hard drive isn't good enough. However, this is NOT the case.

The OS and mysql are on 1 hard drive and recordings on another.

I have a RAID 6 array with hardware controller, 4GB of RAM, and a AMD Quad Core 3Ghz processor dedicated to mythtv and general file storage.

Assuming that 4194304 is a size in bytes, that is so small that it is useless, 4MB of buffer???? How do I increase this tiny number. Since even the most humble hard drives should be able to push 40mb/s I would like a 40mb buffer. Either that or a buffer that automatically expands and contracts as needed.

I am especially concern because I have 4 HD tuners if 4MB isn't enough for 1 HDTV stream it certainly can't handle 4 at once. My lowest RAID 6 speed is 100mb/s write and 500mb/s read. Typically write speeds are 200mb/s and read speed can reach 650mb/s.

I found a "HD ringbuffer size" setting in mythtv-setup->General and I slowly cranked it up to its max of 96,256kb of ram to no effect.

I have tons of system resources including TB of free space on the RAID and etc. This message should not be happening to me. Mythtv could use 500mb of ram as a buffer and I wouldn't care, but getting IOBOUND on my system must indicate an inefficiency in the code.

A HD recording is about 2-4mb/s each, and with modern hardware we should never be IOBOUND. Ten concurrent recording should max at about 40mb/s a number well within any modern hard drives capabilities.

I have extensively benchmarked all hardware and have upgraded to newer and faster equipment. I am still getting TFW IOBOUND...... My hardware is WAY above what I should *need*.

Attachments (2)

blah1.txt (100.2 KB) - added by spamme@… 9 years ago.
blah2.txt (987 bytes) - added by spamme@… 9 years ago.

Download all attachments as: .zip

Change History (17)

comment:1 Changed 9 years ago by spamme@…

additionally sometimes I get these messages:

2011-04-02 22:58:12.423 DevRdB(/dev/dvb/adapter0/frontend0) Error: Driver buffers overflowed

2011-04-02 23:20:30.023 DevRdB(/dev/dvb/adapter0/frontend0) Error: Poll giving up 2011-04-02 23:20:30.028 DVBSH(/dev/dvb/adapter0/frontend0) Error: Device error detected 2011-04-02 23:20:30.082 DVBRec(1:/dev/dvb/adapter0/frontend0) Error: Stream handler died unexpectedly.

comment:2 Changed 9 years ago by Raymond Wagner

Next time you start seeing these errors, could you run

iostat -xk 2

and see what %util is for the recording drive?

comment:3 Changed 9 years ago by spamme@…

Although, I don't have another scheduled recording I have recorded a program at random, and these numbers are typical. I am trying to find another 1920x1080 program though. Typically usage is <5%, but in 5% of time as much as 40%.

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.38    0.00    2.12    0.00    0.00   96.50

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb               0.00   263.00    0.00    8.50     0.00  1086.00   255.53     0.01    0.88   0.18   0.15


comment:4 Changed 9 years ago by spamme@…

I tried another show and it didn't happen for it *yet*, but it ALWAYS happens with Dr. Who. One of the few shows that are actually worth watching, and good enough to watch again and again.

Changed 9 years ago by spamme@…

Attachment: blah1.txt added

Changed 9 years ago by spamme@…

Attachment: blah2.txt added

comment:5 Changed 9 years ago by spamme@…

blah1.txt is the iostat results blah2.txt is the error message from mythbackend

I understand it thinks the utilization is high, but the numbers are puzzling. It is reading and writing less than 2mb/s. It must be some kind of in-efficiency. I can do 100mb from my PC to mythdvr and not see numbers that high.

comment:6 Changed 9 years ago by spamme@…

after start up numbers drop to:

Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util sda 0.00 12.00 0.00 23.50 0.00 142.00 12.09 0.25 10.77 0.36 0.85 sdb 0.00 550.50 0.00 15.00 0.00 2262.00 301.60 0.01 0.87 0.17 0.25

comment:7 Changed 9 years ago by spamme@…

after start up number drop to: (sorry about the lost formatting)

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00    12.00    0.00   23.50     0.00   142.00    12.09     0.25   10.77   0.36   0.85
sdb               0.00   550.50    0.00   15.00     0.00  2262.00   301.60     0.01    0.87   0.17   0.25


comment:8 Changed 9 years ago by danielk

Can you test with the mythtv-rec2 branch? This problem should be fixed there.

comment:9 in reply to:  8 Changed 9 years ago by spamme@…

Replying to danielk:

Can you test with the mythtv-rec2 branch? This problem should be fixed there.

I could try it if I new how to. I usually just do a "git pull".

How should I access this mythtv-rec branch you speak of???

comment:10 Changed 9 years ago by Github

Milestone: unknown0.25
Resolution: fixed
Status: newclosed

Merge of various recorder changes from mythtv-rec2.

  • Fixes #9191. Channel switching doesn't work with cx18 driver.
  • Fixes #9451. IPTVRecorder doesn't produce proper TS packets for big DVB tables.
  • Fixes #9709. TFW IOBOUND.
  • This also fixes pause status locking in various recorders.
  • This also replaces a few spinlocks with QWaitConditions.
  • This also adds a DVB ASI recorder implementation in just 1033 lines. (Uninteresting to most).
  • This makes changes to the DeviceReadBuffer? to make it more efficient and quicker to respond.
  • This changes the ThreadedFileWriter? so that it can expand the level of buffering it does when there are temporary slowdowns in writing to disk.

This will probably cause some regressions, that's why I'm pushing this on a Monday. This refactors all the recorders and stream readers to eliminate a lot of duplicate code, and also fixes a number of small bugs and long time annoyances see the dkristjansson/mythtv-rec branch for details.

Branch: master Changeset: 9b22460f53bf6313516f33987e4260897c6076a3

comment:11 Changed 9 years ago by spamme@…

2011-05-16 16:28:01.784 Tuning recording: "Judge Judy": channel 1061 on cardid 1     , sourceid 1
2011-05-16 16:28:01.785 scheduler: Tuning recording: "Judge Judy": channel 1061      on cardid 1, sourceid 1
2011-05-16 16:28:02.445 Updating status for "Judge Judy" on cardid 1 (Tuning =>      Recording)
2011-05-16 16:28:02.820 TVRec(1): rec->GetPathname(): '/r6Myth/tv/1061_201105161     62800.mpg'
2011-05-16 16:28:02.820 RecBase(1:) Error: SetOption(): Unknown int option: dvb_     on_demand: 0
2011-05-16 16:28:04.806 MainServer::ANN Monitor
2011-05-16 16:28:04.806 adding: mythdvr as a client (events: 2)
2011-05-16 16:28:42.204 TFW(/r6Myth/tv/1061_20110516162800.mpg:46), Warning: write(376) cnt 1265 total 73413060 -- took a long time, 39134 ms
2011-05-16 16:29:13.517 TFW(/r6Myth/tv/1061_20110516162800.mpg:46), Warning: write(57904) cnt 2140 total 124363880 -- took a long time, 31313 ms
2011-05-16 16:29:20.105 TFW(/r6Myth/tv/1061_20110516162800.mpg:46), Error: Maximum buffer size exceeded.
                        file will be truncated, no further writing will be done.
                        This generally indicates your disk performance
                        is insufficient to deal with the number of on-going
                        recordings, or you have a disk failure.
2011-05-16 16:29:24.603 TFW(/r6Myth/tv/1061_20110516162800.mpg:46), Warning: write(57528) cnt 2310 total 134213388 -- took a long time, 10676 ms



I have no idea why write speed is so bad but it isn't my hardware!!!

If I break CTRL-C mythbackend and re-launch it, it starts recording a bit better.

comment:12 Changed 9 years ago by spamme@…

Resolution: fixed
Status: closednew

bonnie++ says 212461kb/s write speed or about 200mb/s for those without a calculator handy.

comment:13 Changed 9 years ago by spamme@…

The incoming data rate is about 2000k/s, why does the ThreadedFileWrite? write at 64kb per interval??? = FAIL.

comment:14 Changed 9 years ago by spamme@…

512k works a lot better for me. However I still get: 2011-05-16 16:55:27.999 RecBase?(1:) Error: SetOption?(): Unknown int option: dvb_on_demand: 0

comment:15 Changed 9 years ago by danielk

Resolution: Fixed
Status: newclosed
Ticket locked: set

Please do not use tickets for discussion. I've posted a reply to the mailing list.

Note: See TracTickets for help on using tickets.