Bug 707552 - WARNING: at block/blk-core.c during boot
Summary: WARNING: at block/blk-core.c during boot
Keywords:
Status: CLOSED UPSTREAM
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 15
Hardware: Unspecified
OS: Linux
unspecified
low
Target Milestone: ---
Assignee: Justin M. Forbes
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: 713399
TreeView+ depends on / blocked
 
Reported: 2011-05-25 11:51 UTC by Vadym Chepkov
Modified: 2011-09-22 13:46 UTC (History)
9 users (show)

Fixed In Version:
Clone Of:
: 713399 (view as bug list)
Environment:
Last Closed: 2011-09-22 13:46:51 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
add extra checks debugging prinkt to xen-blkfront (1.64 KB, patch)
2011-07-08 15:14 UTC, Igor Mammedov
no flags Details | Diff
i386 PAE config for upstream kernel (121.94 KB, text/plain)
2011-08-16 09:01 UTC, Igor Mammedov
no flags Details
Enable function_graph tracer for i386 and add additional tracing. (2.64 KB, patch)
2011-08-16 09:08 UTC, Igor Mammedov
no flags Details | Diff
ftrace function graph pointing to a place where irq-s are becoming enabled (1.75 MB, text/plain)
2011-08-16 10:32 UTC, Igor Mammedov
no flags Details
Reproducer for irq unmasking problem using xen_netfront (1.65 KB, application/x-gzip)
2011-09-01 09:02 UTC, Igor Mammedov
no flags Details
do not enable iterrupts when returning from exception in interrupt context (1.69 KB, patch)
2011-09-01 10:44 UTC, Igor Mammedov
no flags Details | Diff

Description Vadym Chepkov 2011-05-25 11:51:38 UTC
Description of problem:

During the boot in Xen DomU fedora 15 kernel produces multiple WARNING messages (seems one per file system)

[    9.661091] ------------[ cut here ]------------
[    9.661116] WARNING: at block/blk-core.c:352 blk_start_queue+0x24/0x3c()
[    9.661124] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[    9.661143] Pid: 341, comm: udevd Not tainted 2.6.38.6-27.fc15.i686.PAE #1
[    9.661156] Call Trace:
[    9.661163]  [<c07e15f2>] ? printk+0x2d/0x2f
[    9.661172]  [<c044205d>] warn_slowpath_common+0x7c/0x91
[    9.661179]  [<c05c2b22>] ? blk_start_queue+0x24/0x3c
[    9.661186]  [<c05c2b22>] ? blk_start_queue+0x24/0x3c
[    9.661193]  [<c0442094>] warn_slowpath_null+0x22/0x24
[    9.661200]  [<c05c2b22>] blk_start_queue+0x24/0x3c
[    9.661209]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[    9.661219]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[    9.661228]  [<c048eb22>] handle_IRQ_event+0x4c/0xfe
[    9.661236]  [<c045db5b>] ? sched_clock_cpu+0x134/0x144
[    9.661244]  [<c04905d7>] handle_fasteoi_irq+0x74/0xa6
[    9.661252]  [<c064b9f4>] __xen_evtchn_do_upcall+0xb5/0x118
[    9.661260]  [<c064cdf8>] xen_evtchn_do_upcall+0x20/0x2f
[    9.661268]  [<c0409c97>] xen_do_upcall+0x7/0xc
[    9.661275]  [<c0402227>] ? hypercall_page+0x227/0x1000
[    9.661283]  [<c0406283>] ? xen_force_evtchn_callback+0xf/0x14
[    9.661291]  [<c040629f>] xen_irq_enable+0x17/0x19
[    9.661298]  [<c04061fa>] __raw_callee_save_xen_irq_enable+0x6/0x8
[    9.661307]  [<c04294f9>] ? arch_local_irq_enable+0x9/0xb
[    9.661315]  [<c07ebe28>] do_page_fault+0xc7/0x30c
[    9.661323]  [<c05d93c3>] ? vsnprintf+0x147/0x269
[    9.661330]  [<c05d862d>] ? string+0x33/0x91
[    9.661336]  [<c07ebd61>] ? do_page_fault+0x0/0x30c
[    9.661343]  [<c07e9ae7>] error_code+0x67/0x6c
[    9.661351]  [<c043007b>] ? cpuacct_stats_show+0x41/0x58
[    9.661359]  [<c04d00d8>] ? mmap_region+0xf8/0x395
[    9.661366]  [<c05dadf6>] ? __copy_to_user_ll+0x49/0x51
[    9.661373]  [<c05dae42>] copy_to_user+0x44/0x4b
[    9.661381]  [<c05051fb>] simple_read_from_buffer+0x66/0x93
[    9.661389]  [<c05359b7>] sysfs_read_file+0x12f/0x14c
[    9.661396]  [<c059a083>] ? security_file_permission+0x27/0x2b
[    9.661406]  [<c04ede8f>] vfs_read+0x8d/0xd5
[    9.661412]  [<c0535888>] ? sysfs_read_file+0x0/0x14c
[    9.661419]  [<c04edf19>] sys_read+0x42/0x63
[    9.661426]  [<c07e93fc>] syscall_call+0x7/0xb
[    9.661432] ---[ end trace dc89da4cad290431 ]---


kernel-PAE-2.6.38.6-27.fc15.i686

Comment 1 Andrew Jones 2011-05-25 11:57:38 UTC
What host is this running on? RHEL? SUSE? which dom0 kernel?

Thanks.

Comment 2 Vadym Chepkov 2011-05-25 12:11:13 UTC
kernel-xen-2.6.18-238.9.1.el5

Centos 5.6

Comment 3 Andrew Jones 2011-05-25 14:03:14 UTC
Hi Vadym,

do you know which kernel this problem started with? Or do you have other linux distros running on this host that aren't showing the warnings F14, RHEL6, SL6, ...?

Thanks,
Drew

Comment 4 Vadym Chepkov 2011-05-25 15:53:22 UTC
I just upgraded from the Fedora-14
fedora-14 kernel doesn't have this issue:

kernel-PAE-2.6.35.12-90.fc14.i686

