linux-btrfs.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* fstests generic/068 hang 120seconds
@ 2016-06-24  2:28 Wang Xiaoguang
  0 siblings, 0 replies; only message in thread
From: Wang Xiaoguang @ 2016-06-24  2:28 UTC (permalink / raw)
  To: linux-btrfs@vger.kernel.org

[-- Attachment #1: Type: text/plain, Size: 461 bytes --]

hello,

When running generic/068 in linux mail line tree 4.7.rc4, we found that
sometimes there are processes hang 120 seconds WARNINGs, it seems
that some deadlocks occurs, please see the attachment. Also it seems
4.4.0-rc6+ has this issue. Note, this bug was not reproduced every time,
you need to run multiple times.

Currently I'm looking into this issue, but if anybody already knows the true
reason, please let me know, thanks!

Regards,
Xiaoguang Wang



[-- Attachment #2: dmesg.info --]
[-- Type: text/plain, Size: 60595 bytes --]

[    0.000000] Linux version 4.7.0-rc4+ (lege@localhost.localdomain) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-4) (GCC) ) #13 SMP Fri Jun 24 09:56:17 CST 2016
[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-4.7.0-rc4+ root=/dev/sda2 ro crashkernel=auto rhgb quiet LANG=en_US.UTF-8 console=ttyS0,115200n8
[    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
[    0.000000] x86/fpu: Using 'eager' FPU context switches.
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007e1dffff] usable
[    0.000000] BIOS-e820: [mem 0x000000007e1e0000-0x000000007e1fffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 2.8 present.
[    0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.8.2-20150714_191134- 04/01/2014
[    0.000000] Hypervisor detected: KVM
[    0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000000] e820: last_pfn = 0x7e1e0 max_arch_pfn = 0x400000000
[    0.000000] MTRR default type: write-back
[    0.000000] MTRR fixed ranges enabled:
[    0.000000]   00000-9FFFF write-back
[    0.000000]   A0000-BFFFF uncachable
[    0.000000]   C0000-FFFFF write-protect
[    0.000000] MTRR variable ranges enabled:
[    0.000000]   0 base 0080000000 mask FF80000000 uncachable
[    0.000000]   1 disabled
[    0.000000]   2 disabled
[    0.000000]   3 disabled
[    0.000000]   4 disabled
[    0.000000]   5 disabled
[    0.000000]   6 disabled
[    0.000000]   7 disabled
[    0.000000] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WC  UC- WT  
[    0.000000] found SMP MP-table at [mem 0x000f6450-0x000f645f] mapped at [ffff8800000f6450]
[    0.000000] Base memory trampoline at [ffff880000099000] 99000 size 24576
[    0.000000] BRK [0x0224c000, 0x0224cfff] PGTABLE
[    0.000000] BRK [0x0224d000, 0x0224dfff] PGTABLE
[    0.000000] BRK [0x0224e000, 0x0224efff] PGTABLE
[    0.000000] BRK [0x0224f000, 0x0224ffff] PGTABLE
[    0.000000] BRK [0x02250000, 0x02250fff] PGTABLE
[    0.000000] RAMDISK: [mem 0x3240f000-0x351fffff]
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F61B0 000014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 0x000000007E1E1759 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 0x000000007E1E0C14 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 0x000000007E1E0040 000BD4 (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACS 0x000000007E1E0000 000040
[    0.000000] ACPI: SSDT 0x000000007E1E0C88 000A41 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: APIC 0x000000007E1E16C9 000090 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000007e1dffff]
[    0.000000] NODE_DATA(0) allocated [mem 0x7e1be000-0x7e1dffff]
[    0.000000] kexec_core: crashkernel: memory value expected
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:7e13e001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 3868 cycles
[    0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   DMA32    [mem 0x0000000001000000-0x000000007e1dffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.000000]   node   0: [mem 0x0000000000100000-0x000000007e1dffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000007e1dffff]
[    0.000000] On node 0 totalpages: 516478
[    0.000000]   DMA zone: 64 pages used for memmap
[    0.000000]   DMA zone: 21 pages reserved
[    0.000000]   DMA zone: 3998 pages, LIFO batch:0
[    0.000000]   DMA32 zone: 8008 pages used for memmap
[    0.000000]   DMA32 zone: 512480 pages, LIFO batch:31
[    0.000000] ACPI: PM-Timer IO Port: 0x608
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[    0.000000] ACPI: IRQ0 used by override.
[    0.000000] ACPI: IRQ5 used by override.
[    0.000000] ACPI: IRQ9 used by override.
[    0.000000] ACPI: IRQ10 used by override.
[    0.000000] ACPI: IRQ11 used by override.
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs
[    0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]
[    0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
[    0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
[    0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[    0.000000] e820: [mem 0x7e200000-0xfeffbfff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1
[    0.000000] percpu: Embedded 35 pages/cpu @ffff88007de00000 s103000 r8192 d32168 u524288
[    0.000000] pcpu-alloc: s103000 r8192 d32168 u524288 alloc=1*2097152
[    0.000000] pcpu-alloc: [0] 0 1 2 3 
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 7de0d940
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 508385
[    0.000000] Policy zone: DMA32
[    0.000000] Kernel command line: BOOT_IMAGE=/vmlinuz-4.7.0-rc4+ root=/dev/sda2 ro crashkernel=auto rhgb quiet LANG=en_US.UTF-8 console=ttyS0,115200n8
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] Memory: 1965796K/2065912K available (6884K kernel code, 1417K rwdata, 3060K rodata, 1808K init, 3180K bss, 100116K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] 	Build-time adjustment of leaf fanout to 64.
[    0.000000] 	RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[    0.000000] NR_IRQS:524544 nr_irqs:456 16
[    0.000000] 	Offload RCU callbacks from all CPUs
[    0.000000] 	Offload RCU callbacks from CPUs: 0-3.
[    0.000000] Console: colour VGA+ 80x25
[    0.000000] console [ttyS0] enabled
[    0.000000] tsc: Detected 3192.746 MHz processor
[    0.035610] Calibrating delay loop (skipped) preset value.. 6385.49 BogoMIPS (lpj=3192746)
[    0.035612] pid_max: default: 32768 minimum: 301
[    0.035617] ACPI: Core revision 20160422
[    0.035644] Security Framework initialized
[    0.035646] SELinux:  Initializing.
[    0.035651] SELinux:  Starting in permissive mode
[    0.035876] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
[    0.036242] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
[    0.036404] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes)
[    0.036407] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes)
[    0.036616] mce: CPU supports 10 MCE banks
[    0.036650] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.036651] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.037759] Freeing SMP alternatives memory: 28K (ffffffff81f28000 - ffffffff81f2f000)
[    0.042272] ftrace: allocating 26940 entries in 106 pages
[    0.064460] smpboot: Max logical packages: 4
[    0.064463] smpboot: APIC(0) Converting physical 0 to logical package 0
[    0.064464] smpboot: APIC(1) Converting physical 1 to logical package 1
[    0.064464] smpboot: APIC(2) Converting physical 2 to logical package 2
[    0.064465] smpboot: APIC(3) Converting physical 3 to logical package 3
[    0.064608] x2apic enabled
[    0.064786] Switched APIC routing to physical x2apic.
[    0.065482] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.065500] TSC deadline timer enabled
[    0.065503] smpboot: CPU0: Intel Xeon E312xx (Sandy Bridge) (family: 0x6, model: 0x2a, stepping: 0x1)
[    0.065506] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only.
[    0.065996] x86: Booting SMP configuration:
[    0.065998] .... node  #0, CPUs:      #1
[    0.071816] kvm-clock: cpu 1, msr 0:7e13e041, secondary cpu clock
[    0.092018] KVM setup async PF for cpu 1
[    0.092021] kvm-stealtime: cpu 1, msr 7de8d940
[    0.092126]  #2
[    0.097993] kvm-clock: cpu 2, msr 0:7e13e081, secondary cpu clock
[    0.118175] KVM setup async PF for cpu 2
[    0.118178] kvm-stealtime: cpu 2, msr 7df0d940
[    0.118279]  #3
[    0.124089] kvm-clock: cpu 3, msr 0:7e13e0c1, secondary cpu clock
[    0.144281] KVM setup async PF for cpu 3
[    0.144285] kvm-stealtime: cpu 3, msr 7df8d940
[    0.144298] x86: Booted up 1 node, 4 CPUs
[    0.144300] smpboot: Total of 4 processors activated (25541.96 BogoMIPS)
[    0.190502] devtmpfs: initialized
[    0.190560] x86/mm: Memory block size: 128MB
[    0.192234] evm: security.selinux
[    0.192235] evm: security.ima
[    0.192236] evm: security.capability
[    0.192325] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.192362] atomic64_test: passed for x86-64 platform with CX8 and with SSE
[    0.192363] pinctrl core: initialized pinctrl subsystem
[    0.192549] NET: Registered protocol family 16
[    0.196194] cpuidle: using governor menu
[    0.196531] ACPI: bus type PCI registered
[    0.196533] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.196617] PCI: Using configuration type 1 for base access
[    0.199665] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.199971] ACPI: Added _OSI(Module Device)
[    0.199972] ACPI: Added _OSI(Processor Device)
[    0.199973] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.199974] ACPI: Added _OSI(Processor Aggregator Device)
[    0.200687] ACPI: 2 ACPI AML tables successfully acquired and loaded

