Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Alan Stern]

On Tue, 6 Mar 2007, Eric Buddington wrote:

> On Tue, Mar 06, 2007 at 10:36:20AM -0500, Alan Stern wrote:
> > On Tue, 6 Mar 2007, Oliver Neukum wrote:
> > 
> > > > Am Dienstag, 6. M??rz 2007 05:13 schrieb Eric Buddington:
> > > > reiser4[khubd(163)]: commit_current_atom (fs/reiser4/txnmgr.c:1049)[nikita-3176]:
> > > > WARNING: Flushing like mad: 16384
> > > > reiser4[khubd(163)]: commit_current_atom (fs/reiser4/txnmgr.c:1049)[nikita-3176]:
> > > > WARNING: Flushing like mad: 32768
> > > > ...<many simiar messages>
> > > > 
> > > > Most problematically, khubd and ent:sda1! are conspiring to suck 100%
> > > > CPU time, even after powering off the drive. A bunch of processes are
> > > > stuck in 'D' state, possibly because they're trying to access the dead
> > > > disk, which won't umount ("device is busy").
> > > 
> > > It looks like khubd allocates memory and enters reiser4. Possibly we have
> > > GFP_KERNEL in khubd where we should have GFP_NOIO or reiser4 has
> > > a problem dealing with IO failures.
> > 
> > A more complete stack trace (for example, Alt-SysRq-T) would help.

The stack trace didn't include the khubd process at all.  Probably that 
means it had already died.

On the good side, if khubd is dead, it can't be using up 100% of the CPU 
time!  :-)

You need to find out somehow what khubd is doing while it is so busy.  It 
could easily be, like Oliver suggested, that reiser4 is unable to handle 
I/O failures and gets stuck.

Alan Stern

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Eric Buddington]

On Tue, Mar 06, 2007 at 01:34:41PM -0500, Alan Stern wrote:
> The stack trace didn't include the khubd process at all.  Probably that 
> means it had already died.

No, it's still there. I ran 'echo t >/proc/sysrq-trigger' again, and
khubd did not show up in dmesg:

-bash-2.05b# echo t >/proc/sysrq-trigger
-bash-2.05b# dmesg | grep khub
-bash-2.05b# dmesg | grep SysRq
SysRq : Show State
SysRq : Show State
-bash-2.05b# ps ax | grep khubd
  163 ?        R<   633:41 [khubd]
-bash-2.05b# echo p >/proc/sysrq-trigger
-bash-2.05b# dmesg | tail -2
 =======================
SysRq : Show Regs
-bash-2.05b#

So SysRq-t doesn't show anything about khubd, and SysRq-p doesn't give
me anything at all. What else can I try?

-Eric

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Alan Stern]

On Tue, 6 Mar 2007, Eric Buddington wrote:

> On Tue, Mar 06, 2007 at 01:34:41PM -0500, Alan Stern wrote:
> > The stack trace didn't include the khubd process at all.  Probably that 
> > means it had already died.
> 
> No, it's still there. I ran 'echo t >/proc/sysrq-trigger' again, and
> khubd did not show up in dmesg:
> 
> -bash-2.05b# echo t >/proc/sysrq-trigger
> -bash-2.05b# dmesg | grep khub
> -bash-2.05b# dmesg | grep SysRq
> SysRq : Show State
> SysRq : Show State
> -bash-2.05b# ps ax | grep khubd
>   163 ?        R<   633:41 [khubd]
> -bash-2.05b# echo p >/proc/sysrq-trigger
> -bash-2.05b# dmesg | tail -2
>  =======================
> SysRq : Show Regs
> -bash-2.05b#
> 
> So SysRq-t doesn't show anything about khubd, and SysRq-p doesn't give
> me anything at all. What else can I try?

I'm baffled.  khubd should have shown up as the process with ID 163.  Is 
that process listed under a different name?

Alan Stern

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Eric Buddington,,,]

On Wed, Mar 07, 2007 at 11:03:21AM -0500, Alan Stern wrote:
> On Tue, 6 Mar 2007, Eric Buddington wrote:
> 
> > On Tue, Mar 06, 2007 at 01:34:41PM -0500, Alan Stern wrote:
> > > The stack trace didn't include the khubd process at all.  Probably that 
> > > means it had already died.
> > 
> > No, it's still there. I ran 'echo t >/proc/sysrq-trigger' again, and
> > khubd did not show up in dmesg:
> > 
> > -bash-2.05b# echo t >/proc/sysrq-trigger
> > -bash-2.05b# dmesg | grep khub
> > -bash-2.05b# dmesg | grep SysRq
> > SysRq : Show State
> > SysRq : Show State
> > -bash-2.05b# ps ax | grep khubd
> >   163 ?        R<   633:41 [khubd]
> > -bash-2.05b# echo p >/proc/sysrq-trigger
> > -bash-2.05b# dmesg | tail -2
> >  =======================
> > SysRq : Show Regs
> > -bash-2.05b#
> > 
> > So SysRq-t doesn't show anything about khubd, and SysRq-p doesn't give
> > me anything at all. What else can I try?
> 
> I'm baffled.  khubd should have shown up as the process with ID 163.  Is 
> that process listed under a different name?