Comment 5 Chuck Ebbert 2011-05-25 15:55:25 UTC
void blk_start_queue(struct request_queue *q)
{
        WARN_ON(!irqs_disabled());

Comment 7 Igor Mammedov 2011-07-03 20:08:41 UTC
Vadim,

I've tried to reproduce the warning on several boxes without any success.
Can you reproduce it reliably in your env?

Comment 8 Vadym Chepkov 2011-07-03 22:28:07 UTC
Yes, it's 100% repeatable, every time during the boot.

I have kernel-PAE-2.6.38.8-32.fc15.i686 now, with the same result.

I will include all boot messages if it will help:

[    0.000000] Reserving virtual address space above 0xf5800000
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Linux version 2.6.38.8-32.fc15.i686.PAE (mockbuild.fedoraproject.org) (gcc version 4.6.0 20110530 (Red Hat 4.6.0-9) (GCC) ) #1 SMP Mon Jun 13 19:55:27 UTC 2011
[    0.000000] ACPI in unprivileged domain disabled
[    0.000000] released 0 pages of unused memory
[    0.000000] BIOS-provided physical RAM map:
[    0.000000]  Xen: 0000000000000000 - 00000000000a0000 (usable)
[    0.000000]  Xen: 00000000000a0000 - 0000000000100000 (reserved)
[    0.000000]  Xen: 0000000000100000 - 0000000020800000 (usable)
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI not present or invalid.
[    0.000000] last_pfn = 0x20800 max_arch_pfn = 0x1000000
[    0.000000] init_memory_mapping: 0000000000000000-0000000020800000
[    0.000000] RAMDISK: 00e73000 - 02b91000
[    0.000000] 0MB HIGHMEM available.
[    0.000000] 520MB LOWMEM available.
[    0.000000]   mapped low ram: 0 - 20800000
[    0.000000]   low ram: 0 - 20800000
[    0.000000] Zone PFN ranges:
[    0.000000]   DMA      0x00000010 -> 0x00001000
[    0.000000]   Normal   0x00001000 -> 0x00020800
[    0.000000]   HighMem  empty
[    0.000000] Movable zone start PFN for each node
[    0.000000] early_node_map[2] active PFN ranges
[    0.000000]     0: 0x00000010 -> 0x000000a0
[    0.000000]     0: 0x00000100 -> 0x00020800
[    0.000000] Using APIC driver default
[    0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org
[    0.000000] SMP: Allowing 1 CPUs, 0 hotplug CPUs
[    0.000000] Local APIC disabled by BIOS -- you can enable it with "lapic"
[    0.000000] APIC: disable apic facility
[    0.000000] APIC: switched to apic NOOP
[    0.000000] PM: Registered nosave memory: 00000000000a0000 - 0000000000100000
[    0.000000] Allocating PCI resources starting at 20800000 (gap: 20800000:df800000)
[    0.000000] Booting paravirtualized kernel on Xen
[    0.000000] Xen version: 3.1.2-238.12.1.el5 (preserve-AD)
[    0.000000] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:1 nr_node_ids:1
[    0.000000] PERCPU: Embedded 13 pages/cpu @dfbde000 s31040 r0 d22208 u53248
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 131968
[    0.000000] Kernel command line:  ro root=/dev/mapper/fedora-root rd_LVM_LV=fedora/root rd_LVM_LV=fedora/swap rd_NO_LUKS rd_NO_MD rd_NO_DM LANG=en_US.UTF-8 SYSFONT=latarcyrheb-sun16 KEYTABLE=us console=hvc0
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Initializing CPU#0
[    0.000000] allocated 2662080 bytes of page_cgroup
[    0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups
[    0.000000] Initializing HighMem for node 0 (00000000:00000000)
[    0.000000] Memory: 476556k/532480k available (4029k kernel code, 55476k reserved, 2569k data, 592k init, 0k highmem)
[    0.000000] virtual kernel memory layout:
[    0.000000]     fixmap  : 0xf4d75000 - 0xf57ff000   (10792 kB)
[    0.000000]     pkmap   : 0xf4a00000 - 0xf4c00000   (2048 kB)
[    0.000000]     vmalloc : 0xe1000000 - 0xf49fe000   ( 313 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xe0800000   ( 520 MB)
[    0.000000]       .init : 0xc0a72000 - 0xc0b06000   ( 592 kB)
[    0.000000]       .data : 0xc07ef54a - 0xc0a71c40   (2569 kB)
[    0.000000]       .text : 0xc0400000 - 0xc07ef54a   (4029 kB)
[    0.000000] SLUB: Genslabs=15, HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] 	RCU dyntick-idle grace-period acceleration is enabled.
[    0.000000] 	RCU-based detection of stalled CPUs is disabled.
[    0.000000] NR_IRQS:2304
[    0.000000] Console: colour dummy device 80x25
[    0.000000] console [tty0] enabled
[    0.000000] console [hvc0] enabled
[    0.000000] installing Xen timer for CPU 0
[    0.000000] Detected 2400.088 MHz processor.
[    0.000999] Calibrating delay loop (skipped), value calculated using timer frequency.. 4800.17 BogoMIPS (lpj=2400088)
[    0.000999] pid_max: default: 32768 minimum: 301
[    0.000999] Security Framework initialized
[    0.000999] SELinux:  Initializing.
[    0.000999] Mount-cache hash table entries: 512
[    0.000999] Initializing cgroup subsys ns
[    0.000999] ns_cgroup deprecated: consider using the 'clone_children' flag without the ns_cgroup.
[    0.000999] Initializing cgroup subsys cpuacct
[    0.000999] Initializing cgroup subsys memory
[    0.000999] Initializing cgroup subsys devices
[    0.000999] Initializing cgroup subsys freezer
[    0.000999] Initializing cgroup subsys net_cls
[    0.000999] Initializing cgroup subsys blkio
[    0.001066] CPU: Unsupported number of siblings 4
[    0.001228] SMP alternatives: switching to UP code
[    0.026945] Freeing SMP alternatives: 12k freed
[    0.026958] ftrace: allocating 23363 entries in 46 pages
[    0.028059] Performance Events: unsupported p6 CPU model 15 no PMU driver, software events only.
[    0.028432] NMI watchdog disabled (cpu0): hardware events not enabled
[    0.028441] Brought up 1 CPUs
[    0.028696] devtmpfs: initialized
[    0.029819] atomic64 test passed for i586+ platform with CX8 and with SSE
[    0.029850] Grant table initialized
[    0.049764] Time: 165:165:165  Date: 165/165/65
[    0.049889] NET: Registered protocol family 16
[    0.050636] PCI: setting up Xen PCI frontend stub
[    0.052236] bio: create slab <bio-0> at 0
[    0.052363] ACPI: Interpreter disabled.
[    0.053017] xen_balloon: Initialising balloon driver.
[    0.053045] last_pfn = 0x20800 max_arch_pfn = 0x1000000
[    0.053086] vgaarb: loaded
[    0.053155] SCSI subsystem initialized
[    0.053281] usbcore: registered new interface driver usbfs
[    0.054013] usbcore: registered new interface driver hub
[    0.054057] usbcore: registered new device driver usb
[    0.054168] PCI: System does not support PCI
[    0.054174] PCI: System does not support PCI
[    0.054297] NetLabel: Initializing
[    0.054304] NetLabel:  domain hash size = 128
[    0.054309] NetLabel:  protocols = UNLABELED CIPSOv4
[    0.054324] NetLabel:  unlabeled traffic allowed by default
[    0.054372] Switching to clocksource xen
[    0.054995] Switched to NOHz mode on CPU #0
[    0.061952] pnp: PnP ACPI: disabled
[    0.064173] NET: Registered protocol family 2
[    0.064281] IP route cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.064476] TCP established hash table entries: 32768 (order: 6, 262144 bytes)
[    0.064582] TCP bind hash table entries: 32768 (order: 6, 262144 bytes)
[    0.064683] TCP: Hash tables configured (established 32768 bind 32768)
[    0.064691] TCP reno registered
[    0.064697] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.064710] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.065026] NET: Registered protocol family 1
[    0.065078] Trying to unpack rootfs image as initramfs...
[    0.112375] Freeing initrd memory: 29816k freed
[    0.123174] platform rtc_cmos: registered platform RTC device (no PNP device found)
[    0.123375] apm: BIOS not found.
[    0.123579] audit: initializing netlink socket (disabled)
[    0.123602] type=2000 audit(1309731941.461:1): initialized
[    0.131882] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.133541] VFS: Disk quotas dquot_6.5.2
[    0.133740] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.134504] msgmni has been set to 989
[    0.134815] NET: Registered protocol family 38
[    0.134863] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[    0.134899] io scheduler noop registered
[    0.134905] io scheduler deadline registered
[    0.134922] io scheduler cfq registered (default)
[    0.134983] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    0.135022] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    0.135030] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.135155] isapnp: Scanning for PnP cards...
[    0.490602] isapnp: No Plug & Play device found
[    0.491367] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.492171] Non-volatile memory driver v1.3
[    0.492442] Linux agpgart interface v0.103
[    0.494098] brd: module loaded
[    0.494999] loop: module loaded
[    0.495450] Fixed MDIO Bus: probed
[    0.495791] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.496020] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    0.496036] uhci_hcd: USB Universal Host Controller Interface driver
[    0.496098] i8042: PNP: No PS/2 controller found. Probing ports directly.
[    0.496976] mousedev: PS/2 mouse device common for all mice
[    0.497122] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
[    0.497164] rtc_cmos: probe of rtc_cmos failed with error -38
[    0.497242] device-mapper: uevent: version 1.0.3
[    0.497342] device-mapper: ioctl: 4.19.1-ioctl (2011-01-07) initialised: dm-devel
[    0.497384] cpuidle: using governor ladder
[    0.497390] cpuidle: using governor menu
[    0.497551] usbcore: registered new interface driver usbhid
[    0.497557] usbhid: USB HID core driver
[    0.497576] nf_conntrack version 0.5.0 (7912 buckets, 31648 max)
[    0.497723] ip_tables: (C) 2000-2006 Netfilter Core Team
[    0.497741] TCP cubic registered
[    0.497746] Initializing XFRM netlink socket
[    0.497758] NET: Registered protocol family 17
[    0.497781] Registering the dns_resolver key type
[    0.497805] Using IPI No-Shortcut mode
[    0.497913] registered taskstats version 1
[    0.497923] IMA: No TPM chip found, activating TPM-bypass!
[    0.497958] XENBUS: Device with no driver: device/vbd/51712
[    0.497965] XENBUS: Device with no driver: device/vif/0
[    0.497982]   Magic number: 1:252:3141
[    0.498012] drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
[    0.498028] Initalizing network drop monitor service
[    0.498319] Freeing unused kernel memory: 592k freed
[    0.499611] Write protecting the kernel text: 4032k
[    0.500171] Write protecting the kernel read-only data: 1936k
[    0.500181] NX-protecting the kernel data: 4160k
[    0.550423] dracut: dracut-009-11.fc15
[    0.564808] dracut: rd.luks=0: removing cryptoluks activation
[    0.581847] udev[95]: starting version 167
[    0.660598] dracut: Starting plymouth daemon
[    0.670121] dracut: rd.dm=0: removing DM RAID activation
[    0.702477] dracut: rd.md=0: removing MD RAID activation
[    0.844906] blkfront: xvda: barriers disabled
[    0.852515]  xvda: xvda1 xvda2
[    1.211371] dracut: Scanning devices xvda2  for LVM logical volumes fedora/root fedora/swap
[    1.246164] dracut: inactive '/dev/fedora/root' [4.00 GiB] inherit
[    1.246267] dracut: inactive '/dev/fedora/swap' [1.00 GiB] inherit
[    1.246356] dracut: inactive '/dev/fedora/var' [1.00 GiB] inherit
[    1.246445] dracut: inactive '/dev/fedora/home' [1.00 GiB] inherit
[    1.246535] dracut: inactive '/dev/fedora/tmp' [256.00 MiB] inherit
[    1.612194] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null)
[    1.675553] dracut: Checking filesystems
[    1.675599] dracut: fsck -T -t noopts=_netdev -A -a
[    1.707839] dracut: /dev/mapper/fedora-root: clean, 45720/262144 files, 322690/1048576 blocks
[    1.708112] dracut: Remounting /dev/mapper/fedora-root with -o ro,noatime
[    1.762619] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null)
[    1.787779] dracut: Mounted root filesystem /dev/mapper/fedora-root
[    1.853925] dracut: Switching root
[    2.407222] type=1404 audit(1309731943.745:2): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295
[    2.864960] type=1403 audit(1309731944.202:3): policy loaded auid=4294967295 ses=4294967295
[    3.203357] systemd[1]: systemd 26 running in system mode. (+PAM +LIBWRAP +AUDIT +SELINUX +SYSVINIT +LIBCRYPTSETUP; fedora)