[    0.201399] ACPI: Interpreter enabled
[    0.201407] ACPI: (supports S0 S5)
[    0.201408] ACPI: Using IOAPIC for interrupt routing
[    0.201416] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.203174] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.203178] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
[    0.203182] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[    0.203186] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[    0.203391] acpiphp: Slot [3] registered
[    0.203405] acpiphp: Slot [4] registered
[    0.203418] acpiphp: Slot [5] registered
[    0.203440] acpiphp: Slot [7] registered
[    0.203453] acpiphp: Slot [8] registered
[    0.203467] acpiphp: Slot [9] registered
[    0.203481] acpiphp: Slot [10] registered
[    0.203494] acpiphp: Slot [11] registered
[    0.203507] acpiphp: Slot [12] registered
[    0.203520] acpiphp: Slot [13] registered
[    0.203534] acpiphp: Slot [14] registered
[    0.203546] acpiphp: Slot [15] registered
[    0.203560] acpiphp: Slot [16] registered
[    0.203573] acpiphp: Slot [17] registered
[    0.203586] acpiphp: Slot [18] registered
[    0.203600] acpiphp: Slot [19] registered
[    0.203613] acpiphp: Slot [20] registered
[    0.203626] acpiphp: Slot [21] registered
[    0.203640] acpiphp: Slot [22] registered
[    0.203653] acpiphp: Slot [23] registered
[    0.203667] acpiphp: Slot [24] registered
[    0.203680] acpiphp: Slot [25] registered
[    0.203693] acpiphp: Slot [26] registered
[    0.203706] acpiphp: Slot [27] registered
[    0.203719] acpiphp: Slot [28] registered
[    0.203732] acpiphp: Slot [29] registered
[    0.203746] acpiphp: Slot [30] registered
[    0.203764] acpiphp: Slot [31] registered
[    0.203774] PCI host bridge to bus 0000:00
[    0.203776] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.203777] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    0.203778] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    0.203780] pci_bus 0000:00: root bus resource [mem 0x7e200000-0xfebfffff window]
[    0.203781] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.203807] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
[    0.204060] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
[    0.204407] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
[    0.209233] pci 0000:00:01.1: reg 0x20: [io  0xc1e0-0xc1ef]
[    0.211159] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
[    0.211161] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
[    0.211162] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
[    0.211163] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
[    0.211309] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
[    0.211561] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
[    0.211568] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
[    0.211724] pci 0000:00:02.0: [1b36:0100] type 00 class 0x030000
[    0.216023] pci 0000:00:02.0: reg 0x10: [mem 0xf4000000-0xf7ffffff]
[    0.222101] pci 0000:00:02.0: reg 0x14: [mem 0xf8000000-0xfbffffff]
[    0.226215] pci 0000:00:02.0: reg 0x18: [mem 0xfc054000-0xfc055fff]
[    0.230298] pci 0000:00:02.0: reg 0x1c: [io  0xc100-0xc11f]
[    0.244578] pci 0000:00:02.0: reg 0x30: [mem 0xfc040000-0xfc04ffff pref]
[    0.247216] pci 0000:00:03.0: [10ec:8139] type 00 class 0x020000
[    0.248890] pci 0000:00:03.0: reg 0x10: [io  0xc000-0xc0ff]
[    0.250582] pci 0000:00:03.0: reg 0x14: [mem 0xfc056000-0xfc0560ff]
[    0.261577] pci 0000:00:03.0: reg 0x30: [mem 0xfc000000-0xfc03ffff pref]
[    0.262245] pci 0000:00:04.0: [8086:2668] type 00 class 0x040300
[    0.263122] pci 0000:00:04.0: reg 0x10: [mem 0xfc050000-0xfc053fff]
[    0.268759] pci 0000:00:05.0: [1af4:1003] type 00 class 0x078000
[    0.270471] pci 0000:00:05.0: reg 0x10: [io  0xc120-0xc13f]
[    0.272195] pci 0000:00:05.0: reg 0x14: [mem 0xfc057000-0xfc057fff]
[    0.283245] pci 0000:00:06.0: [8086:2934] type 00 class 0x0c0300
[    0.290044] pci 0000:00:06.0: reg 0x20: [io  0xc140-0xc15f]
[    0.292063] pci 0000:00:06.1: [8086:2935] type 00 class 0x0c0300
[    0.296645] pci 0000:00:06.1: reg 0x20: [io  0xc160-0xc17f]
[    0.300975] pci 0000:00:06.2: [8086:2936] type 00 class 0x0c0300
[    0.305445] pci 0000:00:06.2: reg 0x20: [io  0xc180-0xc19f]
[    0.307446] pci 0000:00:06.7: [8086:293a] type 00 class 0x0c0320
[    0.308352] pci 0000:00:06.7: reg 0x10: [mem 0xfc058000-0xfc058fff]
[    0.315764] pci 0000:00:07.0: [1af4:1002] type 00 class 0x00ff00
[    0.316668] pci 0000:00:07.0: reg 0x10: [io  0xc1a0-0xc1bf]
[    0.322424] pci 0000:00:08.0: [8086:2922] type 00 class 0x010601
[    0.334594] pci 0000:00:08.0: reg 0x20: [io  0xc1c0-0xc1df]
[    0.336814] pci 0000:00:08.0: reg 0x24: [mem 0xfc059000-0xfc059fff]
[    0.339699] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    0.339776] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[    0.339839] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[    0.339900] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    0.339933] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[    0.340245] ACPI: Enabled 16 GPEs in block 00 to 0F
[    0.340407] vgaarb: setting as boot device: PCI:0000:00:02.0
[    0.340409] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
[    0.340411] vgaarb: loaded
[    0.340412] vgaarb: bridge control possible 0000:00:02.0
[    0.340458] SCSI subsystem initialized
[    0.340475] ACPI: bus type USB registered
[    0.340487] usbcore: registered new interface driver usbfs
[    0.340493] usbcore: registered new interface driver hub
[    0.340513] usbcore: registered new device driver usb
[    0.340621] PCI: Using ACPI for IRQ routing
[    0.340622] PCI: pci_cache_line_size set to 64 bytes
[    0.340789] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]
[    0.340791] e820: reserve RAM buffer [mem 0x7e1e0000-0x7fffffff]
[    0.340859] NetLabel: Initializing
[    0.340860] NetLabel:  domain hash size = 128
[    0.340861] NetLabel:  protocols = UNLABELED CIPSOv4
[    0.340870] NetLabel:  unlabeled traffic allowed by default
[    0.341015] clocksource: Switched to clocksource kvm-clock
[    0.345484] VFS: Disk quotas dquot_6.6.0
[    0.345499] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.345685] pnp: PnP ACPI init
[    0.345731] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active)
[    0.345766] pnp 00:01: Plug and Play ACPI device, IDs PNP0303 (active)
[    0.345784] pnp 00:02: Plug and Play ACPI device, IDs PNP0f13 (active)
[    0.345803] pnp 00:03: [dma 2]
[    0.345813] pnp 00:03: Plug and Play ACPI device, IDs PNP0700 (active)
[    0.345883] pnp 00:04: Plug and Play ACPI device, IDs PNP0501 (active)
[    0.346036] pnp: PnP ACPI: found 5 devices
[    0.353336] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.353347] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
[    0.353349] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
[    0.353350] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[    0.353351] pci_bus 0000:00: resource 7 [mem 0x7e200000-0xfebfffff window]
[    0.353369] NET: Registered protocol family 2
[    0.353516] TCP established hash table entries: 16384 (order: 5, 131072 bytes)
[    0.353540] TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
[    0.353556] TCP: Hash tables configured (established 16384 bind 16384)
[    0.353568] UDP hash table entries: 1024 (order: 3, 32768 bytes)
[    0.353573] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
[    0.353600] NET: Registered protocol family 1
[    0.353607] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    0.353619] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    0.353633] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    0.353668] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    0.370571] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
[    0.405303] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[    0.440293] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[    0.475105] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[    0.492474] PCI: CLS 0 bytes, default 64
[    0.492528] Unpacking initramfs...
[    0.974609] Freeing initrd memory: 47044K (ffff88003240f000 - ffff880035200000)
[    0.976180] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.976212] audit: initializing netlink subsys (disabled)
[    0.976225] audit: type=2000 audit(1466733625.528:1): initialized
[    0.976431] Initialise system trusted keyrings
[    0.976572] workingset: timestamp_bits=34 max_order=19 bucket_order=0
[    0.978800] zbud: loaded
[    0.979220] Key type big_key registered
[    0.979223] SELinux:  Registering netfilter hooks
[    1.015775] NET: Registered protocol family 38
[    1.015777] Key type asymmetric registered
[    1.015778] Asymmetric key parser 'x509' registered
[    1.015835] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    1.015878] io scheduler noop registered
[    1.015880] io scheduler deadline registered (default)
[    1.015926] io scheduler cfq registered
[    1.016073] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    1.016080] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    1.016104] intel_idle: does not run on family 6 model 42
[    1.016189] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    1.016191] ACPI: Power Button [PWRF]
[    1.016389] GHES: HEST is not enabled!
[    1.016468] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    1.039530] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    1.039936] Non-volatile memory driver v1.3
[    1.039967] Linux agpgart interface v0.103
[    1.040231] rdac: device handler registered
[    1.040266] hp_sw: device handler registered
[    1.040267] emc: device handler registered
[    1.040332] alua: device handler registered
[    1.040356] libphy: Fixed MDIO Bus: probed
[    1.040394] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    1.040397] ehci-pci: EHCI PCI platform driver
[    1.058237] ehci-pci 0000:00:06.7: EHCI Host Controller
[    1.058298] ehci-pci 0000:00:06.7: new USB bus registered, assigned bus number 1
[    1.058422] ehci-pci 0000:00:06.7: irq 10, io mem 0xfc058000
[    1.064036] ehci-pci 0000:00:06.7: USB 2.0 started, EHCI 1.00
[    1.064069] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    1.064071] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.064072] usb usb1: Product: EHCI Host Controller
[    1.064073] usb usb1: Manufacturer: Linux 4.7.0-rc4+ ehci_hcd
[    1.064074] usb usb1: SerialNumber: 0000:00:06.7
[    1.064171] hub 1-0:1.0: USB hub found
[    1.064176] hub 1-0:1.0: 6 ports detected
[    1.064305] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    1.064308] ohci-pci: OHCI PCI platform driver
[    1.064313] uhci_hcd: USB Universal Host Controller Interface driver
[    1.081863] uhci_hcd 0000:00:06.0: UHCI Host Controller
[    1.081951] uhci_hcd 0000:00:06.0: new USB bus registered, assigned bus number 2
[    1.081978] uhci_hcd 0000:00:06.0: detected 2 ports
[    1.082015] uhci_hcd 0000:00:06.0: irq 10, io base 0x0000c140
[    1.082103] usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
[    1.082105] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.082106] usb usb2: Product: UHCI Host Controller
[    1.082107] usb usb2: Manufacturer: Linux 4.7.0-rc4+ uhci_hcd
[    1.082120] usb usb2: SerialNumber: 0000:00:06.0
[    1.082211] hub 2-0:1.0: USB hub found
[    1.082215] hub 2-0:1.0: 2 ports detected
[    1.099830] uhci_hcd 0000:00:06.1: UHCI Host Controller
[    1.099917] uhci_hcd 0000:00:06.1: new USB bus registered, assigned bus number 3
[    1.099943] uhci_hcd 0000:00:06.1: detected 2 ports
[    1.100011] uhci_hcd 0000:00:06.1: irq 11, io base 0x0000c160
[    1.100079] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001
[    1.100081] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.100082] usb usb3: Product: UHCI Host Controller
[    1.100083] usb usb3: Manufacturer: Linux 4.7.0-rc4+ uhci_hcd
[    1.100084] usb usb3: SerialNumber: 0000:00:06.1
[    1.100207] hub 3-0:1.0: USB hub found
[    1.100211] hub 3-0:1.0: 2 ports detected
[    1.117599] uhci_hcd 0000:00:06.2: UHCI Host Controller
[    1.117773] uhci_hcd 0000:00:06.2: new USB bus registered, assigned bus number 4
[    1.117793] uhci_hcd 0000:00:06.2: detected 2 ports
[    1.117828] uhci_hcd 0000:00:06.2: irq 11, io base 0x0000c180
[    1.117873] usb usb4: New USB device found, idVendor=1d6b, idProduct=0001
[    1.117875] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.117876] usb usb4: Product: UHCI Host Controller
[    1.117877] usb usb4: Manufacturer: Linux 4.7.0-rc4+ uhci_hcd
[    1.117878] usb usb4: SerialNumber: 0000:00:06.2
[    1.118059] hub 4-0:1.0: USB hub found
[    1.118064] hub 4-0:1.0: 2 ports detected
[    1.118169] usbcore: registered new interface driver usbserial
[    1.118175] usbcore: registered new interface driver usbserial_generic
[    1.118179] usbserial: USB Serial support registered for generic
[    1.118197] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    1.119374] serio: i8042 KBD port at 0x60,0x64 irq 1
[    1.119377] serio: i8042 AUX port at 0x60,0x64 irq 12
[    1.119537] mousedev: PS/2 mouse device common for all mice
[    1.120026] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    1.120411] rtc_cmos 00:00: RTC can wake from S4
[    1.121050] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
[    1.121116] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram
[    1.121173] hidraw: raw HID events driver (C) Jiri Kosina
[    1.121230] usbcore: registered new interface driver usbhid
[    1.121231] usbhid: USB HID core driver
[    1.121281] drop_monitor: Initializing network drop monitor service
[    1.121336] Initializing XFRM netlink socket
[    1.121452] NET: Registered protocol family 10
[    1.122149] NET: Registered protocol family 17
[    1.122308] microcode: CPU0 sig=0x206a1, pf=0x1, revision=0x1
[    1.122321] microcode: CPU1 sig=0x206a1, pf=0x1, revision=0x1
[    1.122357] microcode: CPU2 sig=0x206a1, pf=0x1, revision=0x1
[    1.122408] microcode: CPU3 sig=0x206a1, pf=0x1, revision=0x1
[    1.122441] microcode: Microcode Update Driver: v2.01 <tigran@aivazian.fsnet.co.uk>, Peter Oruba
[    1.122566] registered taskstats version 1
[    1.122568] Loading compiled-in X.509 certificates
[    1.124028] alg: No test for pkcs1pad(rsa,sha256) (pkcs1pad(rsa-generic,sha256))
[    1.124638] Loaded X.509 cert 'Build time autogenerated kernel key: b6b06926cb00ac060956d18d707e8cdd4cfbaf53'
[    1.124654] zswap: loaded using pool lzo/zbud
[    1.135615] Key type trusted registered
[    1.137132] Key type encrypted registered
[    1.137135] ima: No TPM chip found, activating TPM-bypass!
[    1.137159] evm: HMAC attrs: 0x1
[    1.137519] rtc_cmos 00:00: setting system clock to 2016-06-24 02:00:25 UTC (1466733625)
[    1.138430] Freeing unused kernel memory: 1808K (ffffffff81d64000 - ffffffff81f28000)
[    1.138431] Write protecting the kernel read-only data: 12288k
[    1.138785] Freeing unused kernel memory: 1292K (ffff8800016bd000 - ffff880001800000)
[    1.140444] Freeing unused kernel memory: 1036K (ffff880001afd000 - ffff880001c00000)
[    1.142156] random: systemd urandom read with 11 bits of entropy available
[    1.158513] systemd[1]: systemd 219 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[    1.158528] systemd[1]: Detected virtualization kvm.
[    1.158531] systemd[1]: Detected architecture x86-64.
[    1.158533] systemd[1]: Running in initial RAM disk.
[    1.158556] systemd[1]: Set hostname to <localhost.localdomain>.
[    1.186656] systemd[1]: Reached target Timers.
[    1.186665] systemd[1]: Starting Timers.
[    1.186672] systemd[1]: Reached target Swap.
[    1.186677] systemd[1]: Starting Swap.
[    1.186684] systemd[1]: Reached target Local File Systems.
[    1.186689] systemd[1]: Starting Local File Systems.
[    1.186868] systemd[1]: Created slice -.slice.
[    1.186874] systemd[1]: Starting -.slice.
[    1.186923] systemd[1]: Created slice System Slice.
[    1.186929] systemd[1]: Starting System Slice.
[    1.186969] systemd[1]: Listening on Journal Socket.
[    1.186975] systemd[1]: Starting Journal Socket.
[    1.197187] systemd[1]: Starting Setup Virtual Console...
[    1.197505] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[    1.197584] systemd[1]: Started Load Kernel Modules.
[    1.197875] systemd[1]: Starting Apply Kernel Variables...
[    1.197906] systemd[1]: Started dracut ask for additional cmdline parameters.
[    1.198234] systemd[1]: Starting dracut cmdline hook...
[    1.199695] systemd[1]: Starting Journal Service...
[    1.199734] systemd[1]: Listening on udev Control Socket.
[    1.199742] systemd[1]: Starting udev Control Socket.
[    1.199768] systemd[1]: Listening on udev Kernel Socket.
[    1.199774] systemd[1]: Starting udev Kernel Socket.
[    1.199781] systemd[1]: Reached target Sockets.
[    1.199787] systemd[1]: Starting Sockets.
[    1.199793] systemd[1]: Reached target Slices.
[    1.199797] systemd[1]: Starting Slices.
[    1.200061] systemd[1]: Started Create list of required static device nodes for the current kernel.
[    1.200250] systemd[1]: Started Apply Kernel Variables.
[    1.206177] systemd[1]: Starting Create Static Device Nodes in /dev...
[    1.208587] systemd[1]: Started Create Static Device Nodes in /dev.
[    1.218832] systemd[1]: Started Journal Service.
[    1.341026] libata version 3.00 loaded.
[    1.356397] FDC 0 is a S82078B
[    1.364053] virtio-pci 0000:00:05.0: virtio_pci: leaving for legacy driver
[    1.364752] ata_piix 0000:00:01.1: version 2.13
[    1.366060] scsi host0: ata_piix
[    1.366161] scsi host1: ata_piix
[    1.366190] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14
[    1.366192] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15
[    1.367043] 8139cp: 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[    1.385683] [drm] Initialized drm 1.1.0 20060810
[    1.386900] 8139cp 0000:00:03.0 eth0: RTL-8139C+ at 0xffffc900003d4000, 52:54:00:8f:be:34, IRQ 11
[    1.387699] ahci 0000:00:08.0: version 3.0
[    1.390594] 8139too: 8139too Fast Ethernet driver 0.9.28
[    1.406216] ahci 0000:00:08.0: AHCI 0001.0000 32 slots 6 ports 1.5 Gbps 0x3f impl SATA mode
[    1.406219] ahci 0000:00:08.0: flags: ncq only 
[    1.406961] scsi host2: ahci
[    1.407044] scsi host3: ahci
[    1.408179] scsi host4: ahci
[    1.411105] scsi host5: ahci
[    1.411216] scsi host6: ahci
[    1.411304] scsi host7: ahci
[    1.411352] ata3: SATA max UDMA/133 abar m4096@0xfc059000 port 0xfc059100 irq 24
[    1.411359] ata4: SATA max UDMA/133 abar m4096@0xfc059000 port 0xfc059180 irq 24
[    1.411365] ata5: SATA max UDMA/133 abar m4096@0xfc059000 port 0xfc059200 irq 24
[    1.411381] ata6: SATA max UDMA/133 abar m4096@0xfc059000 port 0xfc059280 irq 24
[    1.411386] ata7: SATA max UDMA/133 abar m4096@0xfc059000 port 0xfc059300 irq 24
[    1.411390] ata8: SATA max UDMA/133 abar m4096@0xfc059000 port 0xfc059380 irq 24
[    1.429843] virtio-pci 0000:00:07.0: virtio_pci: leaving for legacy driver
[    1.431474] 8139cp 0000:00:03.0 ens3: renamed from eth0
[    1.451100] [drm] Device Version 0.0
[    1.451102] [drm] Compression level 0 log level 0
[    1.451103] [drm] Currently using mode #0, list at 0x488
[    1.451104] [drm] 12286 io pages at offset 0x1000000
[    1.451105] [drm] 16777216 byte draw area at offset 0x0
[    1.451106] [drm] RAM header offset: 0x3ffe000
[    1.451106] [drm] rom modes offset 0x488 for 128 modes
[    1.451184] [TTM] Zone  kernel: Available graphics memory: 1008502 kiB
[    1.451185] [TTM] Initializing pool allocator
[    1.451189] [TTM] Initializing DMA pool allocator
[    1.451195] [drm] qxl: 16M of VRAM memory size
[    1.451195] [drm] qxl: 63M of IO pages memory ready (VRAM domain)
[    1.451196] [drm] qxl: 64M of Surface memory size
[    1.453236] [drm] main mem slot 1 [f4000000,3ffe000]
[    1.453240] [drm] surface mem slot 2 [f8000000,4000000]
[    1.453329] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    1.453330] [drm] No driver support for vblank timestamp query.
[    1.453612] [drm] fb mappable at 0xF4000000, size 3145728
[    1.453614] [drm] fb: depth 24, pitch 4096, width 1024, height 768
[    1.453661] fbcon: qxldrmfb (fb0) is primary device
[    1.470152] Console: switching to colour frame buffer device 128x48
[    1.473143] qxl 0000:00:02.0: fb0: qxldrmfb frame buffer device
[    1.483125] [drm] Initialized qxl 0.1.0 20120117 for 0000:00:02.0 on minor 0
[    1.517923] ata2.00: ATA-7: QEMU HARDDISK, 2.4.0.1, max UDMA/100
[    1.517926] ata2.00: 83886080 sectors, multi 16: LBA48 
[    1.518012] ata2.01: ATA-7: QEMU HARDDISK, 2.4.0.1, max UDMA/100
[    1.518029] ata2.01: 190840832 sectors, multi 16: LBA48 
[    1.518210] ata1.00: ATA-7: QEMU HARDDISK, 2.4.0.1, max UDMA/100
[    1.518220] ata1.00: 41943040 sectors, multi 16: LBA48 
[    1.518278] ata1.01: ATAPI: QEMU DVD-ROM, 2.4.0.1, max UDMA/100
[    1.518763] ata2.00: configured for MWDMA2
[    1.518942] ata1.00: configured for MWDMA2
[    1.519454] ata2.01: configured for MWDMA2
[    1.519553] ata1.01: configured for MWDMA2
[    1.519947] scsi 0:0:0:0: Direct-Access     ATA      QEMU HARDDISK    0.1  PQ: 0 ANSI: 5
[    1.530930] scsi 0:0:1:0: CD-ROM            QEMU     QEMU DVD-ROM     2.4. PQ: 0 ANSI: 5
[    1.536333] scsi 1:0:0:0: Direct-Access     ATA      QEMU HARDDISK    0.1  PQ: 0 ANSI: 5
[    1.545301] scsi 1:0:1:0: Direct-Access     ATA      QEMU HARDDISK    0.1  PQ: 0 ANSI: 5
[    1.715044] ata3: SATA link down (SStatus 0 SControl 300)
[    1.715168] ata4: SATA link down (SStatus 0 SControl 300)
[    1.716102] ata6: SATA link down (SStatus 0 SControl 300)
[    1.716187] ata5: SATA link down (SStatus 0 SControl 300)
[    1.717094] ata7: SATA link down (SStatus 0 SControl 300)
[    1.720189] ata8: SATA link down (SStatus 0 SControl 300)
[    1.734606] sd 0:0:0:0: [sda] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB)
[    1.734647] sd 0:0:0:0: [sda] Write Protect is off
[    1.734650] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    1.734662] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.734946] sd 1:0:0:0: [sdb] 83886080 512-byte logical blocks: (42.9 GB/40.0 GiB)
[    1.734986] sd 1:0:0:0: [sdb] Write Protect is off
[    1.734988] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[    1.735001] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.735864] sd 1:0:1:0: [sdc] 190840832 512-byte logical blocks: (97.7 GB/91.0 GiB)
[    1.735907] sd 1:0:1:0: [sdc] Write Protect is off
[    1.735909] sd 1:0:1:0: [sdc] Mode Sense: 00 3a 00 00
[    1.735922] sd 1:0:1:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.737413]  sda: sda1 sda2 sda3
[    1.737776]  sdb: sdb1 sdb2 sdb3
[    1.737958] sd 0:0:0:0: [sda] Attached SCSI disk
[    1.748789] sr 0:0:1:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
[    1.748792] cdrom: Uniform CD-ROM driver Revision: 3.20
[    1.749066] sr 0:0:1:0: Attached scsi CD-ROM sr0
[    1.821296]  sdc: sdc1 < sdc5 sdc6 sdc7 sdc8 sdc9 sdc10 >
[    1.821708] sd 1:0:0:0: [sdb] Attached SCSI disk
[    1.886649] sd 1:0:1:0: [sdc] Attached SCSI disk
[    1.923958] input: ImExPS/2 BYD TouchPad as /devices/platform/i8042/serio1/input/input3
[    1.949513] random: nonblocking pool is initialized
[    1.976078] tsc: Refined TSC clocksource calibration: 3192.748 MHz
[    1.976082] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2e05875245f, max_idle_ns: 440795336287 ns
[    2.916133] SGI XFS with ACLs, security attributes, no debug enabled
[    2.917926] XFS (sda2): Mounting V4 Filesystem
[    3.201870] XFS (sda2): Starting recovery (logdev: internal)
[    3.279166] XFS (sda2): Ending recovery (logdev: internal)
[    3.568249] systemd-journald[162]: Received SIGTERM from PID 1 (systemd).
[    3.914288] SELinux:  Disabled at runtime.
[    3.914319] SELinux:  Unregistering netfilter hooks
[    3.923154] audit: type=1404 audit(1466733628.285:2): selinux=0 auid=4294967295 ses=4294967295
[    3.961232] ip_tables: (C) 2000-2006 Netfilter Core Team
[    3.961517] systemd[1]: Inserted module 'ip_tables'
[    5.463572] systemd-journald[473]: Received request to flush runtime journal from PID 1
[    5.665173] RPC: Registered named UNIX socket transport module.
[    5.665176] RPC: Registered udp transport module.
[    5.665177] RPC: Registered tcp transport module.
[    5.665178] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    5.945092] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[    6.432517] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
[    6.497553] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    6.497574] sr 0:0:1:0: Attached scsi generic sg1 type 5
[    6.497593] sd 1:0:0:0: Attached scsi generic sg2 type 0
[    6.497612] sd 1:0:1:0: Attached scsi generic sg3 type 0
[    6.556517] input: PC Speaker as /devices/platform/pcspkr/input/input4
[    6.945388] AVX version of gcm_enc/dec engaged.
[    6.945391] AES CTR mode by8 optimization enabled
[    6.994894] ppdev: user-space parallel port driver
[    7.004025] raid6: sse2x1   gen()  8804 MB/s
[    7.010777] XFS (sda1): Mounting V4 Filesystem
[    7.015951] Adding 1044476k swap on /dev/sda3.  Priority:-1 extents:1 across:1044476k FS
[    7.021022] raid6: sse2x1   xor()  7226 MB/s
[    7.038021] raid6: sse2x2   gen() 11390 MB/s
[    7.055035] raid6: sse2x2   xor()  8146 MB/s
[    7.072022] raid6: sse2x4   gen() 13468 MB/s
[    7.089021] raid6: sse2x4   xor()  9494 MB/s
[    7.089024] raid6: using algorithm sse2x4 gen() 13468 MB/s
[    7.089025] raid6: .... xor() 9494 MB/s, rmw enabled
[    7.089026] raid6: using ssse3x2 recovery algorithm
[    7.114692] xor: automatically using best checksumming function:
[    7.124023]    avx       : 25780.000 MB/sec
[    7.188963] snd_hda_codec_generic hdaudioC0D0: autoconfig for Generic: line_outs=1 (0x3/0x0/0x0/0x0/0x0) type:line
[    7.188967] snd_hda_codec_generic hdaudioC0D0:    speaker_outs=0 (0x0/0x0/0x0/0x0/0x0)
[    7.188968] snd_hda_codec_generic hdaudioC0D0:    hp_outs=0 (0x0/0x0/0x0/0x0/0x0)
[    7.188969] snd_hda_codec_generic hdaudioC0D0:    mono: mono_out=0x0
[    7.188970] snd_hda_codec_generic hdaudioC0D0:    inputs:
[    7.188972] snd_hda_codec_generic hdaudioC0D0:      Line=0x5
[    7.356706] Btrfs loaded, crc32c=crc32c-intel, debug=on
[    7.356709] BTRFS: selftest: sectorsize: 4096  nodesize: 4096
[    7.356710] BTRFS: selftest: sectorsize: 4096  nodesize: 8192
[    7.356711] BTRFS: selftest: sectorsize: 4096  nodesize: 16384
[    7.356712] BTRFS: selftest: sectorsize: 4096  nodesize: 32768
[    7.356712] BTRFS: selftest: sectorsize: 4096  nodesize: 65536
[    7.359982] BTRFS: device fsid 90aee89d-3eb9-4456-851b-6267b34e21f8 devid 1 transid 15 /dev/sdc5
[    7.374161] BTRFS: device fsid 373aa7ef-e4d3-41fa-a37e-11eca1e76a9c devid 3 transid 20 /dev/sdc8
[    7.398230] BTRFS: device fsid 07970b51-3d9d-4819-9b89-bfc18987714d devid 1 transid 59 /dev/sdb2
[    7.401043] BTRFS: device fsid 373aa7ef-e4d3-41fa-a37e-11eca1e76a9c devid 5 transid 20 /dev/sdc10
[    7.422925] BTRFS: device fsid 373aa7ef-e4d3-41fa-a37e-11eca1e76a9c devid 4 transid 20 /dev/sdc9
[    7.449184] BTRFS: device fsid 373aa7ef-e4d3-41fa-a37e-11eca1e76a9c devid 2 transid 20 /dev/sdc7
[    7.452007] BTRFS: device fsid 245867ba-cd7e-4db8-8f90-a5a5f2c20551 devid 1 transid 105 /dev/sdb1
[    7.467547] BTRFS: device fsid 590f5ba3-c90e-4073-b698-5118ddc3891f devid 1 transid 15 /dev/sdc6
[    7.617902] device-mapper: uevent: version 1.0.3
[    7.618026] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com
[    9.019938] EXT4-fs (sdb3): recovery complete
[    9.031153] EXT4-fs (sdb3): mounted filesystem with ordered data mode. Opts: (null)
[    9.397961] XFS (sda1): Starting recovery (logdev: internal)
[    9.439422] XFS (sda1): Ending recovery (logdev: internal)
[    9.686029] audit: type=1305 audit(1466733634.048:3): audit_pid=644 old=0 auid=4294967295 ses=4294967295 res=1
[   14.728285] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
[   14.796747] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   14.932284] Ebtables v2.0 registered
[   14.991112] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
[   16.772542] IPv6: ADDRCONF(NETDEV_UP): ens3: link is not ready
[   16.772746] 8139cp 0000:00:03.0 ens3: link up, 100Mbps, full-duplex, lpa 0x05E1
[   29.425456] fuse init (API version 7.24)
[   29.871671] input: spice vdagent tablet as /devices/virtual/input/input5
[  108.866658] BTRFS: device fsid c19086e7-6bfa-4ebc-bd2e-c031fab96c8e devid 1 transid 3 /dev/sdc5
[  145.043186] BTRFS info (device sdc5): disk space caching is enabled
[  145.043192] BTRFS info (device sdc5): has skinny extents
[  145.043195] BTRFS info (device sdc5): flagging fs with big metadata feature
[  145.048394] BTRFS info (device sdc5): creating UUID tree
[  145.220961] BTRFS: device fsid 16465df4-279a-421a-ab8e-29de6715e875 devid 1 transid 3 /dev/sdc6
[  145.373600] BTRFS info (device sdc6): disk space caching is enabled
[  145.373605] BTRFS info (device sdc6): has skinny extents
[  145.373607] BTRFS info (device sdc6): flagging fs with big metadata feature
[  145.381608] BTRFS info (device sdc6): creating UUID tree
[  145.621107] BTRFS info (device sdc5): disk space caching is enabled
[  145.621113] BTRFS info (device sdc5): has skinny extents
[  145.708325] run fstests generic/068 at 2016-06-24 10:02:50
[  146.074129] BTRFS: device fsid 7ec7eb41-9d52-411d-8b11-d0cc4f8f318c devid 1 transid 3 /dev/sdc6
[  146.224040] BTRFS info (device sdc6): disk space caching is enabled
[  146.224045] BTRFS info (device sdc6): has skinny extents
[  146.224047] BTRFS info (device sdc6): flagging fs with big metadata feature
[  146.230779] BTRFS info (device sdc6): creating UUID tree
[  249.364470] BTRFS info (device sdc6): disk space caching is enabled
[  249.364474] BTRFS info (device sdc6): has skinny extents
[  249.737384] BTRFS info (device sdc5): disk space caching is enabled
[  249.737388] BTRFS info (device sdc5): has skinny extents
[  249.811077] BTRFS: device fsid 00f81f97-af09-4395-829f-4344921cfdfb devid 1 transid 3 /dev/sdc6
[  249.976915] BTRFS info (device sdc6): disk space caching is enabled
[  249.976918] BTRFS info (device sdc6): has skinny extents
[  249.976920] BTRFS info (device sdc6): flagging fs with big metadata feature
[  249.979259] BTRFS info (device sdc6): creating UUID tree
[  250.201091] BTRFS info (device sdc5): disk space caching is enabled
[  250.201096] BTRFS info (device sdc5): has skinny extents
[  250.232356] run fstests generic/068 at 2016-06-24 10:04:34
[  250.515025] BTRFS: device fsid 5b93dcdb-f217-4414-9ea3-e94d2d8b6c93 devid 1 transid 3 /dev/sdc6
[  250.688275] BTRFS info (device sdc6): disk space caching is enabled
[  250.688279] BTRFS info (device sdc6): has skinny extents
[  250.688280] BTRFS info (device sdc6): flagging fs with big metadata feature
[  250.707364] BTRFS info (device sdc6): creating UUID tree
[  261.002789] serial8250: too much work for irq4
[  261.065275] serial8250: too much work for irq4
[  261.117671] serial8250: too much work for irq4
[  261.169175] serial8250: too much work for irq4
[  367.435661] BTRFS info (device sdc6): disk space caching is enabled
[  367.435666] BTRFS info (device sdc6): has skinny extents
[  367.874838] BTRFS info (device sdc5): disk space caching is enabled
[  367.874842] BTRFS info (device sdc5): has skinny extents
[  367.934369] BTRFS: device fsid ae7b3216-d909-481b-9547-cbbae2360322 devid 1 transid 3 /dev/sdc6
[  368.098480] BTRFS info (device sdc6): disk space caching is enabled
[  368.098484] BTRFS info (device sdc6): has skinny extents
[  368.098486] BTRFS info (device sdc6): flagging fs with big metadata feature
[  368.137031] BTRFS info (device sdc6): creating UUID tree
[  368.360076] BTRFS info (device sdc5): disk space caching is enabled
[  368.360080] BTRFS info (device sdc5): has skinny extents
[  368.380958] run fstests generic/068 at 2016-06-24 10:06:32
[  368.637920] BTRFS: device fsid 998ebf74-97c8-4030-a2f6-7ba9a86f49c1 devid 1 transid 3 /dev/sdc6
[  368.765042] BTRFS info (device sdc6): disk space caching is enabled
[  368.765048] BTRFS info (device sdc6): has skinny extents
[  368.765051] BTRFS info (device sdc6): flagging fs with big metadata feature
[  368.770148] BTRFS info (device sdc6): creating UUID tree
[  471.325993] BTRFS info (device sdc6): disk space caching is enabled
[  471.325998] BTRFS info (device sdc6): has skinny extents
[  471.707472] BTRFS info (device sdc5): disk space caching is enabled
[  471.707476] BTRFS info (device sdc5): has skinny extents
[  471.767701] BTRFS: device fsid c905ec9c-0c57-4976-a876-331991f9739f devid 1 transid 3 /dev/sdc6
[  471.910010] BTRFS info (device sdc6): disk space caching is enabled
[  471.910035] BTRFS info (device sdc6): has skinny extents
[  471.910037] BTRFS info (device sdc6): flagging fs with big metadata feature
[  471.918793] BTRFS info (device sdc6): creating UUID tree
[  472.120217] BTRFS info (device sdc5): disk space caching is enabled
[  472.120221] BTRFS info (device sdc5): has skinny extents
[  472.150617] run fstests generic/068 at 2016-06-24 10:08:16
[  472.463217] BTRFS: device fsid 23207d97-de75-478d-92a4-1d95aaf6b15d devid 1 transid 3 /dev/sdc6
[  472.627626] BTRFS info (device sdc6): disk space caching is enabled
[  472.627632] BTRFS info (device sdc6): has skinny extents
[  472.627634] BTRFS info (device sdc6): flagging fs with big metadata feature
[  472.638854] BTRFS info (device sdc6): creating UUID tree
[  720.250158] INFO: task fsstress:12881 blocked for more than 120 seconds.
[  720.251289]       Not tainted 4.7.0-rc4+ #13
[  720.251957] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  720.253190] fsstress        D ffff880077f0bdd0     0 12881  12880 0x00000080
[  720.253197]  ffff880077f0bdd0 ffff880073a3ace8 ffff88003414ab80 ffff88007515c000
[  720.253200]  ffff880077f0c000 ffff880074eee070 ffffffffffffffff ffff880074eee088
[  720.253204]  ffffffff81248600 ffff880077f0bde8 ffffffff816b0755 ffff88003414ab80
[  720.253207] Call Trace:
[  720.253217]  [<ffffffff81248600>] ? do_fsync+0x70/0x70
[  720.253222]  [<ffffffff816b0755>] schedule+0x35/0x80
[  720.253226]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  720.253232]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  720.253236]  [<ffffffff816b27f0>] down_read+0x20/0x30
[  720.253240]  [<ffffffff81218962>] iterate_supers+0xa2/0x110
[  720.253244]  [<ffffffff81248724>] sys_sync+0x54/0xb0
[  720.253249]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  720.253252]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  720.253256] INFO: task fsstress:12882 blocked for more than 120 seconds.
[  720.254292]       Not tainted 4.7.0-rc4+ #13
[  720.255812] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  720.257218] fsstress        D ffff88006c933dd0     0 12882  12880 0x00000080
[  720.257225]  ffff88006c933dd0 ffff880074eee088 ffff880034158000 ffff88006c933db0
[  720.257229]  ffff88006c934000 ffff880074eee070 ffffffffffffffff ffff880074eee088
[  720.257238]  ffffffff81248600 ffff88006c933de8 ffffffff816b0755 ffff880034158000
[  720.257241] Call Trace:
[  720.257249]  [<ffffffff81248600>] ? do_fsync+0x70/0x70
[  720.257254]  [<ffffffff816b0755>] schedule+0x35/0x80
[  720.257258]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  720.257263]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  720.257268]  [<ffffffff816b27f0>] down_read+0x20/0x30
[  720.257273]  [<ffffffff81218962>] iterate_supers+0xa2/0x110
[  720.257276]  [<ffffffff81248724>] sys_sync+0x54/0xb0
[  720.257282]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  720.257286]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  720.257291] INFO: task fstest:12924 blocked for more than 120 seconds.
[  720.258379]       Not tainted 4.7.0-rc4+ #13
[  720.259501] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  720.261196] fstest          D ffff880074c07ba0     0 12924  12923 0x00000080
[  720.261201]  ffff880074c07ba0 ffffffff8109fc72 ffff880077fbc140 ffff880074c07db0
[  720.261204]  ffff880074c08000 ffff880074eee2c8 fffffffeffffffff ffff880074eee2e0
[  720.261207]  ffff880074c07db0 ffff880074c07bb8 ffffffff816b0755 ffff880077fbc140
[  720.261210] Call Trace:
[  720.261217]  [<ffffffff8109fc72>] ? insert_work+0x62/0xa0
[  720.261220]  [<ffffffff816b0755>] schedule+0x35/0x80
[  720.261224]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  720.261228]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  720.261232]  [<ffffffff810d1de5>] percpu_down_read+0x35/0x50
[  720.261236]  [<ffffffff812174fc>] __sb_start_write+0x2c/0x40
[  720.261239]  [<ffffffff81236584>] mnt_want_write+0x24/0x50
[  720.261242]  [<ffffffff8122376d>] path_openat+0x85d/0x1370
[  720.261247]  [<ffffffff810f10d3>] ? current_fs_time+0x23/0x30
[  720.261254]  [<ffffffff81232301>] ? touch_atime+0x31/0xd0
[  720.261259]  [<ffffffff81190f94>] ? generic_file_read_iter+0x604/0x7b0
[  720.261262]  [<ffffffff812254d1>] do_filp_open+0x91/0x100
[  720.261268]  [<ffffffff813502f4>] ? lockref_put_or_lock+0x44/0x70
[  720.261272]  [<ffffffff81233876>] ? __alloc_fd+0x46/0x180
[  720.261276]  [<ffffffff81213724>] do_sys_open+0x124/0x210
[  720.261279]  [<ffffffff8121382e>] SyS_open+0x1e/0x20
[  720.261283]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  720.261286]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  720.261289] INFO: task fstest:12925 blocked for more than 120 seconds.
[  720.262865]       Not tainted 4.7.0-rc4+ #13
[  720.263858] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  720.265617] fstest          D ffff880074c0bdd0     0 12925  12923 0x00000080
[  720.265622]  ffff880074c0bdd0 0000000000a44010 ffff880077fb95c0 ffff880074c0beb0
[  720.265625]  ffff880074c0c000 ffff880074eee2c8 ffffffffffffffff ffff880074eee2e0
[  720.265628]  ffff8800739fa600 ffff880074c0bde8 ffffffff816b0755 ffff880077fb95c0
[  720.265632] Call Trace:
[  720.265639]  [<ffffffff816b0755>] schedule+0x35/0x80
[  720.265642]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  720.265649]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  720.265652]  [<ffffffff810d1de5>] percpu_down_read+0x35/0x50
[  720.265656]  [<ffffffff812174fc>] __sb_start_write+0x2c/0x40
[  720.265660]  [<ffffffff812125d9>] do_sys_ftruncate.constprop.16+0xc9/0x160
[  720.265665]  [<ffffffff812126ae>] SyS_ftruncate+0xe/0x10
[  720.265669]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  720.265672]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  720.265676] INFO: task xfs_io:12946 blocked for more than 120 seconds.
[  720.267098]       Not tainted 4.7.0-rc4+ #13
[  720.268120] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  720.269897] xfs_io          D ffff88006b8ebb20     0 12946  12942 0x00000080
[  720.269903]  ffff88006b8ebb20 0000000000000000 ffff880077fb8000 ffff880074b53d88
[  720.269906]  ffff88006b8ec000 ffff880074eee3e8 fffffffeffffffff ffff880074eee400
[  720.269909]  0000000000000001 ffff88006b8ebb38 ffffffff816b0755 ffff880077fb8000
[  720.269912] Call Trace:
[  720.269919]  [<ffffffff816b0755>] schedule+0x35/0x80
[  720.269923]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  720.269927]  [<ffffffff811901e1>] ? __filemap_fdatawrite_range+0xd1/0x100
[  720.269931]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  720.269954]  [<ffffffffa06821fc>] ? btrfs_alloc_block_rsv+0x2c/0xb0 [btrfs]
[  720.269960]  [<ffffffff810d1de5>] percpu_down_read+0x35/0x50
[  720.269963]  [<ffffffff812174fc>] __sb_start_write+0x2c/0x40
[  720.269982]  [<ffffffffa069e5b5>] start_transaction+0x2a5/0x4d0 [btrfs]
[  720.269999]  [<ffffffffa069e837>] btrfs_join_transaction+0x17/0x20 [btrfs]
[  720.270023]  [<ffffffffa06aaa04>] btrfs_evict_inode+0x3c4/0x5d0 [btrfs]
[  720.270036]  [<ffffffff81230c7a>] evict+0xba/0x1a0
[  720.270039]  [<ffffffff81231916>] iput+0x196/0x200
[  720.270055]  [<ffffffffa06a41a0>] btrfs_run_delayed_iputs+0x70/0xc0 [btrfs]
[  720.270071]  [<ffffffffa069e1b8>] btrfs_commit_transaction+0x928/0xa80 [btrfs]
[  720.270085]  [<ffffffffa0669060>] btrfs_freeze+0x30/0x40 [btrfs]
[  720.270090]  [<ffffffff81217740>] freeze_super+0xf0/0x190
[  720.270094]  [<ffffffff81228b15>] do_vfs_ioctl+0x4a5/0x5c0
[  720.270097]  [<ffffffff81003276>] ? do_audit_syscall_entry+0x66/0x70
[  720.270101]  [<ffffffff810037cf>] ? syscall_trace_enter_phase1+0x11f/0x140
[  720.270105]  [<ffffffff81228ca9>] SyS_ioctl+0x79/0x90
[  720.270108]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  720.270111]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  840.270110] INFO: task fsstress:12881 blocked for more than 120 seconds.
[  840.270648]       Not tainted 4.7.0-rc4+ #13
[  840.270985] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  840.271588] fsstress        D ffff880077f0bdd0     0 12881  12880 0x00000080
[  840.271591]  ffff880077f0bdd0 ffff880073a3ace8 ffff88003414ab80 ffff88007515c000
[  840.271593]  ffff880077f0c000 ffff880074eee070 ffffffffffffffff ffff880074eee088
[  840.271595]  ffffffff81248600 ffff880077f0bde8 ffffffff816b0755 ffff88003414ab80
[  840.271596] Call Trace:
[  840.271602]  [<ffffffff81248600>] ? do_fsync+0x70/0x70
[  840.271605]  [<ffffffff816b0755>] schedule+0x35/0x80
[  840.271607]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  840.271611]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  840.271613]  [<ffffffff816b27f0>] down_read+0x20/0x30
[  840.271615]  [<ffffffff81218962>] iterate_supers+0xa2/0x110
[  840.271617]  [<ffffffff81248724>] sys_sync+0x54/0xb0
[  840.271619]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  840.271621]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  840.271623] INFO: task fsstress:12882 blocked for more than 120 seconds.
[  840.272137]       Not tainted 4.7.0-rc4+ #13
[  840.272440] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  840.272989] fsstress        D ffff88006c933dd0     0 12882  12880 0x00000080
[  840.272991]  ffff88006c933dd0 ffff880074eee088 ffff880034158000 ffff88006c933db0
[  840.272993]  ffff88006c934000 ffff880074eee070 ffffffffffffffff ffff880074eee088
[  840.272994]  ffffffff81248600 ffff88006c933de8 ffffffff816b0755 ffff880034158000
[  840.272996] Call Trace:
[  840.272999]  [<ffffffff81248600>] ? do_fsync+0x70/0x70
[  840.273001]  [<ffffffff816b0755>] schedule+0x35/0x80
[  840.273002]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  840.273005]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  840.273006]  [<ffffffff816b27f0>] down_read+0x20/0x30
[  840.273009]  [<ffffffff81218962>] iterate_supers+0xa2/0x110
[  840.273010]  [<ffffffff81248724>] sys_sync+0x54/0xb0
[  840.273012]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  840.273024]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  840.273025] INFO: task fstest:12924 blocked for more than 120 seconds.
[  840.273485]       Not tainted 4.7.0-rc4+ #13
[  840.273788] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  840.274341] fstest          D ffff880074c07ba0     0 12924  12923 0x00000080
[  840.274343]  ffff880074c07ba0 ffffffff8109fc72 ffff880077fbc140 ffff880074c07db0
[  840.274344]  ffff880074c08000 ffff880074eee2c8 fffffffeffffffff ffff880074eee2e0
[  840.274346]  ffff880074c07db0 ffff880074c07bb8 ffffffff816b0755 ffff880077fbc140
[  840.274347] Call Trace:
[  840.274350]  [<ffffffff8109fc72>] ? insert_work+0x62/0xa0
[  840.274352]  [<ffffffff816b0755>] schedule+0x35/0x80
[  840.274354]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  840.274356]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  840.274359]  [<ffffffff810d1de5>] percpu_down_read+0x35/0x50
[  840.274361]  [<ffffffff812174fc>] __sb_start_write+0x2c/0x40
[  840.274362]  [<ffffffff81236584>] mnt_want_write+0x24/0x50
[  840.274364]  [<ffffffff8122376d>] path_openat+0x85d/0x1370
[  840.274367]  [<ffffffff810f10d3>] ? current_fs_time+0x23/0x30
[  840.274369]  [<ffffffff81232301>] ? touch_atime+0x31/0xd0
[  840.274372]  [<ffffffff81190f94>] ? generic_file_read_iter+0x604/0x7b0
[  840.274373]  [<ffffffff812254d1>] do_filp_open+0x91/0x100
[  840.274375]  [<ffffffff813502f4>] ? lockref_put_or_lock+0x44/0x70
[  840.274377]  [<ffffffff81233876>] ? __alloc_fd+0x46/0x180
[  840.274379]  [<ffffffff81213724>] do_sys_open+0x124/0x210
[  840.274380]  [<ffffffff8121382e>] SyS_open+0x1e/0x20
[  840.274384]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  840.274385]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  840.274387] INFO: task fstest:12925 blocked for more than 120 seconds.
[  840.274849]       Not tainted 4.7.0-rc4+ #13
[  840.275172] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  840.275727] fstest          D ffff880074c0bdd0     0 12925  12923 0x00000080
[  840.275729]  ffff880074c0bdd0 0000000000a44010 ffff880077fb95c0 ffff880074c0beb0
[  840.275730]  ffff880074c0c000 ffff880074eee2c8 ffffffffffffffff ffff880074eee2e0
[  840.275732]  ffff8800739fa600 ffff880074c0bde8 ffffffff816b0755 ffff880077fb95c0
[  840.275733] Call Trace:
[  840.275735]  [<ffffffff816b0755>] schedule+0x35/0x80
[  840.275737]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  840.275739]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  840.275741]  [<ffffffff810d1de5>] percpu_down_read+0x35/0x50
[  840.275743]  [<ffffffff812174fc>] __sb_start_write+0x2c/0x40
[  840.275745]  [<ffffffff812125d9>] do_sys_ftruncate.constprop.16+0xc9/0x160
[  840.275752]  [<ffffffff812126ae>] SyS_ftruncate+0xe/0x10
[  840.275755]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  840.275756]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25
[  840.275768] INFO: task xfs_io:12946 blocked for more than 120 seconds.
[  840.276239]       Not tainted 4.7.0-rc4+ #13
[  840.276553] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  840.277106] xfs_io          D ffff88006b8ebb20     0 12946  12942 0x00000080
[  840.277107]  ffff88006b8ebb20 0000000000000000 ffff880077fb8000 ffff880074b53d88
[  840.277109]  ffff88006b8ec000 ffff880074eee3e8 fffffffeffffffff ffff880074eee400
[  840.277110]  0000000000000001 ffff88006b8ebb38 ffffffff816b0755 ffff880077fb8000
[  840.277112] Call Trace:
[  840.277124]  [<ffffffff816b0755>] schedule+0x35/0x80
[  840.277126]  [<ffffffff816b2f12>] rwsem_down_read_failed+0xf2/0x140
[  840.277128]  [<ffffffff811901e1>] ? __filemap_fdatawrite_range+0xd1/0x100
[  840.277130]  [<ffffffff8134fd58>] call_rwsem_down_read_failed+0x18/0x30
[  840.277148]  [<ffffffffa06821fc>] ? btrfs_alloc_block_rsv+0x2c/0xb0 [btrfs]
[  840.277149]  [<ffffffff810d1de5>] percpu_down_read+0x35/0x50
[  840.277151]  [<ffffffff812174fc>] __sb_start_write+0x2c/0x40
[  840.277161]  [<ffffffffa069e5b5>] start_transaction+0x2a5/0x4d0 [btrfs]
[  840.277171]  [<ffffffffa069e837>] btrfs_join_transaction+0x17/0x20 [btrfs]
[  840.277180]  [<ffffffffa06aaa04>] btrfs_evict_inode+0x3c4/0x5d0 [btrfs]
[  840.277182]  [<ffffffff81230c7a>] evict+0xba/0x1a0
[  840.277183]  [<ffffffff81231916>] iput+0x196/0x200
[  840.277191]  [<ffffffffa06a41a0>] btrfs_run_delayed_iputs+0x70/0xc0 [btrfs]
[  840.277199]  [<ffffffffa069e1b8>] btrfs_commit_transaction+0x928/0xa80 [btrfs]
[  840.277206]  [<ffffffffa0669060>] btrfs_freeze+0x30/0x40 [btrfs]
[  840.277208]  [<ffffffff81217740>] freeze_super+0xf0/0x190
[  840.277210]  [<ffffffff81228b15>] do_vfs_ioctl+0x4a5/0x5c0
[  840.277212]  [<ffffffff81003276>] ? do_audit_syscall_entry+0x66/0x70
[  840.277214]  [<ffffffff810037cf>] ? syscall_trace_enter_phase1+0x11f/0x140
[  840.277216]  [<ffffffff81228ca9>] SyS_ioctl+0x79/0x90
[  840.277218]  [<ffffffff81003b12>] do_syscall_64+0x62/0x110
[  840.277219]  [<ffffffff816b4561>] entry_SYSCALL64_slow_path+0x25/0x25

^ permalink raw reply	[flat|nested] only message in thread

only message in thread, other threads:[~2016-06-24  2:29 UTC | newest]

Thread overview: (only message) (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2016-06-24  2:28 fstests generic/068 hang 120seconds Wang Xiaoguang

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).