[mythtv-users] Mythbackend causing high load

Mike Benoit ipso at snappymail.ca
Mon Jun 26 03:12:50 UTC 2006


NOTE: I'm cc'ing this to the ReiserFS list, as it appears to be related.

I finally got around to profiling mythbackend when the load starts to
spike up around 10. To my surprise it appears that reiserfs is the
culprit, maybe the ReiserFS guys have some input as to what is causing
this?

#opreport
CPU: CPU with timer interrupt, speed 0 MHz (estimated)
Profiling through timer interrupt
          TIMER:0|
  samples|      %|
------------------
    77863 78.7856 reiserfs
    18183 18.3984 vmlinux
      695  0.7032 mysqld
      452  0.4574 libc-2.4.so
      360  0.3643 libmythtv-0.19.so.0.19.0
      324  0.3278 ivtv
      323  0.3268 nvidia
      242  0.2449 libqt-mt.so.3.3.6
      110  0.1113 libpthread-2.4.so
       53  0.0536 libstdc++.so.6.0.8
       35  0.0354 ld-2.4.so
       23  0.0233 libperl.so
       22  0.0223 libz.so.1.2.3
<snip>

#opreport -l /usr/src/linux/vmlinux
CPU: CPU with timer interrupt, speed 0 MHz (estimated)
Profiling through timer interrupt
samples  %        symbol name
9607     52.8351  default_idle
7694     42.3142  find_next_zero_bit
183       1.0064  __copy_from_user_ll
57        0.3135  handle_IRQ_event
37        0.2035  __copy_to_user_ll
34        0.1870  ide_outb
30        0.1650  ide_end_request
22        0.1210  ioread8
22        0.1210  schedule
21        0.1155  get_page_from_freelist
17        0.0935  mmx_clear_page
<snip>

System Details:
-----------------------------------------------
Kernel v2.6.16.21 (custom compiled)
- This issue also happened with 2.6.14 too though.

Filesystem            Size  Used Avail Use% Mounted on
/dev/hda1             280G  269G   12G  97% /

[root at mythtv]# cat /proc/mounts
rootfs / rootfs rw 0 0
/dev /dev tmpfs rw 0 0
/dev/root / reiserfs rw,noatime,nodiratime 0 0

[root at mythtv]# cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 6
model           : 6
model name      : AMD Athlon(tm) XP 2100+
stepping        : 2
cpu MHz         : 1759.680
cache size      : 256 KB

[root at mythtv]# free
             total       used       free     shared    buffers
cached
Mem:        515992     496256      19736          0      36256
271728
-/+ buffers/cache:     188272     327720
Swap:       262136        408     261728


Syslog:
-------------------------------------------------
Jun 25 19:52:22 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:52:22 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:52:57 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:52:57 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:53:00 mythtv kernel: ivtv0: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:53:00 mythtv kernel: ivtv0: Cause: the application is not
reading fast enough.
Jun 25 19:53:32 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:53:32 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:53:35 mythtv kernel: ivtv0: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:53:35 mythtv kernel: ivtv0: Cause: the application is not
reading fast enough.
Jun 25 19:54:01 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:54:01 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:54:16 mythtv kernel: ivtv0: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:54:16 mythtv kernel: ivtv0: Cause: the application is not
reading fast enough.
Jun 25 19:54:36 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:54:36 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:54:47 mythtv kernel: ivtv0: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:54:47 mythtv kernel: ivtv0: Cause: the application is not
reading fast enough.
Jun 25 19:55:08 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:55:08 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:55:19 mythtv kernel: ivtv0: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:55:19 mythtv kernel: ivtv0: Cause: the application is not
reading fast enough.
Jun 25 19:55:39 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:55:39 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:55:57 mythtv kernel: ivtv0: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:55:57 mythtv kernel: ivtv0: Cause: the application is not
reading fast enough.
Jun 25 19:56:11 mythtv kernel: ivtv1: All encoder MPEG stream buffers
are full. Dropping data.
Jun 25 19:56:11 mythtv kernel: ivtv1: Cause: the application is not
reading fast enough.
Jun 25 19:56:33 mythtv kernel: ivtv0: All encoder MPEG stream buffers
are full. Dropping data.


