Badness in local_bh_enable

Badness in local_bh_enable

[Diwaker Gupta]

+ Summary:
Getting repeated badness in local_bh_enable messages in syslog.

+ Description:
Here's a sample output from dmesg:
Badness in local_bh_enable at kernel/softirq.c:121
Call Trace:
 [<c01241f9>] local_bh_enable+0x89/0x90
 [<c012f985>] worker_thread+0x1c5/0x260
 [<e0995230>] xmit_bh+0x0/0xe0 [ndiswrapper]
 [<c011ccb0>] default_wake_function+0x0/0x20
 [<c010b2d2>] ret_from_fork+0x6/0x14
 [<c011ccb0>] default_wake_function+0x0/0x20
 [<c012f7c0>] worker_thread+0x0/0x260
 [<c01092a5>] kernel_thread_helper+0x5/0x10

+ Environment
Linux 2.6.3 vanilla from kernel.org
LIRC patch from <http://flameeyes.web.ctonet.it/downloads.html#lirc>

I searched the archives and got a few lines here and there talking about
PPP problems giving rise to similar messages. However, I'm not using PPP
at all, and was having no such messages till 2.6.2. There were also some
messages talking about IrDA issues, and I am using IrDA (which works fine).

If this indeed is an IrDA problem, where can I find patches to fix it.
If not, what else could be the problem?

Thanks
-- 
Diwaker Gupta
Graduate Student, Computer Sc. and Engg.
University of California, San Diego
<http://www.cs.ucsd.edu/~dgupta>

Badness in local_bh_enable

[Nicholas Lee]

I'm getting a whole pile of this error messages in the dom0 syslog.

Mar  7 22:34:38 stateless kernel: Badness in local_bh_enable at kernel/softirq.c:140
Mar  7 22:34:38 stateless kernel:  [local_bh_enable+130/144] local_bh_enable+0x82/0x90
Mar  7 22:34:38 stateless kernel:  [skb_checksum+317/720] skb_checksum+0x13d/0x2d0
Mar  7 22:34:38 stateless kernel:  [udp_poll+154/352] udp_poll+0x9a/0x160
Mar  7 22:34:38 stateless kernel:  [sock_poll+41/64] sock_poll+0x29/0x40
Mar  7 22:34:38 stateless kernel:  [do_pollfd+149/160] do_pollfd+0x95/0xa0
Mar  7 22:34:38 stateless kernel:  [do_poll+106/208] do_poll+0x6a/0xd0
Mar  7 22:34:38 stateless kernel:  [sys_poll+353/576] sys_poll+0x161/0x240
Mar  7 22:34:38 stateless kernel:  [sys_gettimeofday+60/144] sys_gettimeofday+0x3c/0x90
Mar  7 22:34:38 stateless kernel:  [__pollwait+0/208] __pollwait+0x0/0xd0
Mar  7 22:34:38 stateless kernel:  [syscall_call+7/11] syscall_call+0x7/0xb
Mar  7 22:34:38 stateless kernel: Badness in local_bh_enable at kernel/softirq.c:140
Mar  7 22:34:38 stateless kernel:  [local_bh_enable+130/144] local_bh_enable+0x82/0x90
Mar  7 22:34:38 stateless kernel:  [skb_checksum+317/720] skb_checksum+0x13d/0x2d0
Mar  7 22:34:38 stateless kernel:  [udp_poll+154/352] udp_poll+0x9a/0x160
Mar  7 22:34:38 stateless kernel:  [sock_poll+41/64] sock_poll+0x29/0x40
Mar  7 22:34:38 stateless kernel:  [do_pollfd+149/160] do_pollfd+0x95/0xa0
Mar  7 22:34:38 stateless kernel:  [do_poll+106/208] do_poll+0x6a/0xd0
Mar  7 22:34:38 stateless kernel:  [sys_poll+353/576] sys_poll+0x161/0x240
Mar  7 22:34:38 stateless kernel:  [sys_gettimeofday+60/144] sys_gettimeofday+0x3c/0x90
Mar  7 22:34:38 stateless kernel:  [__pollwait+0/208] __pollwait+0x0/0xd0
Mar  7 22:34:38 stateless kernel:  [syscall_call+7/11] syscall_call+0x7/0xb