Welcome to Fedora release 15 (Lovelock)!

[    3.394746] NET: Registered protocol family 10
[    3.423611] systemd[1]: Set hostname to <fedora>.
[    3.532518] systemd-getty-generator[306]: Failed to create symlink from /lib/systemd/system/serial-getty@.service to /run/systemd/generator/getty.target.wants/serial-getty: File exists
[    3.532766] systemd[1]: /lib/systemd/system-generators/systemd-getty-generator exited with exit status 1.
Started Load legacy module configuration.
Starting Bootup hack...
Started Load Kernel Modules.
Starting Syslog Kernel Log Buffer Bridge...
Started Syslog Kernel Log Buffer Bridge.
Starting Apply Kernel Variables...
Started Set Up Additional Binary Formats.
Starting udev Kernel Device Manager...
Started File System Check on Root Device.
Starting Remount API VFS...
Starting Media Directory...
Starting Remount Root FS...
Starting Setup Virtual Console...
Started Apply Kernel Variables.
Starting Stdio Syslog Bridge...
Started Stdio Syslog Bridge.
Started Bootup hack.
Started Media Directory.
Started Remount API VFS.
[    4.824124] EXT4-fs (dm-0): re-mounted. Opts: (null)
Started Remount Root FS.
Starting Configure read-only root support...
Started Setup Virtual Console.
Started udev Kernel Device Manager.
Starting udev Coldplug all Devices...
[    5.228145] udev[312]: starting version 167
Started udev Coldplug all Devices.
Starting udev Wait for Complete Device Initialization...
Started udev Kernel Device Manager.
[    5.648247] Initialising Xen virtual ethernet driver.
GStarting /dev/mapper/fedora-swap...
[    5.967820] Adding 1048572k swap on /dev/mapper/fedora-swap.  Priority:0 extents:1 across:1048572k 
Started /dev/mapper/fedora-swap.
Starting File System Check on /dev/disk/by-uuid/ec284f6a-c171-40e9-b77f-f82c70484586...
Started udev Wait for Complete Device Initialization.
Starting Wait for storage scan...
Started Show Plymouth Boot Screen.
Started Wait for storage scan.
Starting Initialize storage subsystems (RAID, LVM, etc.)...
[    8.958944] systemd-fsck[431]: /dev/xvda1: clean, 41/65536 files, 49141/262144 blocks (check after next mount)
systemd-fsck[431]: /dev/xvda1: clean, 41/65536 files, 49141/262144 blocks (check after next mount)
Started File System Check on /dev/disk/by-uuid/ec284f6a-c171-40e9-b77f-f82c70484586.
Starting /boot...
Starting Huge Pages File System...
Started Huge Pages File System.
Starting POSIX Message Queue File System...
Started POSIX Message Queue File System.
Started /boot.
[    9.700656] ------------[ cut here ]------------
[    9.700675] WARNING: at block/blk-core.c:352 blk_start_queue+0x24/0x3c()
[    9.700683] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[    9.700702] Pid: 312, comm: udevd Not tainted 2.6.38.8-32.fc15.i686.PAE #1
[    9.700710] Call Trace:
[    9.700717]  [<c07e17f3>] ? printk+0x2d/0x2f
[    9.700726]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[    9.700733]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[    9.700740]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[    9.700747]  [<c0442104>] warn_slowpath_null+0x22/0x24
[    9.700754]  [<c05c2c6b>] blk_start_queue+0x24/0x3c
[    9.700763]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[    9.700773]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[    9.700783]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[    9.700790]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[    9.700797]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[    9.700806]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[    9.700814]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[    9.700822]  [<c0409c97>] xen_do_upcall+0x7/0xc
[    9.700829]  [<c07e0000>] ? __cpuid+0x11/0x12
[    9.700835] ---[ end trace d6a8f57af5989e54 ]---
[    9.700840] ------------[ cut here ]------------
[    9.700847] WARNING: at block/blk-core.c:260 blk_remove_plug+0x24/0x73()
[    9.700854] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[    9.700869] Pid: 312, comm: udevd Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[    9.700878] Call Trace:
[    9.700882]  [<c07e17f3>] ? printk+0x2d/0x2f
[    9.700889]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[    9.700896]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[    9.700903]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[    9.700910]  [<c0442104>] warn_slowpath_null+0x22/0x24
[    9.700916]  [<c05c0c49>] blk_remove_plug+0x24/0x73
[    9.700923]  [<c05c2b34>] __blk_run_queue+0x13/0x6e
[    9.700930]  [<c05c2c80>] blk_start_queue+0x39/0x3c
[    9.700937]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[    9.700947]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[    9.700955]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[    9.700962]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[    9.700970]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[    9.700977]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[    9.700984]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[    9.700991]  [<c0409c97>] xen_do_upcall+0x7/0xc
[    9.700998]  [<c07e0000>] ? __cpuid+0x11/0x12
[    9.701005] ---[ end trace d6a8f57af5989e55 ]---
[    9.730159] ------------[ cut here ]------------
[    9.730180] WARNING: at block/blk-core.c:352 blk_start_queue+0x24/0x3c()
[    9.730191] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[    9.730216] Pid: 0, comm: swapper Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[    9.730229] Call Trace:
[    9.730239]  [<c07e17f3>] ? printk+0x2d/0x2f
[    9.730251]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[    9.730261]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[    9.730274]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[    9.730281]  [<c0442104>] warn_slowpath_null+0x22/0x24
[    9.730288]  [<c05c2c6b>] blk_start_queue+0x24/0x3c
[    9.730297]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[    9.730307]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[    9.730317]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[    9.730324]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[    9.730331]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[    9.730341]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[    9.730349]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[    9.730357]  [<c0409c97>] xen_do_upcall+0x7/0xc
[    9.730364]  [<c04023a7>] ? hypercall_page+0x3a7/0x1000
[    9.730372]  [<c0406241>] ? xen_safe_halt+0x12/0x1d
[    9.730379]  [<c040f828>] default_idle+0x5a/0x92
[    9.730385]  [<c0408460>] cpu_idle+0x8e/0xa8
[    9.730393]  [<c07cc0e5>] rest_init+0x5d/0x5f
[    9.730401]  [<c0a72827>] start_kernel+0x357/0x35d
[    9.730408]  [<c0a7221d>] ? unknown_bootoption+0x0/0x19e
[    9.731140]  [<c0a720e7>] i386_start_kernel+0xd6/0xdc
[    9.731140]  [<c0a757c4>] xen_start_kernel+0x5a3/0x5ab
[    9.731140]  [<c04090b0>] ? restore_sigcontext+0x17/0xd6
[    9.731140] ---[ end trace d6a8f57af5989e56 ]---
[    9.731140] ------------[ cut here ]------------
[    9.731140] WARNING: at block/blk-core.c:260 blk_remove_plug+0x24/0x73()
[    9.731140] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[    9.731140] Pid: 0, comm: swapper Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[    9.731140] Call Trace:
[    9.731140]  [<c07e17f3>] ? printk+0x2d/0x2f
[    9.731140]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[    9.731140]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[    9.731140]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[    9.731140]  [<c0442104>] warn_slowpath_null+0x22/0x24
[    9.731140]  [<c05c0c49>] blk_remove_plug+0x24/0x73
[    9.731140]  [<c05c2b34>] __blk_run_queue+0x13/0x6e
[    9.731140]  [<c05c2c80>] blk_start_queue+0x39/0x3c
[    9.731140]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[    9.731140]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[    9.731140]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[    9.731140]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[    9.731140]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[    9.731140]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[    9.731140]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[    9.731140]  [<c0409c97>] xen_do_upcall+0x7/0xc
[    9.731140]  [<c04023a7>] ? hypercall_page+0x3a7/0x1000
[    9.731140]  [<c0406241>] ? xen_safe_halt+0x12/0x1d
[    9.731140]  [<c040f828>] default_idle+0x5a/0x92
[    9.731140]  [<c0408460>] cpu_idle+0x8e/0xa8
[    9.731140]  [<c07cc0e5>] rest_init+0x5d/0x5f
[    9.731140]  [<c0a72827>] start_kernel+0x357/0x35d
[    9.731140]  [<c0a7221d>] ? unknown_bootoption+0x0/0x19e
[    9.731140]  [<c0a720e7>] i386_start_kernel+0xd6/0xdc
[    9.731140]  [<c0a757c4>] xen_start_kernel+0x5a3/0x5ab
[    9.731140]  [<c04090b0>] ? restore_sigcontext+0x17/0xd6
[    9.731140] ---[ end trace d6a8f57af5989e57 ]---
Starting File System Check on /dev/mapper/fedora-var...
[    9.961584] ------------[ cut here ]------------
[    9.961599] WARNING: at block/blk-core.c:352 blk_start_queue+0x24/0x3c()
[    9.961606] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[    9.961624] Pid: 1, comm: systemd Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[    9.961632] Call Trace:
[    9.961639]  [<c07e17f3>] ? printk+0x2d/0x2f
[    9.961648]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[    9.961655]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[    9.961662]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[    9.961668]  [<c0442104>] warn_slowpath_null+0x22/0x24
[    9.961675]  [<c05c2c6b>] blk_start_queue+0x24/0x3c
[    9.961684]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[    9.961694]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[    9.961703]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[    9.961710]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[    9.961717]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[    9.961725]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[    9.961733]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[    9.961741]  [<c0409c97>] xen_do_upcall+0x7/0xc
[    9.961748]  [<c0402227>] ? hypercall_page+0x227/0x1000
[    9.961756]  [<c040628b>] ? xen_force_evtchn_callback+0xf/0x14
[    9.961763]  [<c04062ca>] xen_restore_fl+0x21/0x23
[    9.961770]  [<c04061f2>] __raw_callee_save_xen_restore_fl+0x6/0x8
[    9.961778]  [<c04defe4>] ? arch_local_irq_restore+0x9/0xb
[    9.961786]  [<c04e10a6>] kmem_cache_alloc+0x78/0xdb
[    9.961792]  [<c04405ac>] ? dup_mm+0x1ef/0x3ec
[    9.962006]  [<c04405ac>] dup_mm+0x1ef/0x3ec
[    9.962006]  [<c0440f58>] copy_process+0x78c/0xdd2
[    9.962006]  [<c04061f2>] ? __raw_callee_save_xen_restore_fl+0x6/0x8
[    9.962006]  [<c04416b0>] do_fork+0xe0/0x25f
[    9.962006]  [<c040ffb5>] sys_clone+0x30/0x37
[    9.962006]  [<c04097d9>] ptregs_clone+0x15/0x3c
[    9.962006]  [<c07e9604>] ? syscall_call+0x7/0xb
[    9.962006]  [<c07e0000>] ? __cpuid+0x11/0x12
[    9.962006] ---[ end trace d6a8f57af5989e58 ]---
[    9.962006] ------------[ cut here ]------------
[    9.962006] WARNING: at block/blk-core.c:260 blk_remove_plug+0x24/0x73()
[    9.962006] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[    9.962006] Pid: 1, comm: systemd Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[    9.962006] Call Trace:
[    9.962006]  [<c07e17f3>] ? printk+0x2d/0x2f
[    9.962006]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[    9.962006]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[    9.962006]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[    9.962006]  [<c0442104>] warn_slowpath_null+0x22/0x24
[    9.962006]  [<c05c0c49>] blk_remove_plug+0x24/0x73
[    9.962006]  [<c05c2b34>] __blk_run_queue+0x13/0x6e
[    9.962006]  [<c05c2c80>] blk_start_queue+0x39/0x3c
[    9.962006]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[    9.962006]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[    9.962006]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[    9.962006]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[    9.962006]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[    9.962006]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[    9.962006]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[    9.962006]  [<c0409c97>] xen_do_upcall+0x7/0xc
[    9.962006]  [<c0402227>] ? hypercall_page+0x227/0x1000
[    9.962006]  [<c040628b>] ? xen_force_evtchn_callback+0xf/0x14
[    9.962006]  [<c04062ca>] xen_restore_fl+0x21/0x23
[    9.962006]  [<c04061f2>] __raw_callee_save_xen_restore_fl+0x6/0x8
[    9.962006]  [<c04defe4>] ? arch_local_irq_restore+0x9/0xb
[    9.962006]  [<c04e10a6>] kmem_cache_alloc+0x78/0xdb
[    9.962006]  [<c04405ac>] ? dup_mm+0x1ef/0x3ec
[    9.962006]  [<c04405ac>] dup_mm+0x1ef/0x3ec
[    9.962006]  [<c0440f58>] copy_process+0x78c/0xdd2
[    9.962006]  [<c04061f2>] ? __raw_callee_save_xen_restore_fl+0x6/0x8
[    9.962006]  [<c04416b0>] do_fork+0xe0/0x25f
[    9.962006]  [<c040ffb5>] sys_clone+0x30/0x37
[    9.962006]  [<c04097d9>] ptregs_clone+0x15/0x3c
[    9.962006]  [<c07e9604>] ? syscall_call+0x7/0xb
[    9.962006]  [<c07e0000>] ? __cpuid+0x11/0x12
[    9.962006] ---[ end trace d6a8f57af5989e59 ]---
Starting File System Check on /dev/mapper/fedora-home...
Starting File System Check on /dev/mapper/fedora-tmp...
Started Initialize storage subsystems (RAID, LVM, etc.).
Starting Initialize storage subsystems (RAID, LVM, etc.)...
[   10.323336] systemd-fsck[478]: /dev/mapper/fedora-tmp: clean, 16/65536 files, 10344/262144 blocks (check after next mount)
systemd-fsck[478]: /dev/mapper/fedora-tmp: clean, 16/65536 files, 10344/262144 blocks (check after next mount)
Started File System Check on /dev/mapper/fedora-tmp.
Starting /tmp...
[   10.344997] systemd-fsck[475]: /dev/mapper/fedora-home: clean, 1362/65536 files, 15599/262144 blocks
[   10.345061] ------------[ cut here ]------------
[   10.345075] WARNING: at block/blk-core.c:352 blk_start_queue+0x24/0x3c()
[   10.345083] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[   10.345101] Pid: 323, comm: systemd-logger Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[   10.345110] Call Trace:
[   10.345117]  [<c07e17f3>] ? printk+0x2d/0x2f
[   10.345126]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[   10.345133]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[   10.345140]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[   10.345147]  [<c0442104>] warn_slowpath_null+0x22/0x24
[   10.345154]  [<c05c2c6b>] blk_start_queue+0x24/0x3c
[   10.345164]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[   10.345174]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[   10.345183]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[   10.345191]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[   10.345198]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[   10.345207]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[   10.345215]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[   10.345223]  [<c0409c97>] xen_do_upcall+0x7/0xc
[   10.345230]  [<c042007b>] ? apm+0x44d/0x50e
[   10.345238]  [<c04300e0>] ? cpuacct_stats_show+0x42/0x58
[   10.345245]  [<c0402227>] ? hypercall_page+0x227/0x1000
[   10.345253]  [<c040628b>] ? xen_force_evtchn_callback+0xf/0x14
[   10.345261]  [<c04062a7>] xen_irq_enable+0x17/0x19
[   10.345268]  [<c0406202>] __raw_callee_save_xen_irq_enable+0x6/0x8
[   10.345278]  [<c0652252>] ? spin_unlock_irq+0x10/0x12
[   10.345285]  [<c0654878>] tty_open+0x36e/0x3be
[   10.345293]  [<c04f0b3b>] chrdev_open+0xe9/0x10d
[   10.345300]  [<c04ec46c>] __dentry_open+0x139/0x21b
[   10.345307]  [<c04ed31b>] nameidata_to_filp+0x52/0x5e
[   10.345314]  [<c04f0a52>] ? chrdev_open+0x0/0x10d
[   10.345322]  [<c04f790d>] finish_open+0x7f/0x13c
[   10.345329]  [<c04f6c92>] ? do_path_lookup+0xb1/0xd3
[   10.345335]  [<c04f7da1>] do_filp_open+0x173/0x4cb
[   10.345348]  [<c05daf92>] ? copy_to_user+0x44/0x4b
[   10.345355]  [<c04061ea>] ? __raw_callee_save_xen_save_fl+0x6/0x8
[   10.345363]  [<c042ea75>] ? arch_local_save_flags+0x9/0xb
[   10.345371]  [<c04defe4>] ? arch_local_irq_restore+0x9/0xb
[   10.345378]  [<c07e7f79>] ? _cond_resched+0xd/0x21
[   10.345386]  [<c04ed37d>] do_sys_open+0x56/0xdc
[   10.345392]  [<c04ed429>] sys_open+0x26/0x2c
[   10.345404]  [<c07e9604>] syscall_call+0x7/0xb
[   10.345410] ---[ end trace d6a8f57af5989e5a ]---
[   10.345415] ------------[ cut here ]------------
[   10.345422] WARNING: at block/blk-core.c:260 blk_remove_plug+0x24/0x73()
[   10.345429] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[   10.345444] Pid: 323, comm: systemd-logger Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[   10.346009] Call Trace:
[   10.346009]  [<c07e17f3>] ? printk+0x2d/0x2f
[   10.346009]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[   10.346009]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[   10.346009]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[   10.346009]  [<c0442104>] warn_slowpath_null+0x22/0x24
[   10.346009]  [<c05c0c49>] blk_remove_plug+0x24/0x73
[   10.346009]  [<c05c2b34>] __blk_run_queue+0x13/0x6e
[   10.346009]  [<c05c2c80>] blk_start_queue+0x39/0x3c
[   10.346009]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[   10.346009]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[   10.346009]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[   10.346009]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[   10.346009]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[   10.346009]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[   10.346009]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[   10.346009]  [<c0409c97>] xen_do_upcall+0x7/0xc
[   10.346009]  [<c042007b>] ? apm+0x44d/0x50e
[   10.346009]  [<c04300e0>] ? cpuacct_stats_show+0x42/0x58
[   10.346009]  [<c0402227>] ? hypercall_page+0x227/0x1000
[   10.346009]  [<c040628b>] ? xen_force_evtchn_callback+0xf/0x14
[   10.346009]  [<c04062a7>] xen_irq_enable+0x17/0x19
[   10.346009]  [<c0406202>] __raw_callee_save_xen_irq_enable+0x6/0x8
[   10.346009]  [<c0652252>] ? spin_unlock_irq+0x10/0x12
[   10.346009]  [<c0654878>] tty_open+0x36e/0x3be
[   10.346009]  [<c04f0b3b>] chrdev_open+0xe9/0x10d
[   10.346009]  [<c04ec46c>] __dentry_open+0x139/0x21b
[   10.346009]  [<c04ed31b>] nameidata_to_filp+0x52/0x5e
[   10.346009]  [<c04f0a52>] ? chrdev_open+0x0/0x10d
[   10.346009]  [<c04f790d>] finish_open+0x7f/0x13c
[   10.346009]  [<c04f6c92>] ? do_path_lookup+0xb1/0xd3
[   10.346009]  [<c04f7da1>] do_filp_open+0x173/0x4cb
[   10.346009]  [<c05daf92>] ? copy_to_user+0x44/0x4b
[   10.346009]  [<c04061ea>] ? __raw_callee_save_xen_save_fl+0x6/0x8
[   10.346009]  [<c042ea75>] ? arch_local_save_flags+0x9/0xb
[   10.346009]  [<c04defe4>] ? arch_local_irq_restore+0x9/0xb
[   10.346009]  [<c07e7f79>] ? _cond_resched+0xd/0x21
[   10.346009]  [<c04ed37d>] do_sys_open+0x56/0xdc
[   10.346009]  [<c04ed429>] sys_open+0x26/0x2c
[   10.346009]  [<c07e9604>] syscall_call+0x7/0xb
[   10.346009] ---[ end trace d6a8f57af5989e5b ]---
[   10.502468] systemd-fsck[472]: /dev/mapper/fedora-var: clean, 3102/65536 files, 97273/262144 blocks
systemd-fsck[475]: /dev/mapper/fedora-home: clean, 1362/65536 files, 15599/262144 blocks
systemd-fsck[472]: /dev/mapper/fedora-var: clean, 3102/65536 files, 97273/262144 blocks
[   10.518322] ------------[ cut here ]------------
[   10.518336] WARNING: at block/blk-core.c:352 blk_start_queue+0x24/0x3c()
[   10.518347] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[   10.518375] Pid: 0, comm: swapper Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[   10.518388] Call Trace:
[   10.518397]  [<c07e17f3>] ? printk+0x2d/0x2f
[   10.518407]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[   10.518422]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[   10.518429]  [<c05c2c6b>] ? blk_start_queue+0x24/0x3c
[   10.518436]  [<c0442104>] warn_slowpath_null+0x22/0x24
[   10.518443]  [<c05c2c6b>] blk_start_queue+0x24/0x3c
[   10.518451]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[   10.518461]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[   10.519301]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[   10.519301]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[   10.519301]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[   10.519301]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[   10.519301]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[   10.519301]  [<c0409c97>] xen_do_upcall+0x7/0xc
[   10.519301]  [<c04023a7>] ? hypercall_page+0x3a7/0x1000
[   10.519301]  [<c0406241>] ? xen_safe_halt+0x12/0x1d
[   10.519301]  [<c040f828>] default_idle+0x5a/0x92
[   10.519301]  [<c0408460>] cpu_idle+0x8e/0xa8
[   10.519301]  [<c07cc0e5>] rest_init+0x5d/0x5f
[   10.519301]  [<c0a72827>] start_kernel+0x357/0x35d
[   10.519301]  [<c0a7221d>] ? unknown_bootoption+0x0/0x19e
[   10.519301]  [<c0a720e7>] i386_start_kernel+0xd6/0xdc
[   10.519301]  [<c0a757c4>] xen_start_kernel+0x5a3/0x5ab
[   10.519301]  [<c04090b0>] ? restore_sigcontext+0x17/0xd6
[   10.519301] ---[ end trace d6a8f57af5989e5c ]---
[   10.519301] ------------[ cut here ]------------
[   10.519301] WARNING: at block/blk-core.c:260 blk_remove_plug+0x24/0x73()
[   10.519301] Modules linked in: ext2 xen_netfront ipv6 xen_blkfront [last unloaded: scsi_wait_scan]
[   10.519301] Pid: 0, comm: swapper Tainted: G        W   2.6.38.8-32.fc15.i686.PAE #1
[   10.519301] Call Trace:
[   10.519301]  [<c07e17f3>] ? printk+0x2d/0x2f
[   10.519301]  [<c04420cd>] warn_slowpath_common+0x7c/0x91
[   10.519301]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[   10.519301]  [<c05c0c49>] ? blk_remove_plug+0x24/0x73
[   10.519301]  [<c0442104>] warn_slowpath_null+0x22/0x24
[   10.519301]  [<c05c0c49>] blk_remove_plug+0x24/0x73
[   10.519301]  [<c05c2b34>] __blk_run_queue+0x13/0x6e
[   10.519301]  [<c05c2c80>] blk_start_queue+0x39/0x3c
[   10.519301]  [<e1000633>] kick_pending_request_queues+0x21/0x2f [xen_blkfront]
[   10.519301]  [<e1000849>] blkif_interrupt+0x208/0x223 [xen_blkfront]
[   10.519301]  [<c048ebe2>] handle_IRQ_event+0x4c/0xfe
[   10.519301]  [<c045dbfb>] ? sched_clock_cpu+0x134/0x144
[   10.519301]  [<c0490697>] handle_fasteoi_irq+0x74/0xa6
[   10.519301]  [<c064bb50>] __xen_evtchn_do_upcall+0xb5/0x118
[   10.519301]  [<c064cf54>] xen_evtchn_do_upcall+0x20/0x2f
[   10.519301]  [<c0409c97>] xen_do_upcall+0x7/0xc
[   10.519301]  [<c04023a7>] ? hypercall_page+0x3a7/0x1000
[   10.519301]  [<c0406241>] ? xen_safe_halt+0x12/0x1d
[   10.519301]  [<c040f828>] default_idle+0x5a/0x92
[   10.519301]  [<c0408460>] cpu_idle+0x8e/0xa8
[   10.519301]  [<c07cc0e5>] rest_init+0x5d/0x5f
[   10.519301]  [<c0a72827>] start_kernel+0x357/0x35d
[   10.519301]  [<c0a7221d>] ? unknown_bootoption+0x0/0x19e
[   10.519301]  [<c0a720e7>] i386_start_kernel+0xd6/0xdc
[   10.519301]  [<c0a757c4>] xen_start_kernel+0x5a3/0x5ab
[   10.519301]  [<c04090b0>] ? restore_sigcontext+0x17/0xd6
[   10.519301] ---[ end trace d6a8f57af5989e5d ]---
Started File System Check on /dev/mapper/fedora-var.
Starting /var...
Started File System Check on /dev/mapper/fedora-home.
Starting /home...
Started /tmp.
[   10.773996] EXT4-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null)
[   10.774882] EXT4-fs (dm-3): mounted filesystem with ordered data mode. Opts: (null)
Started /var.
Starting Runtime Directory...
Starting Lock Directory...
Started /home.
Started Runtime Directory.
Started Lock Directory.
Started Initialize storage subsystems (RAID, LVM, etc.).
Starting Tell Plymouth To Write Out Runtime Data...
Starting Load Random Seed...
Started Mark the need to relabel after reboot.
Started Relabel all filesystems, if necessary.
Starting Enable all detected swap partitions...
Started Reconfigure the system on administrator request.
Starting Recreate Volatile Files and Directories...
Started Enable all detected swap partitions.
Started Load Random Seed.
Started Tell Plymouth To Write Out Runtime Data.
Started Recreate Volatile Files and Directories.
Starting Console System Startup Logging...
Starting Bootup unhack...
Starting LSB: start and stop ip6tables firewall...
Starting LSB: start and stop iptables firewall...
Starting System Logging Service...
Starting Job spooling tools...
Started Job spooling tools.
Starting LSB: Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling...
Starting Command Scheduler...
Started Command Scheduler.
Starting D-Bus System Message Bus...
Started Console System Startup Logging.
Started Bootup unhack.
Stopping Syslog Kernel Log Buffer Bridge...
Stopped Syslog Kernel Log Buffer Bridge.
Started System Logging Service.
Started D-Bus System Message Bus.
Started LSB: start and stop ip6tables firewall.
Started LSB: start and stop iptables firewall.
Starting LSB: Bring up/down networking...
Starting monitoring for VG fedora: Bringing up loopback interface:    5 logical volume(s) in volume group "fedora" monitored
[  OK  ]
Started LSB: Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling.
[  OK  ]
Bringing up interface eth0:  [  OK  ]
Started LSB: Bring up/down networking.
Starting SYSV: This starts the Linux Auditing System Daemon, which collects security related events in a dedicated audit log. If this daemon is turned off, audit events will be sent to syslog....
Starting auditd: [  OK  ]
Started SYSV: This starts the Linux Auditing System Daemon, which collects security related events in a dedicated audit log. If this daemon is turned off, audit events will be sent to syslog..
Starting LSB: The CUPS scheduler...
Starting LSB: Mount and unmount network filesystems....
Starting cups: Mounting other filesystems:  mount: sysfs already mounted or /sys busy
mount: according to mtab, /sys is already mounted on /sys
[FAILED]
Started LSB: Mount and unmount network filesystems..
Starting Permit User Sessions...
Started Permit User Sessions.
[  OK  ]
Started LSB: The CUPS scheduler.
Starting SYSV: Enable daily run of yum, a program updater....
Enabling nightly yum update: [  OK  ]
Started SYSV: Enable daily run of yum, a program updater..
Starting LSB: start and stop sendmail...
Starting LSB: Start up the OpenSSH server daemon...
Starting LSB: start and stop Apache HTTP Server...
Starting LSB: start and stop MySQL server...
Starting LSB: Client to update dynamic DNS host entries...
Starting /etc/rc.local Compatibility...
Started /etc/rc.local Compatibility.
Starting Terminate Plymouth Boot Screen...
Starting Wait for Plymouth Boot Screen to Quit...
[   37.796847] sshd (916): /proc/916/oom_adj is deprecated, please use /proc/916/oom_score_adj instead.

