Message-ID: <20120619185457.GA6827@linux.vnet.ibm.com>
Date:	Tue, 19 Jun 2012 11:54:57 -0700
From:	"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
To:	Konrad Rzeszutek Wilk <konrad.wilk@...cle.com>
Cc:	linux-kernel@...r.kernel.org, tglx@...utronix.de,
	johnstul@...ibm.com, fweisbec@...il.com
Subject: Re: WARNING: at /home/konrad/ssd/linux/kernel/rcutree.c:1547
 __rcu_process_callbacks+0x42e/0x440()

On Tue, Jun 19, 2012 at 11:47:18AM -0700, Paul E. McKenney wrote:
> On Tue, Jun 19, 2012 at 02:22:16PM -0400, Konrad Rzeszutek Wilk wrote:
> > 
> > I've been getting this when booting a Xen PV guest with 3 CPUs (of which two are
> > online). Any thoughts?
> 
> Maybe...  I am assuming that your kernel/rcutree.c:1547 is this line of code:
> 
> 	WARN_ON_ONCE(cpu_is_offline(smp_processor_id()));
> 
> This is line 1549 in current mainline.
> 
> If my guess is correct, my question is "why on earth is a CPU that has
> marked itself offline taking a timer interrupt???"
> 
> I could provide a patch to make RCU work around this problem from its
> viewpoint, but taking timer interrupts on an offline CPU is an extremely
> bad idea.  It would be good to fix the underlying problem instead of
> silencing RCU's warning.

And one possible source for the problem might be if queue_stop_cpus_work()
or one of its ancestors in the function-call graph incorrectly enabled
interrupts.

							Thanx, Paul