I suspect they a caused by some clash between bridging and running a
openvpn/tun in a domU. I'm not certain on this though.

AFAICT it doesn't seem to affect the operation of the machine.

Suggestions on how to track this down.

Version:
 Xen version 2.0.4 (nic@localdomain) (gcc version 3.3.5 (Debian 1:3.3.5-6)) Fri Feb 25 06:16:12 NZDT 2005
 Latest ChangeSet: 2005/02/04 13:01:10 1.1715 42037216PTjBGQVeEeiwiYxP_vJuyw


Thanks.
Nicholas


-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_id=6595&alloc_id=14396&op=click

RE: Badness in local_bh_enable

[Ian Pratt]

> I suspect they a caused by some clash between bridging and running a
> openvpn/tun in a domU. I'm not certain on this though.
> 
> AFAICT it doesn't seem to affect the operation of the machine.

I'll wager that you compiled some external modules for your kernel and
forgot to specify "ARCH=xen". i386 modules are sufficiently similar to
xen/i386 modules that by some miracle many seem to limp along. In this
case, the driver is probably trying to do cli/sti which are failing
silently due to the ring 1 kernel having insufficient privilege. We've
discussed virtualising iopl such that we could trap (and potentially
emulate) such occurences. 

I did some analysis and I reckon that it should be posible to get the
vast majority of i386 modules to work fine. This means that i386 and
xen/i386 could share a module set. 
The remaining modules could probably be slightly modified to work too
(e.g. the BusLogic drivers use inlined virt_to_bus directly).

Is this something the distros would be keen on? If so, anyone want to
help?

Ian


-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_ide95&alloc_id\x14396&op=click

Re: Badness in local_bh_enable

[Nicholas Lee]

On Mon, Mar 07, 2005 at 10:03:35AM -0000, Ian Pratt wrote:
> I'll wager that you compiled some external modules for your kernel and
> forgot to specify "ARCH=xen". i386 modules are sufficiently similar to
> xen/i386 modules that by some miracle many seem to limp along. In this
> case, the driver is probably trying to do cli/sti which are failing
> silently due to the ring 1 kernel having insufficient privilege. We've
> discussed virtualising iopl such that we could trap (and potentially
> emulate) such occurences. 

Is there a way of telling if a module has not been compiled for Xen?

Its possible I might have on one occasion run 'make' with 'ARCH=xen' on
one occasion in the domU linux src directory. Then later realised by
mistake and recompile with the correct ARCH statement. So modules from
the previous non-ARCHed compile run might have polluted the modules and
been installed.



Nicholas


-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_id=6595&alloc_id=14396&op=click

RE: Badness in local_bh_enable

[Ian Pratt]

> Is there a way of telling if a module has not been compiled for Xen?

You can tell what the kernel version that it was compiled against by
doing:
  strings module.ko | grep vermagic=

If you have a extraversion of "-xen0" in your kernel you should see it
in the vermagic.

Alternatively, in your current case you can probably tell by doing:
 objdump -d module.ko | grep cli

If you have cli instructions, its not a Xen module (or the source is
horibly broken).

Ian


-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_ide95&alloc_id\x14396&op=click

Re: Badness in local_bh_enable

[Nicholas Lee]

On Mon, Mar 07, 2005 at 09:55:36PM -0000, Ian Pratt wrote:
> > Is there a way of telling if a module has not been compiled for Xen?
> 
> You can tell what the kernel version that it was compiled against by
> doing:
>   strings module.ko | grep vermagic=
> 
> If you have a extraversion of "-xen0" in your kernel you should see it
> in the vermagic.
> 
> Alternatively, in your current case you can probably tell by doing:
>  objdump -d module.ko | grep cli
> 
> If you have cli instructions, its not a Xen module (or the source is
> horibly broken).

I guess its fine with the dom0 modules.