[  OK  ]
Starting sm-client: 
Fedora release 15 (Lovelock)
Kernel 2.6.38.8-32.fc15.i686.PAE on an i686 (hvc0)

fedora login:

Comment 9 Igor Mammedov 2011-07-04 09:09:09 UTC
Vadim,

Thanks for your reply.
Since I can't reproduce it locally, would you help to hunt warning down by running test kernels that I could prepare for you?
Or may be you could provide access to affected guest?

Comment 10 Vadym Chepkov 2011-07-05 21:02:33 UTC
I would be happy to run a test kernel.
I can't easily grant you access to this internal system, but I will try to reproduce the same issue at home and will send you login details directly

Comment 11 Vadym Chepkov 2011-07-06 15:27:49 UTC
Igor,

do you have "quiet rhgb" in the grub.conf for the kernel, by any chance ?

After I removed them on freshly installed Fedora 15, I can see these messages right away.

Comment 12 Igor Mammedov 2011-07-07 08:01:35 UTC
Vadym,

Yes, I've removed options "quiet rhgb" from kernel cmd line.
Could you post here guest's config file and grub.conf from the host? I'll try reproduce bug with your settings.

Running test kernels would be ok. I'll prepare one for you.

Comment 13 Vadym Chepkov 2011-07-07 11:23:40 UTC
Guest config (created by virt-install)