> If my guess on what line is warning you is wrong, please do let me know
> what the line really is -- or even better, the corresponding mainline
> git commit ID.
> 
> 							Thanx, Paul
> 
> > Using config file "/test.xm".
> > Started domain latest (id=6)
> > [    0.000000] console [hvc0] enabled, bootconsole disabled
> > [    0.000000] Xen: using vcpuop timer interface
> > [    0.000000] installing Xen timer for CPU 0
> > [    0.000000] Detected 3093.036 MHz processor.
> > [    0.000999] Calibrating delay loop (skipped), value calculated using timer frequency.. 6186.07 BogoMIPS (lpj=3093036)
> > [    0.000999] pid_max: default: 32768 minimum: 301
> > [    0.000999] Security Framework initialized
> > [    0.000999] SELinux:  Initializing.
> > [    0.000999] SELinux:  Starting in permissive mode
> > [    0.000999] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes)
> > [    0.000999] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes)
> > [    0.000999] Mount-cache hash table entries: 256
> > [    0.000999] Initializing cgroup subsys cpuacct
> > [    0.000999] Initializing cgroup subsys freezer
> > [    0.000999] ENERGY_PERF_BIAS: Set to 'normal', was 'performance'
> > [    0.000999] ENERGY_PERF_BIAS: View and update with x86_energy_perf_policy(8)
> > [    0.000999] CPU: Physical Processor ID: 0
> > [    0.000999] CPU: Processor Core ID: 0
> > [    0.000999] SMP alternatives: switching to UP code
> > [    0.026357] cpu 0 spinlock event irq 17
> > [    0.026377] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only.
> > [    0.026462] NMI watchdog: disabled (cpu0): hardware events not enabled
> > [    0.026567] installing Xen timer for CPU 1
> > [    0.026580] cpu 1 spinlock event irq 24
> > [    0.026603] SMP alternatives: switching to SMP code
> > [    0.049557] NMI watchdog: disabled (cpu1): hardware events not enabled
> > [    0.049756] installing Xen timer for CPU 2
> > [    0.049786] cpu 2 spinlock event irq 31
> > [    0.049996] NMI watchdog: disabled (cpu2): hardware events not enabled
> > [    0.049996] Brought up 3 CPUs
> > [    0.050313] kworker/u:0 (20) used greatest stack depth: 6000 bytes left
> > [    0.051028] Grant tables using version 2 layout.
> > [    0.051065] Grant table initialized
> > [    0.069993] RTC time: 165:165:165, date: 165/165/65
> > [    0.070103] NET: Registered protocol family 16
> > [    0.070141] kworker/u:0 (24) used greatest stack depth: 5544 bytes left
> > [    0.073000] ------------[ cut here ]------------
> > [    0.073006] WARNING: at /home/konrad/ssd/linux/kernel/rcutree.c:1547 __rcu_process_callbacks+0x42e/0x440()
> > [    0.073008] Modules linked in:
> > [    0.073010] Pid: 12, comm: migration/2 Not tainted 3.5.0-rc2 #2
> > [    0.073011] Call Trace:
> > [    0.073017]  <IRQ>  [<ffffffff810718ea>] warn_slowpath_common+0x7a/0xb0
> > [    0.073019]  [<ffffffff81071935>] warn_slowpath_null+0x15/0x20
> > [    0.073021]  [<ffffffff810edb1e>] __rcu_process_callbacks+0x42e/0x440
> > [    0.073023]  [<ffffffff810edb50>] rcu_process_callbacks+0x20/0x40
> > [    0.073025]  [<ffffffff810792c9>] __do_softirq+0xa9/0x160
> > [    0.073028]  [<ffffffff810a1065>] ? sched_clock_local+0x25/0x90
> > [    0.073030]  [<ffffffff810d7201>] ? queue_stop_cpus_work+0x51/0xf0
> > [    0.073033]  [<ffffffff815cee1c>] call_softirq+0x1c/0x30
> > [    0.073034]  [<ffffffff81039435>] do_softirq+0x65/0xa0
> > [    0.073036]  [<ffffffff810790c5>] irq_exit+0xd5/0xf0
> > [    0.073039]  [<ffffffff8132347f>] xen_evtchn_do_upcall+0x2f/0x40
> > [    0.073040]  [<ffffffff815cee6e>] xen_do_hypervisor_callback+0x1e/0x30
> > [    0.073042]  <EOI>  [<ffffffff810d7201>] ? queue_stop_cpus_work+0x51/0xf0
> > [    0.073044]  [<ffffffff8100122a>] ? hypercall_page+0x22a/0x1000
> > [    0.073045]  [<ffffffff8100122a>] ? hypercall_page+0x22a/0x1000
> > [    0.073048]  [<ffffffff8103361d>] ? xen_force_evtchn_callback+0xd/0x10
> > [    0.073049]  [<ffffffff81033ed2>] ? check_events+0x12/0x20
> > [    0.073051]  [<ffffffff81033ebf>] ? xen_restore_fl_direct_reloc+0x4/0x4
> > [    0.073053]  [<ffffffff810d73aa>] ? stop_machine_cpu_stop+0xba/0xf0
> > [    0.073054]  [<ffffffff810d72f0>] ? stop_one_cpu_nowait+0x50/0x50
> > [    0.073055]  [<ffffffff810d7021>] ? cpu_stopper_thread+0xf1/0x1c0
> > [    0.073058]  [<ffffffff815c5d7e>] ? __schedule+0x3be/0x760
> > [    0.073060]  [<ffffffff815c6d59>] ? _raw_spin_unlock_irqrestore+0x19/0x30
> > [    0.073061]  [<ffffffff810d6f30>] ? res_counter_charge+0x10/0x10
> > [    0.073064]  [<ffffffff81090c46>] ? kthread+0x96/0xa0
> > [    0.073065]  [<ffffffff815ced24>] ? kernel_thread_helper+0x4/0x10
> > [    0.073067]  [<ffffffff815c72b8>] ? retint_restore_args+0x5/0x6
> > [    0.073069]  [<ffffffff815ced20>] ? gs_change+0x13/0x13
> > [    0.073073] ---[ end trace 4eaa2a86a8e2da22 ]---
> > [    0.073075] dca service started, version 1.12.1
> > [    0.074006] PCI: setting up Xen PCI frontend stub
> > [    0.074015] PCI: pci_cache_line_size set to 64 bytes
> > [    0.088093] bio: create slab <bio-0> at 0
> > [    0.089051] ACPI: Interpreter disabled.
> > [    0.089063] xen/balloon: Initialising balloon driver.
> > [    0.091124] xen-balloon: Initialising balloon driver.
> > [    0.092068] vgaarb: loaded
> > [    0.092068] usbcore: registered new interface driver usbfs
> > [    0.092087] usbcore: registered new interface driver hub
> > [    0.093027] usbcore: registered new device driver usb
> > [    0.093039] PCI: System does not support PCI
> > [    0.093039] PCI: System does not support PCI
> > [    0.094043] NetLabel: Initializing
> > [    0.094052] NetLabel:  domain hash size = 128
> > [    0.094057] NetLabel:  protocols = UNLABELED CIPSOv4
> > [    0.094077] NetLabel:  unlabeled traffic allowed by default
> > [    0.094099] Switching to clocksource xen
> > [    0.094160] pnp: PnP ACPI: disabled
> > [    0.101664] NET: Registered protocol family 2
> > [    0.101866] IP route cache hash table entries: 32768 (order: 6, 262144 bytes)
> > [    0.102859] TCP established hash table entries: 131072 (order: 9, 2097152 bytes)
> > [    0.103661] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
> > [    0.103849] TCP: Hash tables configured (established 131072 bind 65536)
> > [    0.103858] TCP: reno registered
> > [    0.103873] UDP hash table entries: 512 (order: 2, 16384 bytes)
> > [    0.103891] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
> > [    0.104035] NET: Registered protocol family 1
> > [    0.104333] RPC: Registered named UNIX socket transport module.
> > [    0.104347] RPC: Registered udp transport module.
> > [    0.104356] RPC: Registered tcp transport module.
> > [    0.104362] RPC: Registered tcp NFSv4.1 backchannel transport module.
> > [    0.104371] PCI: CLS 0 bytes, default 64
> > [    0.104511] Trying to unpack rootfs image as initramfs...
> > [    0.337888] Freeing initrd memory: 273152k freed
> > [    0.383239] platform rtc_cmos: registered platform RTC device (no PNP device found)
> > [    0.383418] Machine check injector initialized
> > [    0.384702] microcode: CPU0 sig=0x206a7, pf=0x2, revision=0x12
> > [    0.384730] microcode: CPU1 sig=0x206a7, pf=0x2, revision=0x12
> > [    0.384859] microcode: Microcode Update Driver: v2.00 <tigran@...azian.fsnet.co.uk>, Peter Oruba
> > [    0.385589] audit: initializing netlink socket (disabled)
> > [    0.385612] type=2000 audit(1340130254.678:1): initialized
> > [    0.403267] HugeTLB registered 2 MB page size, pre-allocated 0 pages
> > [    0.403508] VFS: Disk quotas dquot_6.5.2
> > [    0.403552] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
> > [    0.403720] NFS: Registering the id_resolver key type
> > [    0.403739] Key type id_resolver registered
> > [    0.403882] NTFS driver 2.1.30 [Flags: R/W].
> > [    0.403981] msgmni has been set to 1986
> > [    0.404021] SELinux:  Registering netfilter hooks
> > [    0.404794] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
> > [    0.404806] io scheduler noop registered
> > [    0.404812] io scheduler deadline registered
> > [    0.404843] io scheduler cfq registered (default)
> > [    0.404993] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
> > [    0.405260] ioatdma: Intel(R) QuickData Technology Driver 4.00
> > [    0.451143] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
> > [    0.452662] Non-volatile memory driver v1.3
> > [    0.452673] Linux agpgart interface v0.103
> > [    0.453294] [drm] Initialized drm 1.1.0 20060810
> > [    0.457300] brd: module loaded
> > [    0.459306] loop: module loaded
> > [    0.459798] Fixed MDIO Bus: probed
> > [    0.459807] tun: Universal TUN/TAP device driver, 1.6
> > [    0.459813] tun: (C) 1999-2004 Max Krasnyansky <maxk@...lcomm.com>
> > [    0.459986] ixgbevf: Intel(R) 10 Gigabit PCI Express Virtual Function Network Driver - version 2.6.0-k
> > [    0.459998] ixgbevf: Copyright (c) 2009 - 2012 Intel Corporation.
> > [    0.460777] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
> > [    0.460788] ehci_hcd: block sizes: qh 112 qtd 96 itd 192 sitd 96
> > [    0.460891] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
> > [    0.460901] ohci_hcd: block sizes: ed 80 td 96
> > [    0.461001] uhci_hcd: USB Universal Host Controller Interface driver
> > [    0.461293] usbcore: registered new interface driver usblp
> > [    0.461392] usbcore: registered new interface driver libusual
> > [    0.461734] i8042: PNP: No PS/2 controller found. Probing ports directly.
> > [    0.462609] i8042: No controller found
> > [    0.462737] mousedev: PS/2 mouse device common for all mice
> > [    0.523312] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
> > [    0.523440] rtc_cmos: probe of rtc_cmos failed with error -38
> > [    0.523679] EFI Variables Facility v0.08 2004-May-17
> > [    0.523734] zram: num_devices not specified. Using default: 1
> > [    0.523739] zram: Creating 1 devices ...
> > [    0.523980] xenoprofile_init: ret 0, events 4, xenoprof_is_primary 0
> > [    0.524019] Netfilter messages via NETLINK v0.30.
> > [    0.524035] nf_conntrack version 0.5.0 (7944 buckets, 31776 max)
> > [    0.524099] ctnetlink v0.93: registering with nfnetlink.
> > [    0.524262] ip_tables: (C) 2000-2006 Netfilter Core Team
> > [    0.524293] TCP: cubic registered
> > [    0.524298] Initializing XFRM netlink socket
> > [    0.524346] NET: Registered protocol family 10
> > [    0.524486] ip6_tables: (C) 2000-2006 Netfilter Core Team
> > [    0.524675] sit: IPv6 over IPv4 tunneling driver
> > [    0.524866] NET: Registered protocol family 17
> > [    0.524902] Key type dns_resolver registered
> > [    0.525076] PM: Hibernation image not present or could not be loaded.
> > [    0.525094] registered taskstats version 1
> > [    0.525121] XENBUS: Device with no driver: device/vkbd/0
> > [    0.525127] XENBUS: Device with no driver: device/vfb/0
> > [    0.525132] XENBUS: Device with no driver: device/vif/0
> > [    0.525191]   Magic number: 1:252:3141
> > [    0.525898] Freeing unused kernel memory: 716k freed
> > [    0.526109] Write protecting the kernel read-only data: 8192k
> > [    0.530939] Freeing unused kernel memory: 172k freed
> > [    0.531314] Freeing unused kernel memory: 356k freed
> > init started: BusyBox v1.14.3 (2012-06-19 13:33:49 EDT)
> > [    0.536840] consoletype (1049) used greatest stack depth: 5304 bytes left
> > Mounting directories  [  OK  ]
> > mount: mount point /proc/bus/usb does not exist
> > [    0.723241] modprobe (1078) used greatest stack depth: 5064 bytes left
> > mount: mount point /sys/kernel/config does not exist
> > [    0.731128] core_filesystem (1050) used greatest stack depth: 4984 bytes left
> > [    0.744953] input: Xen Virtual Keyboard as /devices/virtual/input/input0
> > [    0.745268] input: Xen Virtual Pointer as /devices/virtual/input/input1
> > [    0.963843] Initialising Xen virtual ethernet driver.
> > [    1.085463] udevd (1114): /proc/1114/oom_adj is deprecated, please use /proc/1114/oom_score_adj instead.
> > udevd-work[1125]: error opening ATTR{/sys/devices/system/cpu/cpu0/online} for writing: No such file or directory
> > 
> > Waiting for devices [  OK  ]
> > [    1.247709] ip (1927) used greatest stack depth: 3768 bytes left
> > Waiting for init.pre_custom [  OK  ]
> > Waiting for fb [  OK  ]
> > Starting..[/dev/fb0]
> > /dev/fb0: len:0
> > /dev/fb0: bits/pixel32
> > (7f69b03c2000): Writting .. [800:600]
> > Done!
> > .. blah blah
> > 

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists