* (irda) Badness in local_bh_enable at kernel/softirq.c:121 @ 2003-12-26 13:00 Russell King 2003-12-26 22:34 ` David S. Miller 2003-12-26 23:16 ` [irda-users] " Martin Diehl 0 siblings, 2 replies; 5+ messages in thread From: Russell King @ 2003-12-26 13:00 UTC (permalink / raw) To: Linux Kernel List, irda-users Hi, I've just been testing w83977af_ir with ircomm on a NetWinder (ARM) and a Nokia mobile phone, and, while closing down the connection by exiting minicom, I saw this which looks particularly evil. I'm not sure exactly when this occurred because I was running minicom over ssh. ircomm_param_service_type(), services in common=04 ircomm_param_service_type(), resulting service type=0x04 ircomm_param_port_type(), port type=1 ircomm_param_port_type(), port type=1 ircomm_param_xon_xoff(), XON/XOFF = 0x11,0x13 ircomm_param_enq_ack(), ENQ/ACK = 0x13,0x11 ircomm_tty_check_modem_status() ircomm_tty_check_modem_status() ircomm_tty_check_modem_status() ircomm_tty_check_modem_status() ircomm_tty_close() ircomm_tty_shutdown() ircomm_tty_detach_cable() Badness in local_bh_enable at kernel/softirq.c:121 [<c00429c4>] (local_bh_enable+0x0/0x84) from [<c014d1b4>] (dev_queue_xmit+0x108/0x20c) [<c014d0ac>] (dev_queue_xmit+0x0/0x20c) from [<bf00ee68>] (irlap_send_data_primary_poll+0xdc/0x1c4 [irda]) [<bf00ed8c>] (irlap_send_data_primary_poll+0x0/0x1c4 [irda]) from [<bf00babc>] (irlap_state_xmit_p+0x1a4/0x308 [irda]) [<bf00b918>] (irlap_state_xmit_p+0x0/0x308 [irda]) from [<bf00a78c>] (irlap_do_event+0xd8/0x1f0 [irda]) [<bf00a6b4>] (irlap_do_event+0x0/0x1f0 [irda]) from [<bf008938>] (irlap_data_request+0x174/0x1a8 [irda]) [<bf0087c4>] (irlap_data_request+0x0/0x1a8 [irda]) from [<bf006f80>] (irlmp_state_dtr+0x17c/0x328 [irda]) [<bf006e04>] (irlmp_state_dtr+0x0/0x328 [irda]) from [<bf005fcc>] (irlmp_do_lsap_event+0xb8/0xe8 [irda]) [<bf005f14>] (irlmp_do_lsap_event+0x0/0xe8 [irda]) from [<bf003bc8>] (irlmp_disconnect_request+0x138/0x2f0 [irda]) [<bf003a90>] (irlmp_disconnect_request+0x0/0x2f0 [irda]) from [<bf0149bc>] (irttp_disconnect_request+0x220/0x274 [irda]) [<bf01479c>] (irttp_disconnect_request+0x0/0x274 [irda]) from [<bf035100>] (ircomm_state_conn+0xbc/0xf0 [ircomm]) [<bf035044>] (ircomm_state_conn+0x0/0xf0 [ircomm]) from [<bf0351a0>] (ircomm_do_event+0x6c/0x88 [ircomm]) [<bf035134>] (ircomm_do_event+0x0/0x88 [ircomm]) from [<bf034a40>] (ircomm_disconnect_request+0x94/0xc0 [ircomm]) [<bf0349ac>] (ircomm_disconnect_request+0x0/0xc0 [ircomm]) from [<bf03d838>] (ircomm_tty_state_ready+0x58/0xfc [ircomm_tty]) [<bf03d7e0>] (ircomm_tty_state_ready+0x0/0xfc [ircomm_tty]) from [<bf03d99c>] (ircomm_tty_do_event+0xc0/0xf4 [ircomm_tty]) [<bf03d8dc>] (ircomm_tty_do_event+0x0/0xf4 [ircomm_tty]) from [<bf03c4fc>] (ircomm_tty_detach_cable+0xcc/0x10c [ircomm_tty]) [<bf03c430>] (ircomm_tty_detach_cable+0x0/0x10c [ircomm_tty]) from [<bf03b5d8>] (ircomm_tty_shutdown+0x128/0x178 [ircomm_tty]) [<bf03b4b0>] (ircomm_tty_shutdown+0x0/0x178 [ircomm_tty]) from [<bf03a9c0>] (ircomm_tty_close+0x15c/0x240 [ircomm_tty]) [<bf03a864>] (ircomm_tty_close+0x0/0x240 [ircomm_tty]) from [<c00d7bd4>] (release_dev+0x1d8/0x5a4) [<c00d79fc>] (release_dev+0x0/0x5a4) from [<c00d831c>] (tty_release+0x14/0x1c) [<c00d8308>] (tty_release+0x0/0x1c) from [<c0072d6c>] (__fput+0x58/0x13c) [<c0072d14>] (__fput+0x0/0x13c) from [<c007175c>] (filp_close+0x84/0x90) [<c00716d8>] (filp_close+0x0/0x90) from [<c0028a40>] (ret_fast_syscall+0x0/0x2c) ircomm_close() Obviously, uniprocessor configuration, irda built completely modular. -- Russell King Linux kernel 2.6 ARM Linux - http://www.arm.linux.org.uk/ maintainer of: 2.6 PCMCIA - http://pcmcia.arm.linux.org.uk/ 2.6 Serial core ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: (irda) Badness in local_bh_enable at kernel/softirq.c:121 2003-12-26 13:00 (irda) Badness in local_bh_enable at kernel/softirq.c:121 Russell King @ 2003-12-26 22:34 ` David S. Miller 2003-12-26 23:16 ` [irda-users] " Martin Diehl 1 sibling, 0 replies; 5+ messages in thread From: David S. Miller @ 2003-12-26 22:34 UTC (permalink / raw) To: Russell King; +Cc: linux-kernel, irda-users On Fri, 26 Dec 2003 13:00:31 +0000 Russell King <rmk+lkml@arm.linux.org.uk> wrote: > I've just been testing w83977af_ir with ircomm on a NetWinder (ARM) and > a Nokia mobile phone, and, while closing down the connection by exiting > minicom, I saw this which looks particularly evil. I'm not sure exactly > when this occurred because I was running minicom over ssh. This is akin to the PPP issues, and all of this basically is telling that the TTY driver's locking conflicts with networking quite badly. In this case: > Badness in local_bh_enable at kernel/softirq.c:121 > [<c00429c4>] (local_bh_enable+0x0/0x84) from [<c014d1b4>] (dev_queue_xmit+0x108/0x20c) > [<c014d0ac>] (dev_queue_xmit+0x0/0x20c) from [<bf00ee68>] (irlap_send_data_primary_poll+0xdc/0x1c4 [irda]) local_bh_enable() with hardware interrupts disabled, which is racy and illegal. Who disabled CPU interrupts? Let's see: > [<bf03b4b0>] (ircomm_tty_shutdown+0x0/0x178 [ircomm_tty]) from [<bf03a9c0>] (ircomm_tty_close+0x15c/0x240 [ircomm_tty]) And this is where the spin_lock_irqsave() occurs, that leads to all of the trouble. ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [irda-users] (irda) Badness in local_bh_enable at kernel/softirq.c:121 2003-12-26 13:00 (irda) Badness in local_bh_enable at kernel/softirq.c:121 Russell King 2003-12-26 22:34 ` David S. Miller @ 2003-12-26 23:16 ` Martin Diehl 2003-12-26 23:33 ` Martin Diehl 1 sibling, 1 reply; 5+ messages in thread From: Martin Diehl @ 2003-12-26 23:16 UTC (permalink / raw) To: Russell King; +Cc: Linux Kernel List, irda-users On Fri, 26 Dec 2003, Russell King wrote: Hi Russell, > I've just been testing w83977af_ir with ircomm on a NetWinder (ARM) and > a Nokia mobile phone, and, while closing down the connection by exiting > minicom, I saw this which looks particularly evil. I'm not sure exactly > when this occurred because I was running minicom over ssh. > > Badness in local_bh_enable at kernel/softirq.c:121 > [<c00429c4>] (local_bh_enable+0x0/0x84) from [<c014d1b4>] (dev_queue_xmit+0x108/0x20c) > [<c014d0ac>] (dev_queue_xmit+0x0/0x20c) from [<bf00ee68>] (irlap_send_data_primary_poll+0xdc/0x1c4 [irda]) > [<bf00ed8c>] (irlap_send_data_primary_poll+0x0/0x1c4 [irda]) from [<bf00babc>] (irlap_state_xmit_p+0x1a4/0x308 [irda]) Yes, Thanks. It's a known problem with 2.6.0: sirdev_txlock-patch is waiting on Jean's page to get forwarded - for 2.6.[12] I assume. Beware, there's another local_bh_enable issue with ircomm even with this patch applied. It's triggered when the ircomm-dev wasn't closed by the application before exiting (say kill -9 f.e.). So if you get another such badness warning with slightly different backtrace, chances are you also want to apply the "IrCOMM detach Oops" fixes from Jean's page. Martin ------------------- --- linux-2.6.0-test9-bk22/drivers/net/irda/sir_dev.c Wed Oct 8 21:24:16 2003 +++ v2.6.0-test9-bk22/drivers/net/irda/sir_dev.c Tue Nov 18 00:01:38 2003 @@ -62,24 +62,25 @@ int sirdev_set_dongle(struct sir_dev *de int sirdev_raw_write(struct sir_dev *dev, const char *buf, int len) { + unsigned long flags; int ret; if (unlikely(len > dev->tx_buff.truesize)) return -ENOSPC; - spin_lock_bh(&dev->tx_lock); /* serialize with other tx operations */ - while (dev->tx_buff.len > 0) { /* wait until tx idle */ - spin_unlock_bh(&dev->tx_lock); + spin_lock_irqsave(&dev->tx_lock, flags); /* serialize with other tx operations */ + while (dev->tx_buff.len > 0) { /* wait until tx idle */ + spin_unlock_irqrestore(&dev->tx_lock, flags); set_current_state(TASK_UNINTERRUPTIBLE); schedule_timeout(MSECS_TO_JIFFIES(10)); - spin_lock_bh(&dev->tx_lock); + spin_lock_irqsave(&dev->tx_lock, flags); } dev->tx_buff.data = dev->tx_buff.head; memcpy(dev->tx_buff.data, buf, len); ret = dev->drv->do_write(dev, dev->tx_buff.data, dev->tx_buff.len); - spin_unlock_bh(&dev->tx_lock); + spin_unlock_irqrestore(&dev->tx_lock, flags); return ret; } @@ -114,11 +115,12 @@ int sirdev_raw_read(struct sir_dev *dev, void sirdev_write_complete(struct sir_dev *dev) { + unsigned long flags; struct sk_buff *skb; int actual = 0; int err; - spin_lock_bh(&dev->tx_lock); + spin_lock_irqsave(&dev->tx_lock, flags); IRDA_DEBUG(3, "%s() - dev->tx_buff.len = %d\n", __FUNCTION__, dev->tx_buff.len); @@ -143,7 +145,7 @@ void sirdev_write_complete(struct sir_de dev->tx_buff.len = 0; } if (dev->tx_buff.len > 0) { - spin_unlock_bh(&dev->tx_lock); + spin_unlock_irqrestore(&dev->tx_lock, flags); return; } } @@ -190,7 +192,7 @@ void sirdev_write_complete(struct sir_de netif_wake_queue(dev->netdev); } - spin_unlock_bh(&dev->tx_lock); + spin_unlock_irqrestore(&dev->tx_lock, flags); } /* called from client driver - likely with bh-context - to give us @@ -258,6 +260,7 @@ static struct net_device_stats *sirdev_g static int sirdev_hard_xmit(struct sk_buff *skb, struct net_device *ndev) { struct sir_dev *dev = ndev->priv; + unsigned long flags; int actual = 0; int err; s32 speed; @@ -307,7 +310,7 @@ static int sirdev_hard_xmit(struct sk_bu } /* serialize with write completion */ - spin_lock_bh(&dev->tx_lock); + spin_lock_irqsave(&dev->tx_lock, flags); /* Copy skb to tx_buff while wrapping, stuffing and making CRC */ dev->tx_buff.len = async_wrap_skb(skb, dev->tx_buff.data, dev->tx_buff.truesize); @@ -337,7 +340,7 @@ static int sirdev_hard_xmit(struct sk_bu dev->stats.tx_dropped++; netif_wake_queue(ndev); } - spin_unlock_bh(&dev->tx_lock); + spin_unlock_irqrestore(&dev->tx_lock, flags); return 0; } --- linux-2.6.0-test9-bk22/drivers/net/irda/sir_kthread.c Wed Oct 8 21:24:27 2003 +++ v2.6.0-test9-bk22/drivers/net/irda/sir_kthread.c Mon Nov 17 17:39:54 2003 @@ -436,14 +436,13 @@ int sirdev_schedule_request(struct sir_d IRDA_DEBUG(2, "%s - state=0x%04x / param=%u\n", __FUNCTION__, initial_state, param); - if (in_interrupt()) { - if (down_trylock(&fsm->sem)) { + if (down_trylock(&fsm->sem)) { + if (in_interrupt() || in_atomic() || irqs_disabled()) { IRDA_DEBUG(1, "%s(), state machine busy!\n", __FUNCTION__); return -EWOULDBLOCK; - } + } else + down(&fsm->sem); } - else - down(&fsm->sem); if (fsm->state == SIRDEV_STATE_DEAD) { /* race with sirdev_close should never happen */ ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [irda-users] (irda) Badness in local_bh_enable at kernel/softirq.c:121 2003-12-26 23:16 ` [irda-users] " Martin Diehl @ 2003-12-26 23:33 ` Martin Diehl 2004-01-06 3:58 ` David S. Miller 0 siblings, 1 reply; 5+ messages in thread From: Martin Diehl @ 2003-12-26 23:33 UTC (permalink / raw) To: irda-users; +Cc: David S. Miller, Russell King, Linux Kernel List On Sat, 27 Dec 2003, Martin Diehl wrote: > Beware, there's another local_bh_enable issue with ircomm even with this > patch applied. It's triggered when the ircomm-dev wasn't closed by the > application before exiting (say kill -9 f.e.). So if you get another such > badness warning with slightly different backtrace, chances are you also > want to apply the "IrCOMM detach Oops" fixes from Jean's page. Oops, right after sending this I realized you aren't using the sirdev at all, so in fact this is already the second case triggered from the ircomm-shutdown path - like davem was already pointing to. Below said patch from Jean. Martin ---------------------------- diff -u -p linux/include/net/irda/ircomm_tty.d4.h linux/include/net/irda/ircomm_tty.h --- linux/include/net/irda/ircomm_tty.d4.h Thu Dec 18 18:22:57 2003 +++ linux/include/net/irda/ircomm_tty.h Thu Dec 18 18:29:01 2003 @@ -52,6 +52,11 @@ /* Same for payload size. See qos.c for the smallest max data size */ #define IRCOMM_TTY_DATA_UNINITIALISED (64 - IRCOMM_TTY_HDR_UNINITIALISED) +/* Those are really defined in include/linux/serial.h - Jean II */ +#define ASYNC_B_INITIALIZED 31 /* Serial port was initialized */ +#define ASYNC_B_NORMAL_ACTIVE 29 /* Normal device is active */ +#define ASYNC_B_CLOSING 27 /* Serial port is closing */ + /* * IrCOMM TTY driver state */ @@ -75,7 +80,7 @@ struct ircomm_tty_cb { LOCAL_FLOW flow; /* IrTTP flow status */ int line; - __u32 flags; + volatile unsigned long flags; __u8 dlsap_sel; __u8 slsap_sel; diff -u -p linux/net/irda/ircomm_tty.d4.c linux/net/irda/ircomm_tty.c --- linux/net/irda/ircomm/ircomm_tty.d4.c Thu Dec 18 17:40:14 2003 +++ linux/net/irda/ircomm/ircomm_tty.c Thu Dec 18 18:29:09 2003 @@ -182,15 +182,15 @@ void __exit ircomm_tty_cleanup(void) static int ircomm_tty_startup(struct ircomm_tty_cb *self) { notify_t notify; - int ret; + int ret = -ENODEV; IRDA_DEBUG(2, "%s()\n", __FUNCTION__ ); ASSERT(self != NULL, return -1;); ASSERT(self->magic == IRCOMM_TTY_MAGIC, return -1;); - /* Already open */ - if (self->flags & ASYNC_INITIALIZED) { + /* Check if already open */ + if (test_and_set_bit(ASYNC_B_INITIALIZED, &self->flags)) { IRDA_DEBUG(2, "%s(), already open so break out!\n", __FUNCTION__ ); return 0; } @@ -214,7 +214,7 @@ static int ircomm_tty_startup(struct irc self->line); } if (!self->ircomm) - return -ENODEV; + goto err; self->slsap_sel = self->ircomm->slsap_sel; @@ -222,12 +222,13 @@ static int ircomm_tty_startup(struct irc ret = ircomm_tty_attach_cable(self); if (ret < 0) { ERROR("%s(), error attaching cable!\n", __FUNCTION__); - return ret; + goto err; } - self->flags |= ASYNC_INITIALIZED; - return 0; +err: + clear_bit(ASYNC_B_INITIALIZED, &self->flags); + return ret; } /* @@ -300,7 +301,8 @@ static int ircomm_tty_block_til_ready(st current->state = TASK_INTERRUPTIBLE; - if (tty_hung_up_p(filp) || !(self->flags & ASYNC_INITIALIZED)){ + if (tty_hung_up_p(filp) || + !test_bit(ASYNC_B_INITIALIZED, &self->flags)) { retval = (self->flags & ASYNC_HUP_NOTIFY) ? -EAGAIN : -ERESTARTSYS; break; @@ -311,7 +313,7 @@ static int ircomm_tty_block_til_ready(st * specified, we cannot return before the IrCOMM link is * ready */ - if (!(self->flags & ASYNC_CLOSING) && + if (!test_bit(ASYNC_B_CLOSING, &self->flags) && (do_clocal || (self->settings.dce & IRCOMM_CD)) && self->state == IRCOMM_TTY_READY) { @@ -426,7 +428,7 @@ static int ircomm_tty_open(struct tty_st * If the port is the middle of closing, bail out now */ if (tty_hung_up_p(filp) || - (self->flags & ASYNC_CLOSING)) { + test_bit(ASYNC_B_CLOSING, &self->flags)) { /* Hm, why are we blocking on ASYNC_CLOSING if we * do return -EAGAIN/-ERESTARTSYS below anyway? @@ -436,7 +438,7 @@ static int ircomm_tty_open(struct tty_st * probably better sleep uninterruptible? */ - if (wait_event_interruptible(self->close_wait, !(self->flags&ASYNC_CLOSING))) { + if (wait_event_interruptible(self->close_wait, !test_bit(ASYNC_B_CLOSING, &self->flags))) { WARNING("%s - got signal while blocking on ASYNC_CLOSING!\n", __FUNCTION__); return -ERESTARTSYS; @@ -531,11 +533,13 @@ static void ircomm_tty_close(struct tty_ IRDA_DEBUG(0, "%s(), open count > 0\n", __FUNCTION__ ); return; } - self->flags |= ASYNC_CLOSING; + + /* Hum... Should be test_and_set_bit ??? - Jean II */ + set_bit(ASYNC_B_CLOSING, &self->flags); /* We need to unlock here (we were unlocking at the end of this * function), because tty_wait_until_sent() may schedule. - * I don't know if the rest should be locked somehow, + * I don't know if the rest should be protected somehow, * so someone should check. - Jean II */ spin_unlock_irqrestore(&self->spinlock, flags); @@ -979,10 +983,12 @@ static void ircomm_tty_shutdown(struct i ASSERT(self->magic == IRCOMM_TTY_MAGIC, return;); IRDA_DEBUG(0, "%s()\n", __FUNCTION__ ); - - if (!(self->flags & ASYNC_INITIALIZED)) + + if (!test_and_clear_bit(ASYNC_B_INITIALIZED, &self->flags)) return; + ircomm_tty_detach_cable(self); + spin_lock_irqsave(&self->spinlock, flags); del_timer(&self->watchdog_timer); @@ -999,13 +1005,10 @@ static void ircomm_tty_shutdown(struct i self->tx_skb = NULL; } - ircomm_tty_detach_cable(self); - if (self->ircomm) { ircomm_close(self->ircomm); self->ircomm = NULL; } - self->flags &= ~ASYNC_INITIALIZED; spin_unlock_irqrestore(&self->spinlock, flags); } ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [irda-users] (irda) Badness in local_bh_enable at kernel/softirq.c:121 2003-12-26 23:33 ` Martin Diehl @ 2004-01-06 3:58 ` David S. Miller 0 siblings, 0 replies; 5+ messages in thread From: David S. Miller @ 2004-01-06 3:58 UTC (permalink / raw) To: Martin Diehl; +Cc: irda-users, rmk+lkml, linux-kernel On Sat, 27 Dec 2003 00:33:34 +0100 (CET) Martin Diehl <lists@mdiehl.de> wrote: > On Sat, 27 Dec 2003, Martin Diehl wrote: > > > Beware, there's another local_bh_enable issue with ircomm even with this > > patch applied. It's triggered when the ircomm-dev wasn't closed by the > > application before exiting (say kill -9 f.e.). So if you get another such > > badness warning with slightly different backtrace, chances are you also > > want to apply the "IrCOMM detach Oops" fixes from Jean's page. > > Oops, right after sending this I realized you aren't using the sirdev at > all, so in fact this is already the second case triggered from the > ircomm-shutdown path - like davem was already pointing to. > Below said patch from Jean. I'm going to add this to my tree, the patch looks perfectly fine and we might as well get this thing fixed now rather than later. ^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2004-01-06 4:04 UTC | newest] Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2003-12-26 13:00 (irda) Badness in local_bh_enable at kernel/softirq.c:121 Russell King 2003-12-26 22:34 ` David S. Miller 2003-12-26 23:16 ` [irda-users] " Martin Diehl 2003-12-26 23:33 ` Martin Diehl 2004-01-06 3:58 ` David S. Miller
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.