name = "f15"
uuid = "40957976-26eb-6137-c5a3-c8f663e416aa"
maxmem = 512
memory = 512
vcpus = 1
bootloader = "/usr/bin/pygrub"
on_poweroff = "destroy"
on_reboot = "restart"
on_crash = "restart"
disk = [ "phy:/dev/vg0/f15,xvda,w" ]
vif = [ "mac=00:16:36:25:39:7d,bridge=br0,script=vif-bridge" ]

Guest :

# grub.conf generated by anaconda
#
# Note that you do not have to rerun grub after making changes to this file
# NOTICE:  You have a /boot partition.  This means that
#          all kernel and initrd paths are relative to /boot/, eg.
#          root (hd0,0)
#          kernel /vmlinuz-version ro root=/dev/mapper/fedora-root
#          initrd /initrd-[generic-]version.img
#boot=/dev/xvda
default=0
timeout=0
#splashimage=(hd0,0)/grub/splash.xpm.gz
hiddenmenu
title Fedora (2.6.38.8-32.fc15.i686.PAE)
	root (hd0,0)
	kernel /vmlinuz-2.6.38.8-32.fc15.i686.PAE ro root=/dev/mapper/fedora-root rd_LVM_LV=fedora/root rd_LVM_LV=fedora/swap rd_NO_LUKS rd_NO_MD rd_NO_DM LANG=en_US.UTF-8 SYSFONT=latarcyrheb-sun16 KEYTABLE=us console=hvc0
	initrd /initramfs-2.6.38.8-32.fc15.i686.PAE.img