nic@stateless:~$ strings /lib/modules/2.6.10-xen0/kernel/net/ipv4/netfilter/ipt_REJECT.ko | grep vermagic=
vermagic=2.6.10-xen0 preempt PENTIUM4 gcc-3.3
nic@stateless:~$ objdump -d /lib/modules/2.6.10-xen0/kernel/net/ipv4/netfilter/ipt_REJECT.ko | grep sti
 b6f:   fb                      sti
nic@stateless:~$ objdump -d /lib/modules/2.6.10-xen0/kernel/net/ipv4/netfilter/ipt_REJECT.ko | grep cli

nic@stateless:~$ objdump -d /lib/modules/2.6.10-xen0/kernel/net/rxrpc/rxrpc.ko | grep cli
nic@stateless:~$ objdump -d /lib/modules/2.6.10-xen0/kernel/net/rxrpc/rxrpc.ko | grep sti
    1f94:       fb                      sti
nic@stateless:~$ strings /lib/modules/2.6.10-xen0/kernel/net/rxrpc/rxrpc.ko | grep vermagic=
vermagic=2.6.10-xen0 preempt PENTIUM4 gcc-3.3


These seems to be compiled with ARCH=xen.

nic@stateless:~$ strings /lib/modules/2.6.10-xenU/kernel/net/ipv4/netfilter/ipt_REJECT.ko | grep vermagic=
vermagic=2.6.10-xenU preempt PENTIUM4 gcc-3.3
nic@stateless:~$ objdump -d /lib/modules/2.6.10-xenU/kernel/net/ipv4/netfilter/ipt_REJECT.ko | egrep  -e sti
 b3f:   fb                      sti

nic@stateless:~$ strings /lib/modules/2.6.10-xenU/kernel/net/rxrpc/rxrpc.ko | grep vermagic=
vermagic=2.6.10-xenU preempt PENTIUM4 gcc-3.3
nic@stateless:~$ objdump -d /lib/modules/2.6.10-xenU/kernel/net/rxrpc/rxrpc.ko | egrep  -e sti
    1f94:       fb                      sti


find /lib/modules/2.6.10-xenU -name \*.ko -exec /tmp/version-check  {}  \;
nic@stateless:~$ cat /tmp/version-check
#!/bin/bash

strings $1 | grep vermagic= | grep -v 'xenU'
objdump -d $1 | perl -n -e 'print $_ if /\scli/'
objdump -d $1 | perl -n -e 'print $_ if /\ssti/'


Nicholas


-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_id=6595&alloc_id=14396&op=click

RE: Badness in local_bh_enable

[Ian Pratt]

 > nic@stateless:~$ strings 
> /lib/modules/2.6.10-xen0/kernel/net/rxrpc/rxrpc.ko | grep vermagic=
> vermagic=2.6.10-xen0 preempt PENTIUM4 gcc-3.3 
> 
> These seems to be compiled with ARCH=xen.

Not necessarily. You may have used that -xen0 tree, but not specified
ARCH=xen. There's no way to tell :-(

> nic@stateless:~$ strings 
> /lib/modules/2.6.10-xenU/kernel/net/ipv4/netfilter/ipt_REJECT.
> ko | grep vermagic=
> vermagic=2.6.10-xenU preempt PENTIUM4 gcc-3.3
> nic@stateless:~$ objdump -d 
> /lib/modules/2.6.10-xenU/kernel/net/ipv4/netfilter/ipt_REJECT.
> ko | egrep  -e sti
>  b3f:   fb                      sti

Just finding a cli/sti in the disassembled output does not necessarily
indicate a problem -- objdump frequently gets confused and disassembles
things that are data, particularly after an undefined instruction e.g.
the uda2 used for BUG messages.

You'll need to look at the instructions around the cli/sti to determine
whether they're real or not.

Ian

> nic@stateless:~$ strings 
> /lib/modules/2.6.10-xenU/kernel/net/rxrpc/rxrpc.ko | grep vermagic=
> vermagic=2.6.10-xenU preempt PENTIUM4 gcc-3.3
> nic@stateless:~$ objdump -d 
> /lib/modules/2.6.10-xenU/kernel/net/rxrpc/rxrpc.ko | egrep  -e sti
>     1f94:       fb                      sti
> 
> 
> find /lib/modules/2.6.10-xenU -name \*.ko -exec 
> /tmp/version-check  {}  \;
> nic@stateless:~$ cat /tmp/version-check
> #!/bin/bash
> 
> strings $1 | grep vermagic= | grep -v 'xenU'
> objdump -d $1 | perl -n -e 'print $_ if /\scli/'
> objdump -d $1 | perl -n -e 'print $_ if /\ssti/'
> 
> 
> Nicholas
> 