mythbackend log:
--------------------------------------------------------
2006-06-25 19:51:43.906 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:44.836 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:44.842 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:45.022 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:45.028 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:46.123 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:46.129 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:47.500 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:48.094 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:48.099 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:48.370 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:48.376 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:48.922 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:48.928 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:50.650 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:50.657 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:50.660 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:50.697 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:52.195 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:52.201 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:52.450 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:52.457 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:54.369 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:54.375 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:54.644 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:54.650 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:55.423 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:55.429 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:56.057 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:56.063 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:56.481 TFW, Error: Write() -- IOBOUND end
2006-06-25 19:51:56.487 TFW, Error: Write() -- IOBOUND begin cnt(2048)
free(2047)
2006-06-25 19:51:57.746 TFW, Error: Write() -- IOBOUND end


On Fri, 2006-06-16 at 12:58 -0500, Stuart Larson wrote:
> I've seen this sort of behavior when recoding or transcoding (doesn't seem
> to make a difference which) when my free space on drive was close to what
> Myth is set to keep free - I have Myth set to keep 20G free, and when it
> reached around 22-23G free, I started seeing this behavior (I'm running
> reiserfs, so the xfs space-free thing shouldn't be an issue).  Not sure if
> it would be related...  The recordings did work fine (PVR-250), but
> watching while recording doesn't work very well.
> 
> > I'm seeing something very familiar, mythbackend uses about 100% CPU
> > during a recording and though not always, I sometimes see IOBOUND errors
> > in the log. I have transcode/commflag jobs set to run after midnight
> > each day, and no other processes are using CPU while mythbackend is
> > hogging it all.
> >
> > The weird thing is my box was running fine for a few months prior to a
> > power outage. After the outage I booted up the box and I started to
> > notice IVTV buffer overflows happening during every recording causing
> > the load to spike up to 10+ during each recording. The recording was
> > useless of course too. This was with IVTV 0.4.1 on a PVR-500.
> >
> > So I decided to upgrade to IVTV 0.4.5 to see if that solved the problem.
> > Well, I no longer see IVTV buffer overflow messages in the log, but now
> > mythbackend uses 100% CPU. I upgraded to the latest SVN snapshot of
> > 019-fixes branch to see if that helped at all, but it didn't.
> >
> > So now mythbackend uses 100% CPU, the recordings seem to be working
> > fine, but I can't watch any recordings while this is happening.
> >
> > I'm running an Athlon 2100 with kernel 2.6.14.
> >
> > Just last week I could have two recordings going at once, mythcomm flag
> > running in real-time, and two frontends both watching recordings with no
> > issues at all. Now one recording at a time and NOTHING else is all that
> > can happen. :(
> >
> > Does anyone know what I can do to try and track this issue down?
> >
> > Thanks.
> >
> > On Fri, 2006-06-16 at 06:41 -0400, Jeff wrote:
> >> On 6/15/06, Ryan Steffes <rbsteffes at gmail.com> wrote:
> >>
> >> > Do you, by any chance, have a slave to offload the transcode onto?
> >> Try
> >> > disabling transcode jobs on that backend, and see if it comes back.
> >> Mine
> >> > hasn't since then, even though it's a less than ideal fix.
> >> >
> >>
> >> For the most part I don't do transcoding. I do have a 'transcode for
> >> ipod'
> >> job which seems to have gotten itself attached to every recording (it
> >> was
> >> only supposed to be one show) but I don't think its working at the
> >> moment.
> >>
> >> I do commercial flagging though at the end of each show.
> >>
> >> I can try moving this to a slave backend.
> >> _______________________________________________
> >> mythtv-users mailing list
> >> mythtv-users at mythtv.org
> >> http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-users
> > --
> > Mike Benoit <ipso at snappymail.ca>
> > _______________________________________________
> > mythtv-users mailing list
> > mythtv-users at mythtv.org
> > http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-users
> >
> 
> 
> _______________________________________________
> mythtv-users mailing list
> mythtv-users at mythtv.org
> http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-users
-- 
Mike Benoit <ipso at snappymail.ca>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
Url : http://mythtv.org/pipermail/mythtv-users/attachments/20060625/5c15721e/attachment.pgp 


More information about the mythtv-users mailing list