Host :

# grub.conf generated by anaconda
#
# Note that you do not have to rerun grub after making changes to this file
# NOTICE:  You have a /boot partition.  This means that
#          all kernel and initrd paths are relative to /boot/, eg.
#          root (hd0,0)
#          kernel /vmlinuz-version ro root=/dev/vg0/root
#          initrd /initrd-version.img
#boot=/dev/sda
default=0
timeout=5
#splashimage=(hd0,0)/grub/splash.xpm.gz
hiddenmenu
title Red Hat Enterprise Linux Server (2.6.18-238.12.1.el5xen)
	root (hd0,0)
	kernel /xen.gz-2.6.18-238.12.1.el5 dom0_mem=1024M
	module /vmlinuz-2.6.18-238.12.1.el5xen ro root=/dev/vg0/root selinux=0 xencons=off
	module /initrd-2.6.18-238.12.1.el5xen.img



In case it makes the difference - Host is x86_64, Guest is i386

Comment 14 Igor Mammedov 2011-07-07 14:50:24 UTC
Tried with your guest config (2.6.38.8-32.fc15.i686.PAE) and RHEL5 host with 2.6.18-238.12.1.el5xen, still no warning.

Would you like get test kernel as prebuild rpm or as a patch to 2.6.38.8-32.fc15.i686.PAE ?

