From mboxrd@z Thu Jan 1 00:00:00 1970 From: Marek Vasut Subject: Re: ipv6/addrconf_dad_failure printk() in interrupt context Date: Sun, 18 Dec 2011 14:09:49 +0100 Message-ID: <201112181409.49299.marek.vasut@gmail.com> References: <201112180328.00422.marek.vasut@gmail.com> <1324199708.3323.71.camel@edumazet-laptop> Mime-Version: 1.0 Content-Type: Text/Plain; charset=iso-8859-1 Content-Transfer-Encoding: QUOTED-PRINTABLE Cc: netdev@vger.kernel.org, Wolfgang Denk , "David S. Miller" , Alexey Kuznetsov , James Morris , Hideaki YOSHIFUJI , Patrick McHardy , linux@vger.kernel.org To: Eric Dumazet Return-path: Received: from mail-ee0-f46.google.com ([74.125.83.46]:42287 "EHLO mail-ee0-f46.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751538Ab1LRNJx convert rfc822-to-8bit (ORCPT ); Sun, 18 Dec 2011 08:09:53 -0500 In-Reply-To: <1324199708.3323.71.camel@edumazet-laptop> Sender: netdev-owner@vger.kernel.org List-ID: > Le dimanche 18 d=E9cembre 2011 =E0 03:28 +0100, Marek Vasut a =E9crit= : > > Hi, > >=20 > > I just recently hit the following issue. I might actually be wrong = with > > my conclusions so bear with me. The events that led to the issue: > >=20 > > 1) Duplicate IPv6 address on the network > > 2) console driver that locks a mutex when printk() is called >=20 > This seems buggy : printk() might be called from irq, so muext_lock()= is > not allowed. I could have guessed so ... mutex_lock() is called in clk_enable() in m= xs clock=20 driver. So that needs to be fixed. >=20 > > The problem is the following backtrace: > >=20 > > [ 4.870000] eth0: IPv6 duplicate address XXXX::YYYY:ZZZZ:WWWW:0 > > detected! [ 4.870000] ------------[ cut here ]------------ > > [ 4.870000] WARNING: at kernel/mutex.c:198 > > mutex_lock_nested+0x284/0x2c0() [ 4.870000] Modules linked in: > > [ 4.870000] [] (unwind_backtrace+0x0/0xf0) from [] > > (warn_slowpath_common+0x4c/0x64) > > [ 4.870000] [] (warn_slowpath_common+0x4c/0x64) from > > [] (warn_slowpath_null+0x1c/0x24) > > [ 4.870000] [] (warn_slowpath_null+0x1c/0x24) from > > [] (mutex_lock_nested+0x284/0x2c0) > > [ 4.870000] [] (mutex_lock_nested+0x284/0x2c0) from > > [] (clk_enable+0x20/0x48) > > [ 4.870000] [] (clk_enable+0x20/0x48) from [= ] > > (pl011_console_write+0x20/0x74) > > [ 4.870000] [] (pl011_console_write+0x20/0x74) from > > [] (__call_console_drivers+0x7c/0x94) > > [ 4.870000] [] (__call_console_drivers+0x7c/0x94) from > > [] (console_unlock+0xf8/0x244) > > [ 4.870000] [] (console_unlock+0xf8/0x244) from [] > > (vprintk+0x29c/0x484) > > [ 4.870000] [] (vprintk+0x29c/0x484) from [] > > (printk+0x20/0x30) > > [ 4.870000] [] (printk+0x20/0x30) from [] > > (addrconf_dad_failure+0x148/0x158) > > [ 4.870000] [] (addrconf_dad_failure+0x148/0x158) from > > [] (ndisc_rcv+0xb38/0xdb0) > > [ 4.870000] [] (ndisc_rcv+0xb38/0xdb0) from [] > > (icmpv6_rcv+0x6ec/0x9c4) > > [ 4.870000] [] (icmpv6_rcv+0x6ec/0x9c4) from [] > > (ip6_input_finish+0x144/0x4e0) > > [ 4.870000] [] (ip6_input_finish+0x144/0x4e0) from > > [] (ip6_mc_input+0xb8/0x154) > > [ 4.870000] [] (ip6_mc_input+0xb8/0x154) from [] > > (ipv6_rcv+0x300/0x53c) > > [ 4.870000] [] (ipv6_rcv+0x300/0x53c) from [= ] > > (__netif_receive_skb+0x240/0x420) > > [ 4.870000] [] (__netif_receive_skb+0x240/0x420) from > > [] (process_backlog+0x90/0x150) > > [ 4.870000] [] (process_backlog+0x90/0x150) from > > [] (net_rx_action+0xc0/0x264) > > [ 4.870000] [] (net_rx_action+0xc0/0x264) from [] > > (__do_softirq+0xa8/0x214) > > [ 4.870000] [] (__do_softirq+0xa8/0x214) from [] > > (irq_exit+0x8c/0x94) > > [ 4.870000] [] (irq_exit+0x8c/0x94) from [] > > (handle_IRQ+0x34/0x84) > > [ 4.870000] [] (handle_IRQ+0x34/0x84) from [= ] > > (__irq_usr+0x38/0x80) > > [ 4.870000] ---[ end trace 32eab6a8dcdca9c0 ]--- > >=20 > > So basically what I see here is the following order of events: > >=20 > > Packet received -> IRQ generated -> ipv6 packet received (still in > > interrupt context ... why not in tasklet ... or am I wrong here ?) = -> > > icmpv6 packet processing -> addrconf_dad_failure() called -> printk= () > > called in there -> mutex_lock() called in printk(), causing the war= ning. > >=20 > > Can printk() be actually called in interrupt context? >=20 > Yes, it can be. >=20 > > What direction of solving this shall I take? >=20 > Send this to lkml, since its not a netdev issue, but a kernel one. I already know the direction (where to squash the improper mutex) so I'= ll poke=20 into that and send to LKML incl. patch. Thanks for your reply! M