It does show up under /proc/163, for whatever that's worth.

Going through the list of processes dumped by SysRq-t, here are the
ones I didn't knowingly start myself:

aio/0
ata/0
ata_aux
ent:md1.
events/0
ib_addr
ib_cm/0
ib_mcast
iw_cm_wq
kacpid
kblockd/0
kcryptd/0
khelper
khpsbpkt
kmirrord
kmpathd/0
kprefetchd
kpsmoused
kseriod
ksnapd
ksuspend_usbd
kswapd0
kthread
ktxnmgrd:md1:
ktxnmgrd:sda1
md2_raid1
pdflush
rdma_cm
reiserfs/0
scsi_eh_0 
watchdog/0

And khubd is still showing up as a major CPU consumer.  Interestingly,
ent:sda1! is also absent from the SysRq-t listing, though present (and
using lost of CPU) according to 'top' (ps, oddly, hangs in 'D' state
after listing some processes).

-Eric

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Alan Stern]

On Wed, 7 Mar 2007, Eric Buddington,,, wrote:

> > > So SysRq-t doesn't show anything about khubd, and SysRq-p doesn't give
> > > me anything at all. What else can I try?

How about SysRq-r?

> > I'm baffled.  khubd should have shown up as the process with ID 163.  Is 
> > that process listed under a different name?
> 
> It does show up under /proc/163, for whatever that's worth.

Maybe that means the process is dying but isn't completely dead yet, and 
it's stuck running something inside the reiser4 driver.  Unless we can 
find out what it is, though, there isn't much we can do.

> Going through the list of processes dumped by SysRq-t, here are the
> ones I didn't knowingly start myself:
> 
> aio/0
> ata/0
> ata_aux
> ent:md1.
> events/0
> ib_addr
> ib_cm/0
> ib_mcast
> iw_cm_wq
> kacpid
> kblockd/0
> kcryptd/0
> khelper
> khpsbpkt
> kmirrord
> kmpathd/0
> kprefetchd
> kpsmoused
> kseriod
> ksnapd
> ksuspend_usbd
> kswapd0
> kthread
> ktxnmgrd:md1:
> ktxnmgrd:sda1
> md2_raid1
> pdflush
> rdma_cm
> reiserfs/0
> scsi_eh_0 
> watchdog/0

Most of those (maybe all of them) are built-in kernel threads.

> And khubd is still showing up as a major CPU consumer.  Interestingly,
> ent:sda1! is also absent from the SysRq-t listing, though present (and
> using lost of CPU) according to 'top' (ps, oddly, hangs in 'D' state
> after listing some processes).

Something is badly messed up somewhere, but I have no idea what it could 
be.

These problems start with some USB resets, right?  Did they occur with 
earlier kernel versions, or is this new behavior?

How often does the problem occur?

Alan Stern

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Eric Buddington]

On Wed, Mar 07, 2007 at 03:22:05PM -0500, Alan Stern wrote:
> On Wed, 7 Mar 2007, Eric Buddington,,, wrote:
> 
> > > > So SysRq-t doesn't show anything about khubd, and SysRq-p doesn't give
> > > > me anything at all. What else can I try?
> 
> How about SysRq-r?

SysRq : Keyboard mode set to XLATE

> These problems start with some USB resets, right?  Did they occur with 
> earlier kernel versions, or is this new behavior?

Yes, the problem starts with USB resets (or USB errors that trigger a reset)

> How often does the problem occur?

Recently, the USB drive has choked up after several hours of moderate
use. However, before this instance, it would consistently hang up my
watchdog process and force a system reboot (no idea why; the watchdog
process didn't use this drive at all). This may have changed when I
upgraded from 2.6.20-rc6-mm3 to 2.6.20-mm2, but my sample size is to
small to be sure.

-Eric

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Alan Stern]

On Wed, 7 Mar 2007, Eric Buddington wrote:

> On Wed, Mar 07, 2007 at 03:22:05PM -0500, Alan Stern wrote:
> > On Wed, 7 Mar 2007, Eric Buddington,,, wrote:
> > 
> > > > > So SysRq-t doesn't show anything about khubd, and SysRq-p doesn't give
> > > > > me anything at all. What else can I try?
> > 
> > How about SysRq-r?
> 
> SysRq : Keyboard mode set to XLATE

Whoops, I was thinking of SysRq-p, which you have already tried.