Comment 15 Vadym Chepkov 2011-07-07 15:27:21 UTC
Whatever is more convenient for you.

Comment 16 Igor Mammedov 2011-07-08 15:14:00 UTC
Created attachment 511944 [details]
add extra checks debugging prinkt to xen-blkfront

Vadim,

With this patch we could probably narrow down piece of code we should trace. It should apply to 2.6.38.8-32.fc15.i686.PAE kernel source.
And add 'ignore_loglevel' to kernel command line.

Comment 17 Igor Mammedov 2011-08-16 07:55:52 UTC
Summary on the current state:
 - Bug is reproducible if back-end storage is slow or very busy. I've managed to reproduce it using a iscsi target from another host.
 - It is easier to reproduce if guest RAM is quite small, however it is not necessary. 
 - Tried with swap and without it, bug reproduces anyway.
 - Reproduces only with xen pv guest. Checked bare-metal and kvm - no problem.
 - Affects fc15 i386 pae kernel and upstream kernel with fc15.i386PAE config.
 - Reproduces both on top of xen 3.1 and 4.1.1.


Steps to reproduce warning:

FC15 i386 PAE release, updates and upstream kernels are affected.

1. Guest config:
---------------
name = "fc15x32pv"
maxmem = 128
memory = 128
vcpus = 1
bootloader = "/usr/bin/pygrub"
on_poweroff = "destroy"
on_reboot = "restart"
on_crash = "preserve"
disk = [ "phy:/dev/vg0/fc15x32pv,xvda,w", "phy:/dev/vg0/fc15T1,xvdb,w","phy:/dev/sdc,xvdc,w"]
vif = [ "mac=00:16:3e:1d:26:ce,bridge=xenbr2,script=vif-bridge" ]
----------------

