Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1946666AbXBIQkw (ORCPT ); Fri, 9 Feb 2007 11:40:52 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1946650AbXBIQkg (ORCPT ); Fri, 9 Feb 2007 11:40:36 -0500 Received: from mail.dbd-breitband.de ([217.188.211.21]:13655 "EHLO dbd-mpx01.dbd-breitband.de" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1946613AbXBIQkE (ORCPT ); Fri, 9 Feb 2007 11:40:04 -0500 From: Marc Donner Organization: DBD DeutscheBreitbandDienste To: David Lang , Arjan van de Ven Subject: Re: cpu load balancing problem on smp Date: Fri, 9 Feb 2007 16:12:13 +0100 User-Agent: KMail/1.9.5 References: <200702061832.17771.donner@dbd-breitband.de> <45C96AC1.4030301@linux.intel.com> In-Reply-To: Cc: linux-kernel@vger.kernel.org MIME-Version: 1.0 Content-Type: Multipart/Mixed; boundary="Boundary-00=_N9IzFWu6zijktM1" Message-Id: <200702091612.13426.donner@dbd-breitband.de> Sender: linux-kernel-owner@vger.kernel.org X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 25440 Lines: 657 --Boundary-00=_N9IzFWu6zijktM1 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline On Thursday 08 February 2007 09:42, you wrote: > On Wed, 7 Feb 2007, Arjan van de Ven wrote: > > Marc Donner wrote: > >> 501: 215717 209388 209430 202514 PCI-MSI-edge > >> eth10 502: 927 1019 1053 888 PCI-MSI-edge > >> eth11 > > > > this is odd, this is not an irq distribution that irqbalance should give > > you 1 > > > >> NMI: 451 39 42 46 > >> LOC: 170899 170864 170846 170788 > >> ERR: 0 > >> > >> top output: > >> > >> top - 01:45:32 up 16 min, 2 users, load average: 1.04, 0.92, 0.50 > >> Tasks: 81 total, 3 running, 78 sleeping, 0 stopped, 0 zombie > >> Cpu0 : 0.0% us, 0.0% sy, 0.0% ni, 0.0% id, 0.0% wa, 0.0% hi, > >> 100.0% si > > > > and this doesn't match the irq output... > > sounds as if something has a real bug; can you send an lsmod ? maybe some > > driver keeps doing si's > > since this only happens when he adds more iptables rules, is it possible > that there sis some locking, or otherdata structure access that's > serializing things under load? > > Marc, since you don't use modules, send your .config. > > David Lang i've inserted some more iptables rules, and got 'softlockup detected' messages. BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0x2cd/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] task_rq_lock+0x3d/0x6f [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 Marc --Boundary-00=_N9IzFWu6zijktM1 Content-Type: text/plain; charset="iso-8859-1"; name="x.txt" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="x.txt" BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0x2cd/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] task_rq_lock+0x3d/0x6f [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xaf/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] lock_timer_base+0x1b/0x3c [] __mod_timer+0xa6/0xb4 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xbf/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] handle_edge_irq+0x106/0x12f [] handle_edge_irq+0x0/0x12f [] do_IRQ+0x137/0x159 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0x2c8/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] handle_edge_irq+0x106/0x12f [] handle_edge_irq+0x0/0x12f [] do_IRQ+0x137/0x159 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xbf/0x315 [] ip_rcv+0x0/0x48e [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] lock_timer_base+0x1b/0x3c [] __mod_timer+0xa6/0xb4 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] do_IRQ+0x137/0x159 [] ksoftirqd+0x0/0x8f [] ret_from_intr+0x0/0xa [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xc3/0x315 [] smp_local_timer_interrupt+0x32/0x55 [] bnx2_start_xmit+0x0/0x487 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] do_IRQ+0x137/0x159 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] do_IRQ+0x137/0x159 [] ksoftirqd+0x0/0x8f [] ret_from_intr+0x0/0xa [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xd6/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] handle_edge_irq+0x106/0x12f [] handle_edge_irq+0x0/0x12f [] do_IRQ+0x137/0x159 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xce/0x315 [] smp_apic_timer_interrupt+0x54/0x67 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] printk+0x4e/0x56 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] do_IRQ+0x137/0x159 [] ksoftirqd+0x0/0x8f [] ret_from_intr+0x0/0xa [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] bnx2_start_xmit+0x0/0x487 [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] bnx2_start_xmit+0x0/0x487 [] __qdisc_run+0x1b9/0x1c2 [] dev_queue_xmit+0x123/0x247 [] ip_output+0x1e7/0x22b [] ip_forward+0x1b6/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] printk+0x4e/0x56 [] task_rq_lock+0x3d/0x6f [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xbc/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] task_rq_lock+0x3d/0x6f [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] ksoftirqd+0x0/0x8f [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] smp_apic_timer_interrupt+0x54/0x67 [] apic_timer_interrupt+0x66/0x70 [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [] kthread+0xcb/0xf5 [] child_rip+0xa/0x12 [] kthread+0x0/0xf5 [] child_rip+0x0/0x12 BUG: soft lockup detected on CPU#1! Call Trace: [] softlockup_tick+0xda/0xec [] update_process_times+0x42/0x68 [] smp_local_timer_interrupt+0x32/0x55 [] ip_rcv+0x0/0x48e [] smp_apic_timer_interrupt+0x4f/0x67 [] apic_timer_interrupt+0x66/0x70 [] ip_rcv+0x0/0x48e [] ipt_do_table+0xbc/0x315 [] nf_iterate+0x3f/0x7b [] ip_forward_finish+0x0/0x3e [] nf_hook_slow+0x5f/0xca [] ip_forward_finish+0x0/0x3e [] ip_forward+0x16e/0x212 [] ip_rcv+0x447/0x48e [] e1000_clean_rx_irq+0x41e/0x4ea [] e1000_clean+0x2f7/0x4b0 [] printk+0x4e/0x56 [] net_rx_action+0x78/0x14a [] __do_softirq+0x56/0xd3 [] call_softirq+0x1c/0x28 [] do_softirq+0x2c/0x7d [] do_IRQ+0x137/0x159 [] ksoftirqd+0x0/0x8f [] ret_from_intr+0x0/0xa [] do_softirq+0x7b/0x7d [] ksoftirqd+0x4f/0x8f [