-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_ide95&alloc_id\x14396&op=click

Re: Badness in local_bh_enable

[Nick Craig-Wood]

(re-opening an old thread)

On Tue, Mar 08, 2005 at 11:05:01AM -0000, Ian Pratt wrote:
>  > nic@stateless:~$ strings 
> > /lib/modules/2.6.10-xen0/kernel/net/rxrpc/rxrpc.ko | grep vermagic=
> > vermagic=2.6.10-xen0 preempt PENTIUM4 gcc-3.3 
> > 
> > These seems to be compiled with ARCH=xen.
> 
> Not necessarily. You may have used that -xen0 tree, but not specified
> ARCH=xen. There's no way to tell :-(
> 
> > nic@stateless:~$ strings 
> > /lib/modules/2.6.10-xenU/kernel/net/ipv4/netfilter/ipt_REJECT.
> > ko | grep vermagic=
> > vermagic=2.6.10-xenU preempt PENTIUM4 gcc-3.3
> > nic@stateless:~$ objdump -d 
> > /lib/modules/2.6.10-xenU/kernel/net/ipv4/netfilter/ipt_REJECT.
> > ko | egrep  -e sti
> >  b3f:   fb                      sti
> 
> Just finding a cli/sti in the disassembled output does not necessarily
> indicate a problem -- objdump frequently gets confused and disassembles
> things that are data, particularly after an undefined instruction e.g.
> the uda2 used for BUG messages.
> 
> You'll need to look at the instructions around the cli/sti to determine
> whether they're real or not.

Was this problem ever got to the bottom of?

We are seeing it too.  Lots of 

Badness in local_bh_enable at kernel/softirq.c:140
 [<c011fb12>] local_bh_enable+0x82/0x90
 [<c031fcfd>] skb_checksum+0x13d/0x2d0
 [<c016ac5c>] __pollwait+0x8c/0xd0
 [<c0360d3a>] udp_poll+0x9a/0x160
 [<c031af49>] sock_poll+0x29/0x40
 [<c016b635>] do_pollfd+0x95/0xa0
 [<c016b6aa>] do_poll+0x6a/0xd0
 [<c016b871>] sys_poll+0x161/0x240
 [<c011f14c>] sys_gettimeofday+0x3c/0x90
 [<c016abd0>] __pollwait+0x0/0xd0
 [<c0109758>] syscall_call+0x7/0xb

In the logs.

I've checked the loaded modules...

Module                  Size  Used by
sch_sfq                 4992  88 
cls_u32                 8068  101 
sch_cbq                15616  13 
ipt_state               1664  2 
ipt_REJECT              5888  3 
ipt_LOG                 6528  4 
ipt_limit               2176  4 
iptable_mangle          2432  0 
iptable_filter          3200  1 
ip_nat_ftp              4464  0 
ip_conntrack_ftp       71600  1 ip_nat_ftp
iptable_nat            23496  1 ip_nat_ftp
ip_conntrack           41364  4 ipt_state,ip_nat_ftp,ip_conntrack_ftp,iptable_nat
ip_tables              17024  7 ipt_state,ipt_REJECT,ipt_LOG,ipt_limit,iptable_mangle,iptable_filter,iptable_nat
e1000                  84788  0 

And these all have the right vermagic

# strings `cat /tmp/modules` | grep vermagic
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3
vermagic=2.6.10-x1d-p4 preempt PENTIUM4 gcc-3.3

# objdump -d `cat /tmp/modules` | grep -c cli
0

# objdump -d `cat /tmp/modules` | grep -c sti
2