> > These problems start with some USB resets, right?  Did they occur with 
> > earlier kernel versions, or is this new behavior?
> 
> Yes, the problem starts with USB resets (or USB errors that trigger a reset)
> 
> > How often does the problem occur?
> 
> Recently, the USB drive has choked up after several hours of moderate
> use. However, before this instance, it would consistently hang up my
> watchdog process and force a system reboot (no idea why; the watchdog
> process didn't use this drive at all). This may have changed when I
> upgraded from 2.6.20-rc6-mm3 to 2.6.20-mm2, but my sample size is to
> small to be sure.

What about earlier kernels?  Does 2.6.19 work any better?

What about non -mm kernels, like 2.6.21-rc2?

I've never heard of a process failing to show up in a SysRq-t listing.  It 
suggests something is wrong with the process management in the kernel you 
were using.  That leads me to think a non -mm kernel might give more 
informative results.

And as long as you're testing, you might as well also turn on 
CONFIG_USB_DEBUG.

Alan Stern

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Pete Zaitcev]

On Wed, 7 Mar 2007 17:18:29 -0500 (EST), Alan Stern <stern@rowland.harvard.edu> wrote:

> I've never heard of a process failing to show up in a SysRq-t listing.  It 
> suggests something is wrong with the process management in the kernel you 
> were using.  That leads me to think a non -mm kernel might give more 
> informative results.

I think, if a process is looping, it's not shown in SysRq-t. So maybe
khubd is on a CPU.

In RHEL we have a patch for SysRq-w, which showed all CPU states by
the way of a special IPI (unless looping with closed interrups, of course).
But this capability seems a bit degraded in stock SysRq-w. It might not
catch this (does not seem for me in 2.6.20).

Another possibility is, something killed khubd. It's only a process
after all. Remember how we had grief with it being killed by "telinit 1".

-- Pete

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Alan Stern]

On Wed, 7 Mar 2007, Pete Zaitcev wrote:

> On Wed, 7 Mar 2007 17:18:29 -0500 (EST), Alan Stern <stern@rowland.harvard.edu> wrote:
> 
> > I've never heard of a process failing to show up in a SysRq-t listing.  It 
> > suggests something is wrong with the process management in the kernel you 
> > were using.  That leads me to think a non -mm kernel might give more 
> > informative results.
> 
> I think, if a process is looping, it's not shown in SysRq-t. So maybe
> khubd is on a CPU.

You mean, if it is currently running?  I don't believe that.  A simple 
test comparison shows every process listed in "ps -A" also listed in 
SysRq-t.

> In RHEL we have a patch for SysRq-w, which showed all CPU states by
> the way of a special IPI (unless looping with closed interrups, of course).
> But this capability seems a bit degraded in stock SysRq-w. It might not
> catch this (does not seem for me in 2.6.20).
> 
> Another possibility is, something killed khubd. It's only a process
> after all. Remember how we had grief with it being killed by "telinit 1".

If it was killed then it wouldn't show up in "ps" or as a directory under 
/proc.

Alan Stern

Re: khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Oliver Neukum]

Am Dienstag, 6. März 2007 05:13 schrieb Eric Buddington:
> reiser4[khubd(163)]: commit_current_atom (fs/reiser4/txnmgr.c:1049)[nikita-3176]:
> WARNING: Flushing like mad: 16384
> reiser4[khubd(163)]: commit_current_atom (fs/reiser4/txnmgr.c:1049)[nikita-3176]:
> WARNING: Flushing like mad: 32768
> ...<many simiar messages>
> 
> Most problematically, khubd and ent:sda1! are conspiring to suck 100%
> CPU time, even after powering off the drive. A bunch of processes are
> stuck in 'D' state, possibly because they're trying to access the dead
> disk, which won't umount ("device is busy").

It looks like khubd allocates memory and enters reiser4. Possibly we have
GFP_KERNEL in khubd where we should have GFP_NOIO or reiser4 has
a problem dealing with IO failures.

	Regards
		Oliver

Re: [linux-usb-devel] khubd and ent:sda1 sucking CPU with reiser4 + USB HD

[Alan Stern]

On Tue, 6 Mar 2007, Oliver Neukum wrote:

> > Am Dienstag, 6. März 2007 05:13 schrieb Eric Buddington:
> > reiser4[khubd(163)]: commit_current_atom (fs/reiser4/txnmgr.c:1049)[nikita-3176]:
> > WARNING: Flushing like mad: 16384
> > reiser4[khubd(163)]: commit_current_atom (fs/reiser4/txnmgr.c:1049)[nikita-3176]:
> > WARNING: Flushing like mad: 32768
> > ...<many simiar messages>
> > 
> > Most problematically, khubd and ent:sda1! are conspiring to suck 100%
> > CPU time, even after powering off the drive. A bunch of processes are
> > stuck in 'D' state, possibly because they're trying to access the dead
> > disk, which won't umount ("device is busy").
> 
> It looks like khubd allocates memory and enters reiser4. Possibly we have
> GFP_KERNEL in khubd where we should have GFP_NOIO or reiser4 has
> a problem dealing with IO failures.

A more complete stack trace (for example, Alt-SysRq-T) would help.

Alan Stern