2. create test volume group using xdvc (iscsi disk) and xvdb physical volumes and create logical volume on it. in my case it lv size was 1Gb.

3. do ping pong 'pvmove' of just created lv from one pv to another
 while [ 1 ]; do  pvmove -n swp /dev/xvdc; pvmove -n swp /dev/xvdb; done

4. while doing pvmove, from another shell (I've used ssh) create some io activity on moving lv.
  while [ 1 ]; do dd if=/dev/zero of=/dev/vgx/swp; done

5. repeat steps 3-4 till you get warning

Comment 18 Igor Mammedov 2011-08-16 09:01:04 UTC
Created attachment 518435 [details]
i386 PAE config for upstream kernel

I've used this config with upstream kernel (a9e4e6e) for debugging.

Comment 19 Igor Mammedov 2011-08-16 09:08:55 UTC
Created attachment 518440 [details]
Enable function_graph tracer for i386 and add additional tracing.

Function_graph should be used with "optimize for size" option disabled. Use attached config.

Comment 20 Igor Mammedov 2011-08-16 10:32:45 UTC
Created attachment 518455 [details]
ftrace function graph pointing to a place where irq-s are becoming enabled

To see problematic place, scroll down attached file to the end.

Irq always restored at drivers/md/dm.c
static void clone_endio(struct bio *bio, int error)
...
dm_endio_fn endio = tio->ti->type->end_io;
...
when page fault happens accessing tio->ti->type field.

After successful resync with kernel's pagetable in do_page_fault->vmalloc_fault, io continues happily on, however with IF flag restored even if faulted context's eflags register had no IF flag set.

Comment 21 Vadym Chepkov 2011-08-20 14:57:10 UTC
Problem went away after installing kernel-PAE-2.6.40.3-0.fc15.i686

Comment 22 Igor Mammedov 2011-08-24 08:24:12 UTC
I easily reproduce it with 2.6.40-4.fc15.i686.PAE, so problem is still there.
Reopening bug.

Comment 23 Josh Boyer 2011-08-24 11:53:29 UTC
(In reply to comment #22)
> I easily reproduce it with 2.6.40-4.fc15.i686.PAE, so problem is still there.
> Reopening bug.

2.6.40-4.fc15 is older.  Can you try testing with kernel-PAE-2.6.40.3-0.fc15?

Comment 24 Igor Mammedov 2011-08-24 12:49:07 UTC
(In reply to comment #23)
> (In reply to comment #22)
> > I easily reproduce it with 2.6.40-4.fc15.i686.PAE, so problem is still there.
> > Reopening bug.
> 
> 2.6.40-4.fc15 is older.  Can you try testing with kernel-PAE-2.6.40.3-0.fc15?

I've just tried with 2.6.40.3-0.fc15.i686.PAE kernel. 
The warning is still there. Reproduced it in 10 sec as per comment 17.

Comment 25 Igor Mammedov 2011-09-01 09:02:22 UTC
Created attachment 520978 [details]
Reproducer for irq unmasking problem using xen_netfront

Steps to reproduce:

1. Configure 32-bit PAE pv guest kernel build

2. Apply patch 0001-xen-irq-unmasking-bug-reproducer.patch and build kernel with it. Then install it into 32-bit pv guest.

3. Fix KSRC in mod_bz707552/Makefile to point to your kernel source tree and
run 'make' and copy module to guest

4. on guest execute command:
  while [ 1 ]; do insmod mod_bz707552.ko; rmmod mod_bz707552.ko; done

5. Form host flood ping guest.

Comment 26 Igor Mammedov 2011-09-01 09:39:03 UTC
One more thing about reproducer. It will print messages like:

++++ OK: page fault + irqs [enabled: 0, disabled: 6648, total: 6648]

when page fault inside netfront interrupt context happens.
If bug is present in several minutes you'll get 'enabled' field with non zero value.

Comment 27 Igor Mammedov 2011-09-01 10:44:05 UTC
Created attachment 520991 [details]
do not enable iterrupts when returning from exception in interrupt context

lkml link: https://lkml.org/lkml/2011/9/1/100

Some history of the bug: http://xen.1045712.n5.nabble.com/Fix-the-occasional-xen-blkfront-deadlock-when-irqbalancing-tt2644296.html#a4757820


Note You need to log in before you can comment on or make changes to this bug.