Those two are clearly caused by bodged dissasembly, eg

 b65:   ff 8b 5c 24 38 85       decl   0x8538245c(%ebx)
 b6b:   db 0f                   fisttpl (%edi)
 b6d:   84 d2                   test   %dl,%dl
 b6f:   fb                      sti    
 b70:   ff                      (bad)  
 b71:   ff 8b 43 04 85 c0       decl   0xc0850443(%ebx)

I built the kernel using debian's make-kpkg which I wouldn't have
thought would have made a mistake.

Any other ideas?

This is kernel 2.6.10 running with xen 2.04.

-- 
Nick Craig-Wood <nick@craig-wood.com> -- http://www.craig-wood.com/nick

RE: Badness in local_bh_enable

[Ian Pratt]

> Badness in local_bh_enable at kernel/softirq.c:140  
> [<c011fb12>] local_bh_enable+0x82/0x90  [<c031fcfd>] 
> skb_checksum+0x13d/0x2d0  [<c016ac5c>] __pollwait+0x8c/0xd0  
> [<c0360d3a>] udp_poll+0x9a/0x160  [<c031af49>] 
> sock_poll+0x29/0x40  [<c016b635>] do_pollfd+0x95/0xa0  
> [<c016b6aa>] do_poll+0x6a/0xd0  [<c016b871>] 
> sys_poll+0x161/0x240  [<c011f14c>] sys_gettimeofday+0x3c/0x90 
>  [<c016abd0>] __pollwait+0x0/0xd0  [<c0109758>] syscall_call+0x7/0xb

This only happened when you had two virtual NICs enabled on a domU,
right?

It's on the list of issues to try and reproduce and investigate when we
get a chance. Having further reports that the problem goes away with
just a single NIC would be useful.

Ian  

Re: Badness in local_bh_enable

[Nicholas Lee]

On Apr 11, 2005 11:19 PM, Ian Pratt <m+Ian.Pratt@cl.cam.ac.uk> wrote:
> 
> This only happened when you had two virtual NICs enabled on a domU,
> right?
> 
> It's on the list of issues to try and reproduce and investigate when we
> get a chance. Having further reports that the problem goes away with
> just a single NIC would be useful.

I have several domUs with 2 NICs.  One set hooked to xen-br0, another
(internal) set hooked to a dummy NIC/bridge.

I had this problem, but it went away when I went from 2.0.3 to
2.0.4-testing and did a (very) clean recompile of Xen. Usually I
ARCH=xen menuconfig in the kernel dir, then make in the xen dir.

Originally I think I was getting this only a domU that was using
openvpn2/tun.  Now this dom doesn't cause any problems with
2.0.5-testing.

One of the things I did was remove any modules that I didn't need.
This might have removed a module that although not loaded might have
been causing issues. I'm not sure exactly how this might work though.

Nicholas

Re: Badness in local_bh_enable

[Nick Craig-Wood]

On Mon, Apr 11, 2005 at 12:19:30PM +0100, Ian Pratt wrote:
> > Badness in local_bh_enable at kernel/softirq.c:140  
> > [<c011fb12>] local_bh_enable+0x82/0x90  [<c031fcfd>] 
> > skb_checksum+0x13d/0x2d0  [<c016ac5c>] __pollwait+0x8c/0xd0  
> > [<c0360d3a>] udp_poll+0x9a/0x160  [<c031af49>] 
> > sock_poll+0x29/0x40  [<c016b635>] do_pollfd+0x95/0xa0  
> > [<c016b6aa>] do_poll+0x6a/0xd0  [<c016b871>] 
> > sys_poll+0x161/0x240  [<c011f14c>] sys_gettimeofday+0x3c/0x90 
> >  [<c016abd0>] __pollwait+0x0/0xd0  [<c0109758>] syscall_call+0x7/0xb
> 
> This only happened when you had two virtual NICs enabled on a domU,
> right?

No, all the domUs have one nic only.  Each NIC has multiple IP
addresses.

> It's on the list of issues to try and reproduce and investigate when we
> get a chance. Having further reports that the problem goes away with
> just a single NIC would be useful.

Possibly relevant or not - we don't bridge the domUs we route them.

-- 
Nick Craig-Wood <nick@craig-wood.com> -- http://www.craig-wood.com/nick