From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1759170AbYD2Gwa (ORCPT ); Tue, 29 Apr 2008 02:52:30 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1754169AbYD2GwW (ORCPT ); Tue, 29 Apr 2008 02:52:22 -0400 Received: from E23SMTP03.au.ibm.com ([202.81.18.172]:34709 "EHLO e23smtp03.au.ibm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752440AbYD2GwU (ORCPT ); Tue, 29 Apr 2008 02:52:20 -0400 Date: Tue, 29 Apr 2008 12:22:11 +0530 From: Gautham R Shenoy To: Ingo Molnar , Peter Zijlstra , Dhaval Giani , Srivatsa Vaddagiri , Balbir Singh Cc: linux-kernel@vger.kernel.org Subject: [BUG-REPORT] hrtick_start_fair and CPU-Hotplug Message-ID: <20080429065211.GB7859@in.ibm.com> Reply-To: ego@in.ibm.com MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.5.15+20070412 (2007-04-11) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Hello! While running the usual CPU-Hotplug stress tests on linux-2.6.25, I noticed the following in the console logs. This is a wee bit difficult to reproduce. In the past 10 runs I hit this only once. ------------[ cut here ]------------ WARNING: at kernel/sched.c:962 hrtick+0x2e/0x65() Modules linked in: usbhid Pid: 15, comm: events/0 Not tainted 2.6.25 #3 [] warn_on_slowpath+0x40/0x65 [] schedule_on_each_cpu+0x74/0xbc [] hrtick+0x0/0x65 [] __lock_acquire+0xbe8/0xbf7 [] __lock_acquire+0xbe8/0xbf7 [] __run_hrtimer+0x42/0x79 [] hrtick+0x2e/0x65 [] hrtick+0x0/0x65 [] __run_hrtimer+0x46/0x79 [] hrtimer_interrupt+0x100/0x173 [] smp_apic_timer_interrupt+0x68/0x77 [] apic_timer_interrupt+0x33/0x38 [] native_read_tsc+0xe/0xf [] delay_tsc+0x12/0x1d [] __const_udelay+0x29/0x2a [] do_boot_cpu+0x2f0/0x473 [] do_warm_boot_cpu+0x11/0x1a [] run_workqueue+0xd1/0x1a5 [] run_workqueue+0x91/0x1a5 [] do_warm_boot_cpu+0x0/0x1a [] worker_thread+0xb6/0xc2 [] autoremove_wake_function+0x0/0x2d [] worker_thread+0x0/0xc2 [] kthread+0x38/0x5d [] kthread+0x0/0x5d [] kernel_thread_helper+0x7/0x10 ======================= ---[ end trace 9ccf64fec08bb0d7 ]--- ------------[ cut here ]------------ WARNING: at kernel/sched.c:514 __update_rq_clock+0x69/0x12b() Modules linked in: usbhid Pid: 15, comm: events/0 Not tainted 2.6.25 #3 [] warn_on_slowpath+0x40/0x65 [] schedule_on_each_cpu+0x74/0xbc [] __lock_acquire+0xbe8/0xbf7 [] native_sched_clock+0x91/0xa2 [] __update_rq_clock+0x69/0x12b [] hrtick+0x46/0x65 [] hrtick+0x0/0x65 [] __run_hrtimer+0x46/0x79 [] hrtimer_interrupt+0x100/0x173 [] smp_apic_timer_interrupt+0x68/0x77 [] apic_timer_interrupt+0x33/0x38 [] native_read_tsc+0xe/0xf [] delay_tsc+0x12/0x1d [] __const_udelay+0x29/0x2a [] do_boot_cpu+0x2f0/0x473 [] do_warm_boot_cpu+0x11/0x1a [] run_workqueue+0xd1/0x1a5 [] run_workqueue+0x91/0x1a5 [] do_warm_boot_cpu+0x0/0x1a [] worker_thread+0xb6/0xc2 [] autoremove_wake_function+0x0/0x2d [] worker_thread+0x0/0xc2 [] kthread+0x38/0x5d [] kthread+0x0/0x5d [] kernel_thread_helper+0x7/0x10 ======================= ---[ end trace 9ccf64fec08bb0d7 ]--- Calibrating delay using timer specific routine.. 186544.67 BogoMIPS (lpj=373089344) CPU: L1 I cache: 32K, L1 D cache: 32K CPU: L2 cache: 4096K CPU: Physical Processor ID: 3 CPU: Processor Core ID: 1 Intel machine check architecture supported. Intel machine check reporting enabled on CPU#3. CPU3: Intel(R) Xeon(R) CPU 5160 @ 3.00GHz stepping 06 checking TSC synchronization [CPU#0 -> CPU#3]: passed. lockdep: fixing up alternatives. Booting processor 1/1 ip 4000 Initializing CPU#1 Calibrating delay using timer specific routine.. 5985.62 BogoMIPS (lpj=11971248) CPU: L1 I cache: 32K, L1 D cache: 32K CPU: L2 cache: 4096K CPU: Physical Processor ID: 0 CPU: Processor Core ID: 1 Intel machine check architecture supported. . . . . . After some half hour, BUG: unable to handle kernel NULL pointer dereference at 00000000 IP: [] hrtick_start_fair+0x57/0x156 *pde = 00000000 Oops: 0000 [#1] SMP Modules linked in: usbhid Pid: 3316, comm: bash Not tainted (2.6.25 #3) EIP: 0060:[] EFLAGS: 00010002 CPU: 1 EIP is at hrtick_start_fair+0x57/0x156 EAX: 00000000 EBX: c04ffc88 ECX: 00000001 EDX: 00000003 ESI: f35a1020 EDI: f31a90e0 EBP: cc84fe00 ESP: f60e7e80 DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068 Process bash (pid: 3316, ti=f60e6000 task=f78dc020 task.ti=f60e6000) Stack: 00b873a6 c011c4b9 f31a90e0 cc84cb80 cc84fe00 c04ffc88 f35a1020 cc84fe00 00000001 c011715d cc84fe00 f35a1020 cc84fe00 c0117183 f35a1020 00000001 c011c961 00000000 0000000f 00000003 00000282 c06c7d7c 00000003 00000000 Call Trace: [] task_rq_lock+0x2d/0x53 [] enqueue_task+0x49/0x54 [] activate_task+0x1b/0x2e [] try_to_wake_up+0x15e/0x1a1 [] cpu_callback+0xb2/0x12a [] writeback_set_ratelimit+0x11/0x43 [] notifier_call_chain+0x2a/0x47 [] raw_notifier_call_chain+0x9/0xc [] _cpu_up+0xa8/0xd6 [] cpu_up+0x48/0x59 [] store_online+0x3a/0x56 [] store_online+0x0/0x56 [] sysdev_store+0x1e/0x22 [] sysfs_write_file+0xb5/0xe2 [] sysfs_write_file+0x0/0xe2 [] vfs_write+0x84/0xf7 [] sys_write+0x3c/0x63 [] sysenter_past_esp+0x5f/0xa5 ======================= Code: 95 00 43 6d c0 39 c5 74 0f ba 2d 03 00 00 b8 76 a7 5c c0 e8 a7 9d 00 00 f6 05 50 4a 6d c0 08 0f 84 fd 00 00 00 8b 85 84 04 00 00 <8b> 00 83 b8 9c 00 00 00 00 0f 84 e8 00 00 00 8b 44 24 0c 8b 58 EIP: [] hrtick_start_fair+0x57/0x156 SS:ESP 0068:f60e7e80 ---[ end trace 9ccf64fec08bb0d7 ]--- ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ Disassembly of hrtick_start_fair + 0x57 is as follows: 00001abd : hrtick_start_fair(): . . . . /home/ego/kernels/linux-2.6.25/kernel/sched_fair.c:815 1b0e: 8b 85 84 04 00 00 mov 0x484(%ebp),%eax ------------------------------------------------------------ 1b14: 8b 00 mov (%eax),%eax ------------------------------------------------------------- 1b16: 83 b8 9c 00 00 00 00 cmpl $0x0,0x9c(%eax) 1b1d: 0f 84 e8 00 00 00 je 1c0b 1b23: 8b 44 24 0c mov 0xc(%esp),%eax 1b27: 8b 58 08 mov 0x8(%eax),%ebx 1b2a: 83 fb 01 cmp $0x1,%ebx 1b2d: 0f 86 d8 00 00 00 jbe 1c0b I am not well versed with this part of the code, so just wondering if we are doing a good job at handling the cancellation of any per-cpu scheduler timers during CPU-Hotplug. -- Thanks and Regards gautham