From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753345AbYHLUqh (ORCPT ); Tue, 12 Aug 2008 16:46:37 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1751754AbYHLUqZ (ORCPT ); Tue, 12 Aug 2008 16:46:25 -0400 Received: from mail-gx0-f16.google.com ([209.85.217.16]:41267 "EHLO mail-gx0-f16.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751951AbYHLUqX (ORCPT ); Tue, 12 Aug 2008 16:46:23 -0400 DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:to:subject:cc:in-reply-to:mime-version :content-type:content-transfer-encoding:content-disposition :references; b=m7AEEwvBphIHxhAXVma7/gUMjHm1FIKQlMoCMtgKxAJrLLXjPcIqdzkbn0L7dJW1r4 mqiIJvMsJyDa34EYZiYBL4U7tHVvMKscpyQXOT34gY3RypVyq48OUCdAxFAdk0iD2YzH 6XNY1n5fmEl6oGbCw6JEW5jrEOFdMI89tZsjo= Message-ID: <19f34abd0808121346w60f37ac0mf8e4ed20549af0e1@mail.gmail.com> Date: Tue, 12 Aug 2008 22:46:21 +0200 From: "Vegard Nossum" To: "Alexey Dobriyan" Subject: Re: latest -git: kernel hangs when pulling the plug on 8139too Cc: "netdev@vger.kernel.org" , LKML In-Reply-To: <19f34abd0808121202p6a59917ey561ac48012fb92ca@mail.gmail.com> MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit Content-Disposition: inline References: <19f34abd0808110949n5d7d363es66325b87a8fb0fd1@mail.gmail.com> <20080811192739.GB5791@martell.zuzino.mipt.ru> <19f34abd0808121020l4a0552a0v3d48b181d980d600@mail.gmail.com> <19f34abd0808121202p6a59917ey561ac48012fb92ca@mail.gmail.com> Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Tue, Aug 12, 2008 at 9:02 PM, Vegard Nossum wrote: > On Tue, Aug 12, 2008 at 7:20 PM, Vegard Nossum wrote: >> ...but after pulling the cable and seeing the keyboard blink for five >> seconds, the CPU resets without running the new kernel (i.e. it >> reboots and I see the BIOS messages, etc.). >> >> Maybe I did something wrong? (Though I don't think so.) >> >> I will try to replace some printk()s to early_printk() (allows me to >> maybe capture some messages on ttyS0 without trying to send anything >> over netconsole). > > It turns out that we're not getting as far as the "panic:" line in panic(). Actually, I just forgot earlyprintk=...,keep. Now I modified the printk() to use early_printk() if oops_in_progress is set. This does actually give some result, but again the text is garbled, this time for real, and I don't understand why. But this is what I get on the serial console: <0>BUG: NMI Watchdog detected LOCKUP on CPU1, ip c010ae8c, registers: Pid: 0, comm: swapper Not tainted (2.6.27-rc2-00325-g796aade-dirty #3) EIP: 0060:[] EFLAGS: 00000246 CPU: 1 EIP is at mwait_idle+0x3c/0x50 EAX: 00000000 EBX: f7894008 ECX: 00000000 EDX: 00000000 ESI: 00000001 EDI: c081ec00 EBP: f7895f7c ESP: f7895f78 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 <0>Process swapper (pid: 0, ti=f7894000 task=f7898000 task.ti=f7894000) <0>Stack: c1fb1c00 f7895f94 c010285c c07d0020 c1f63020 00000001 00000000 f7895fb4 <0> c058b859 00000000 00000000 00000000 00000000 01020800 00000000 00000000 <0> 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 <0>Call Trace: <0> [] ? cpu_idle+0x6c/0x120 <0> [] ? start_secondary+0x169/0x1d0 <0> ======================= <0>Code: 08 75 2b 31 c9 89 d8 89 ca 0f 01 c8 0f ae f0 66 90 89 e0 25 00 e0 ff ff f6 40 08 08 75 10 e8 dc db 04 00 31 c9 89 c8 fb 0f 01 c9 <5b> 5d c3 e8 cc db 04 00 fb 0f 1f 84 00 00 00 00 00 90 eb ec 55 <0>KUG: N panatchdnot stected: AieUP kilCPU0,intec0upt 1andlegis <4>--- Pid: --[ cmm: sre ]-r Not----nted<42.6.2INGc2-00/uio/796aaedesirty #ega dnP: 0t-wo[] .6/keS: 0/smp.96 CPUsmp_calP isnction_ay_ts0x1398/0xb0() AP: : 0,0006 : swaf796bNot taX: c0 2.6.2 EDc2-0001000796aSI: 03rty aa ED[] Barn_o775cow ESP:0x4f70x80 [] ?0__pri: 00ymbGS+0x000 S4: 0 [Sta>k: 0n0000e0 che75ca4ck+08a0b9xc077 cdc c12998d>] ? 1fb4ntk+05aeb0x3e0 [c 150> >] p0775ccfunc15623bask+00001/0x1d8ab0[ 58b8 000 00s6 rt_75cfndar5916b69/00000 0 000010ae 0>] b 55 f6s_acti f796b/0x2 [Call 5d8de: <0> [] ?0__de] ? prin[] ? +0x4_spin_ [<0xb9/859>] 0tart_0156ndb>] 0xtrac0x1d0dirq] 10sto0> [/0x5_sp [] [ [<>] atl8139_p_set_xmitp+0x5/0x130 [] > wanttpoll+0x3d_skb00x1[]>pani04cx62/0] ? t[] +0mwab/0xdle+0x0> [<50 c7] do_exix8c/0e2/0x<80 [ []>] __shll_cogiolers+0vers+0x30/0x6 [4>] 3 do_u] la_cascreensole4/0x1ers+ [ ] + xc5/0_idl <0> /0x00 f0b>]10avpc>] k 0x1ib/0x3e+0x30> [] n_e_nmik_irf/0xfore+[ mwc0146dle+0 ? /0x50 _woc011x31/0] 0mi<0> [hdo1461e5+0x? 5/0ue_wo []] ? q []wnmi_stack_c0 rect [] ? 0spin_b>] c _iratestorl_ti43/0x36b/0x> []8c>s hemwae_delaeed_3c/0+0x1 /0x20 028> [ [scart9736>ndarmiix169ck_me0ia+===96/0==e0= <0> [<==== 27b>---[_end tlock+03bf506b02770> [ ]035 7<4>- ? --l_ch--[ cedia+re ]-0x30----> [ [] 0 10a/le_f0() iiirq+, com0xe0 <0>r Tai107128G IR 2.648/0xc2-0<0> [g7968a604dirt #3ce_hac0135s_of] thunkon_s/0x18 h+0> [] ?6c14a>]_in__rrupt_sy28/0x0x2a/0> [< 0150013610? ] ? vpriall_ti3e+00x3e/0x7d [] k+mwai/0x3ee+ [c/0x500e5>> [ ef9a>6bsmp>] llrfunctnit_sing/0x701 a0> === ==] ?9st0 25his_cp ff ff f50 08c05875 17] ? s4 0c_secon <5f> xd c3 e1d00 4d 30 00 a0 a9 29 rd e8activc ff f0x20 8 [] ? vprintnic 2d/0t syncing:01051f kil? ng nt_trrupt hdreser!x4] ?rstart----onda--+0<4>9/0xING: a[]tnatiG mp_seW 2.top+0x12-00705-g7] ?#mwa []0war _ []xpan0x80 2[] intexit2d/0x2/0x8 [] c>] ristk+0regisx3e0 0 [] cmp_caa4>] n tiounblank_scre/0x1x24/ [p_this_cpmi+0x/0x5xf0 [] ] ? st_it_id0x62x3c70 0 [8c>]d? ay_tt_idlec/03b/0x [] f>] rie_nmi+2d/0x0xf0 [] rintt_iale+0x3ress50 45[05nmi_2>] ? og_t_initx1d5//0x70 [] dostoi+0x97_cpu+0 0/0xc059 [] e wally_tsc+0x36/0xb8d [ [c>nat ve_st_idln+0x3op+050 /0xidled0x6c/tsc+0 8/0c058b [====delay_t====x <4>--8 endc0138e 33b 576exit+932f2/0x-80 0>Reb01054g in 3 sec_regi.ters+0x7c/0x230 [] ? do_unblank_screen+0x24/0x130 [] ? die_nmi+0xb9/0xf0 [] ? delay_tsc+0x98/0xb8 [] ? delay_tsc+0x98/0xb8 [] die_nmi+0xef/0xf0 [] ? delay_tsc+0x98/0xb8 [] nmi_watchdog_tick+0x1d5/0x1e0 [] do_nmi+0x97/0x2d0 [] nmi_stack_correct+0x26/0x2b [] ? as_remove_queued_request+0x9b/0xb0 [] ? delay_tsc+0x98/0xb8 [] __delay+0x9/0x10 [] _raw_spin_lock+0xb9/0x140 [] ? trace_hardirqs_off+0xb/0x10 [] _spin_lock_irqsave+0x76/0x90 [] ? rtl8139_start_xmit+0x65/0x130 [] rtl8139_start_xmit+0x65/0x130 [] netpoll_send_skb+0x158/0x1a0 [] netpoll_send_udp+0x1db/0x1f0 [] write_msg+0x8c/0xc0 [] __call_console_drivers+0x53/0x60 [] _call_console_drivers+0x4b/0x90 [] release_console_sem+0xc5/0x1f0 [] vprintk+0x1ab/0x3e0 [] ? _spin_unlock_irqrestore+0x6c/0x70 [] ? __queue_work+0x31/0x40 [] ? queue_work+0x45/0x50 [] ? queue_delayed_work+0xf/0x30 [] ? _spin_unlock_irqrestore+0x43/0x70 [] ? schedule_delayed_work+0x11/0x20 [] printk+0x1b/0x20 [] mii_check_media+0x196/0x1e0 [] ? _spin_lock+0x5b/0x70 [] rtl_check_media+0x24/0x30 [] rtl8139_interrupt+0x42a/0x4a0 [] handle_IRQ_event+0x28/0x70 [] handle_fasteoi_irq+0x6b/0xe0 [] do_IRQ+0x48/0xa0 [] ? trace_hardirqs_off_thunk+0xc/0x18 [] common_interrupt+0x28/0x30 [] ? update_wall_time+0x36b/0x7d0 [] ? mwait_idle+0x3c/0x50 [] cpu_idle+0x6c/0x120 [] rest_init+0x62/0x70 ======================= <4>---[ end trace 33bf576b6277932f ]--- <4>------------[ cut here ]------------ <4>WARNING: at /uio/arkimedes/s29/vegardno/git-working/linux-2.6/kernel/smp.c:216 smp_call_function_single+0x10a/0x110() Pid: 0, comm: swapper Tainted: G W 2.6.27-rc2-00325-g796aade-dirty #3 [] warn_on_slowpath+0x4f/0x80 [] ? __print_symbol+0x2a/0x40 [] ? vprintk+0x2d/0x3e0 [] smp_call_function_single+0x10a/0x110 [] ? stop_this_cpu+0x0/0x50 [] smp_call_function_mask+0x12d/0x150 [] ? stop_this_cpu+0x0/0x50 [] ? rest_init+0x62/0x70 [] ? delay_tsc+0xac/0xb8 [] ? vprintk+0x2d/0x3e0 [] ? print_trace_address+0x45/0x50 [] ? rest_init+0x62/0x70 [] ? stop_this_cpu+0x0/0x50 [] smp_call_function+0x30/0x60 [] ? delay_tsc+0x98/0xb8 [] native_smp_send_stop+0x1e/0x70 [] ? delay_tsc+0x98/0xb8 [] panic+0x62/0x120 [] ? delay_tsc+0x98/0xb8 [] do_exit+0x7e2/0x880 [] ? show_registers+0x7c/0x230 [] ? do_unblank_screen+0x24/0x130 [] ? die_nmi+0xb9/0xf0 [] ? delay_tsc+0x98/0xb8 [] ? delay_tsc+0x98/0xb8 [] die_nmi+0xef/0xf0 [] ? delay_tsc+0x98/0xb8 [] nmi_watchdog_tick+0x1d5/0x1e0 [] do_nmi+0x97/0x2d0 [] nmi_stack_correct+0x26/0x2b [] ? as_remove_queued_request+0x9b/0xb0 [] ? delay_tsc+0x98/0xb8 [] __delay+0x9/0x10 [] _raw_spin_lock+0xb9/0x140 [] ? trace_hardirqs_off+0xb/0x10 [] _spin_lock_irqsave+0x76/0x90 [] ? rtl8139_start_xmit+0x65/0x130 [] rtl8139_start_xmit+0x65/0x130 [] netpoll_send_skb+0x158/0x1a0 [] netpoll_send_udp+0x1db/0x1f0 [] write_msg+0x8c/0xc0 [] __call_console_drivers+0x53/0x60 [] _call_console_drivers+0x4b/0x90 [] release_console_sem+0xc5/0x1f0 [] vprintk+0x1ab/0x3e0 [] ? _spin_unlock_irqrestore+0x6c/0x70 [] ? __queue_work+0x31/0x40 [] ? queue_work+0x45/0x50 [] ? queue_delayed_work+0xf/0x30 [] ? _spin_unlock_irqrestore+0x43/0x70 [] ? schedule_delayed_work+0x11/0x20 [] printk+0x1b/0x20 [] mii_check_media+0x196/0x1e0 [] ? _spin_lock+0x5b/0x70 [] rtl_check_media+0x24/0x30 [] rtl8139_interrupt+0x42a/0x4a0 [] handle_IRQ_event+0x28/0x70 [] handle_fasteoi_irq+0x6b/0xe0 [] do_IRQ+0x48/0xa0 [] ? trace_hardirqs_off_thunk+0xc/0x18 [] common_interrupt+0x28/0x30 [] ? update_wall_time+0x36b/0x7d0 [] ? mwait_idle+0x3c/0x50 [] cpu_idle+0x6c/0x120 [] rest_init+0x62/0x70 ======================= <4>---[ end trace 33bf576b6277932f ]--- ...this seems to contain at least a little bit of useful information. Looks to me like it's quite simply a recursive printk. I don't understand why the printk code doesn't catch this, though. Any ideas? Vegard -- "The animistic metaphor of the bug that maliciously sneaked in while the programmer was not looking is intellectually dishonest as it disguises that the error is the programmer's own creation." -- E. W. Dijkstra, EWD1036