Possible recursive locking detected with XFS

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



I've just got it while running "dbench 200" over a XFS mounted partition. Kernel is 2.6.23. See the attachment.

Regards,
Vlad
Dec 13 16:17:20 tst kernel: [    0.000000] Linux version 2.6.23-dbg (v@ws) (gcc version 4.1.1 20070105 (Red Hat 4.1.1-51)) #17 SMP PREEMPT Thu Oct 25 22:19:38 MSD 2007
Dec 13 16:17:20 tst kernel: [    0.000000] BIOS-provided physical RAM map:
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 00000000000e0000 - 0000000000100000 (reserved)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 0000000000100000 - 000000007fff0000 (usable)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 000000007fff0000 - 000000007ffff000 (ACPI data)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 000000007ffff000 - 0000000080000000 (ACPI NVS)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 00000000fec00000 - 00000000fed00000 (reserved)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
Dec 13 16:17:20 tst kernel: [    0.000000]  BIOS-e820: 00000000fff80000 - 0000000100000000 (reserved)
Dec 13 16:17:20 tst kernel: [    0.000000] 2047MB LOWMEM available.
Dec 13 16:17:20 tst kernel: [    0.000000] found SMP MP-table at 000ff780
Dec 13 16:17:20 tst kernel: [    0.000000] Zone PFN ranges:
Dec 13 16:17:20 tst kernel: [    0.000000]   DMA             0 ->     4096
Dec 13 16:17:20 tst kernel: [    0.000000]   Normal       4096 ->   524272
Dec 13 16:17:20 tst kernel: [    0.000000] Movable zone start PFN for each node
Dec 13 16:17:20 tst kernel: [    0.000000] early_node_map[1] active PFN ranges
Dec 13 16:17:20 tst kernel: [    0.000000]     0:        0 ->   524272
Dec 13 16:17:20 tst kernel: [    0.000000] DMI 2.3 present.
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: RSDP 000F5070, 0014 (r0 ACPIAM)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: RSDT 7FFF0000, 0030 (r1 A M I  OEMRSDT   9000318 MSFT       97)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: FACP 7FFF0200, 0081 (r2 A M I  OEMFACP   9000318 MSFT       97)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: DSDT 7FFF0420, 2CB5 (r1  0ABBP 0ABBP004        4 INTL  2002026)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: FACS 7FFFF000, 0040
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: APIC 7FFF0390, 0084 (r1 A M I  OEMAPIC   9000318 MSFT       97)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: OEMB 7FFFF040, 0040 (r1 A M I  AMI_OEM   9000318 MSFT       97)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: PM-Timer IO Port: 0x408
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
Dec 13 16:17:20 tst kernel: [    0.000000] Processor #0 15:2 APIC version 20
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled)
Dec 13 16:17:20 tst kernel: [    0.000000] Processor #1 15:2 APIC version 20
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x82] disabled)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: LAPIC (acpi_id[0x04] lapic_id[0x83] disabled)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0])
Dec 13 16:17:20 tst kernel: [    0.000000] IOAPIC[0]: apic_id 2, version 32, address 0xfec00000, GSI 0-23
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: IOAPIC (id[0x03] address[0xfec80000] gsi_base[24])
Dec 13 16:17:20 tst kernel: [    0.000000] IOAPIC[1]: apic_id 3, version 32, address 0xfec80000, GSI 24-47
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: IOAPIC (id[0x04] address[0xfec80400] gsi_base[48])
Dec 13 16:17:20 tst kernel: [    0.000000] IOAPIC[2]: apic_id 4, version 32, address 0xfec80400, GSI 48-71
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
Dec 13 16:17:20 tst kernel: [    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
Dec 13 16:17:20 tst kernel: [    0.000000] Enabling APIC mode:  Flat.  Using 3 I/O APICs
Dec 13 16:17:20 tst kernel: [    0.000000] Using ACPI (MADT) for SMP configuration information
Dec 13 16:17:20 tst kernel: [    0.000000] Allocating PCI resources starting at 88000000 (gap: 80000000:7ec00000)
Dec 13 16:17:20 tst kernel: [    0.000000] Built 1 zonelists in Zone order.  Total pages: 516081
Dec 13 16:17:20 tst kernel: [    0.000000] Kernel command line: auto BOOT_IMAGE=2.6.23d ro root=301 nmi_watchdog=1 resume=/dev/hdc1 console=ttyS0,115200n8
Dec 13 16:17:20 tst kernel: [    0.000000] Enabling fast FPU save and restore... done.
Dec 13 16:17:20 tst kernel: [    0.000000] Enabling unmasked SIMD FPU exception support... done.
Dec 13 16:17:20 tst kernel: [    0.000000] Initializing CPU#0
Dec 13 16:17:20 tst kernel: [    0.000000] CPU 0 irqstacks, hard=78516000 soft=7850e000
Dec 13 16:17:20 tst kernel: [    0.000000] PID hash table entries: 4096 (order: 12, 16384 bytes)
Dec 13 16:17:20 tst kernel: [    0.000000] Detected 2396.038 MHz processor.
Dec 13 16:17:20 tst kernel: [   53.344012] Console: colour VGA+ 80x25
Dec 13 16:17:20 tst kernel: [   53.344040] console [ttyS0] enabled
Dec 13 16:17:20 tst kernel: [   53.662188] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
Dec 13 16:17:20 tst kernel: [   53.669918] ... MAX_LOCKDEP_SUBCLASSES:    8
Dec 13 16:17:20 tst kernel: [   53.674177] ... MAX_LOCK_DEPTH:          30
Dec 13 16:17:20 tst kernel: [   53.678350] ... MAX_LOCKDEP_KEYS:        2048
Dec 13 16:17:20 tst kernel: [   53.682695] ... CLASSHASH_SIZE:           1024
Dec 13 16:17:20 tst kernel: [   53.687127] ... MAX_LOCKDEP_ENTRIES:     8192
Dec 13 16:17:20 tst kernel: [   53.691553] ... MAX_LOCKDEP_CHAINS:      16384
Dec 13 16:17:20 tst kernel: [   53.695983] ... CHAINHASH_SIZE:          8192
Dec 13 16:17:20 tst kernel: [   53.700330]  memory used by lock dependency info: 1024 kB
Dec 13 16:17:20 tst kernel: [   53.705714]  per task-struct memory footprint: 1680 bytes
Dec 13 16:17:20 tst kernel: [   53.711100] ------------------------
Dec 13 16:17:20 tst kernel: [   53.714666] | Locking API testsuite:
Dec 13 16:17:20 tst kernel: [   53.718234] ----------------------------------------------------------------------------
Dec 13 16:17:20 tst kernel: [   53.726302]                                  | spin |wlock |rlock |mutex | wsem | rsem |
Dec 13 16:17:20 tst kernel: [   53.734467]   --------------------------------------------------------------------------
Dec 13 16:17:20 tst kernel: [   53.742548]                      A-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.751347]                  A-B-B-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.760108]              A-B-B-C-C-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.768896]              A-B-C-A-B-C deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.777683]          A-B-B-C-C-D-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.786505]          A-B-C-D-B-D-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.795326]          A-B-C-D-B-C-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.804139]                     double unlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.812874]                   initialize held:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.821609]                  bad unlock order:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.830370]   --------------------------------------------------------------------------
Dec 13 16:17:20 tst kernel: [   53.838560]               recursive read-lock:             |  ok  |             |  ok  |
Dec 13 16:17:20 tst kernel: [   53.846887]            recursive read-lock #2:             |  ok  |             |  ok  |
Dec 13 16:17:20 tst kernel: [   53.855216]             mixed read-write-lock:             |  ok  |             |  ok  |
Dec 13 16:17:20 tst kernel: [   53.863553]             mixed write-read-lock:             |  ok  |             |  ok  |
Dec 13 16:17:20 tst kernel: [   53.871881]   --------------------------------------------------------------------------
Dec 13 16:17:20 tst kernel: [   53.879950]      hard-irqs-on + irq-safe-A/12:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.886555]      soft-irqs-on + irq-safe-A/12:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.893161]      hard-irqs-on + irq-safe-A/21:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.899758]      soft-irqs-on + irq-safe-A/21:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.906354]        sirq-safe-A => hirqs-on/12:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.912960]        sirq-safe-A => hirqs-on/21:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.919565]          hard-safe-A + irqs-on/12:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.926153]          soft-safe-A + irqs-on/12:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.932759]          hard-safe-A + irqs-on/21:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.939356]          soft-safe-A + irqs-on/21:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.946065]     hard-safe-A + unsafe-B #1/123:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.952671]     soft-safe-A + unsafe-B #1/123:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.959276]     hard-safe-A + unsafe-B #1/132:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.965882]     soft-safe-A + unsafe-B #1/132:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.972486]     hard-safe-A + unsafe-B #1/213:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.979092]     soft-safe-A + unsafe-B #1/213:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.985698]     hard-safe-A + unsafe-B #1/231:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.992364]     soft-safe-A + unsafe-B #1/231:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   53.998969]     hard-safe-A + unsafe-B #1/312:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.005574]     soft-safe-A + unsafe-B #1/312:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.012181]     hard-safe-A + unsafe-B #1/321:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.018785]     soft-safe-A + unsafe-B #1/321:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.025390]     hard-safe-A + unsafe-B #2/123:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.031996]     soft-safe-A + unsafe-B #2/123:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.038602]     hard-safe-A + unsafe-B #2/132:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.045207]     soft-safe-A + unsafe-B #2/132:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.051813]     hard-safe-A + unsafe-B #2/213:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.058418]     soft-safe-A + unsafe-B #2/213:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.065023]     hard-safe-A + unsafe-B #2/231:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.071629]     soft-safe-A + unsafe-B #2/231:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.078235]     hard-safe-A + unsafe-B #2/312:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.084841]     soft-safe-A + unsafe-B #2/312:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.091445]     hard-safe-A + unsafe-B #2/321:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.098094]     soft-safe-A + unsafe-B #2/321:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.104699]       hard-irq lock-inversion/123:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.111305]       soft-irq lock-inversion/123:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.117910]       hard-irq lock-inversion/132:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.124516]       soft-irq lock-inversion/132:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.131147]       hard-irq lock-inversion/213:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.137779]       soft-irq lock-inversion/213:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.144410]       hard-irq lock-inversion/231:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.151042]       soft-irq lock-inversion/231:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.157656]       hard-irq lock-inversion/312:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.164262]       soft-irq lock-inversion/312:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.170866]       hard-irq lock-inversion/321:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.177473]       soft-irq lock-inversion/321:  ok  |  ok  |  ok  |
Dec 13 16:17:20 tst kernel: [   54.184077]       hard-irq read-recursion/123:  ok  |
Dec 13 16:17:20 tst kernel: [   54.189247]       soft-irq read-recursion/123:  ok  |
Dec 13 16:17:20 tst kernel: [   54.194414]       hard-irq read-recursion/132:  ok  |
Dec 13 16:17:20 tst kernel: [   54.199643]       soft-irq read-recursion/132:  ok  |
Dec 13 16:17:20 tst kernel: [   54.204819]       hard-irq read-recursion/213:  ok  |
Dec 13 16:17:20 tst kernel: [   54.209989]       soft-irq read-recursion/213:  ok  |
Dec 13 16:17:20 tst kernel: [   54.215157]       hard-irq read-recursion/231:  ok  |
Dec 13 16:17:20 tst kernel: [   54.220325]       soft-irq read-recursion/231:  ok  |
Dec 13 16:17:20 tst kernel: [   54.225493]       hard-irq read-recursion/312:  ok  |
Dec 13 16:17:20 tst kernel: [   54.230662]       soft-irq read-recursion/312:  ok  |
Dec 13 16:17:20 tst kernel: [   54.235830]       hard-irq read-recursion/321:  ok  |
Dec 13 16:17:20 tst kernel: [   54.240999]       soft-irq read-recursion/321:  ok  |
Dec 13 16:17:20 tst kernel: [   54.246211] -------------------------------------------------------
Dec 13 16:17:20 tst kernel: [   54.252461] Good, all 218 testcases passed! |
Dec 13 16:17:20 tst kernel: [   54.256807] ---------------------------------
Dec 13 16:17:20 tst kernel: [   54.262293] Dentry cache hash table entries: 262144 (order: 8, 1048576 bytes)
Dec 13 16:17:20 tst kernel: [   54.271443] Inode-cache hash table entries: 131072 (order: 7, 524288 bytes)
Dec 13 16:17:20 tst kernel: [   54.359088] Memory: 2022124k/2097088k available (2463k kernel code, 74432k reserved, 1129k data, 524k init, 0k highmem)
Dec 13 16:17:20 tst kernel: [   54.369857] virtual kernel memory layout:
Dec 13 16:17:20 tst kernel: [   54.369858]     fixmap  : 0xfffb5000 - 0xfffff000   ( 296 kB)
Dec 13 16:17:20 tst kernel: [   54.369860]     vmalloc : 0xf8800000 - 0xfffb3000   ( 119 MB)
Dec 13 16:17:20 tst kernel: [   54.369861]     lowmem  : 0x78000000 - 0xf7ff0000   (2047 MB)
Dec 13 16:17:20 tst kernel: [   54.369862]       .init : 0x78488000 - 0x7850b000   ( 524 kB)
Dec 13 16:17:20 tst kernel: [   54.369863]       .data : 0x78367cf6 - 0x78482454   (1129 kB)
Dec 13 16:17:20 tst kernel: [   54.369865]       .text : 0x78100000 - 0x78367cf6   (2463 kB)
Dec 13 16:17:20 tst kernel: [   54.408257] Checking if this processor honours the WP bit even in supervisor mode... Ok.
Dec 13 16:17:20 tst kernel: [   54.476957] Calibrating delay using timer specific routine.. 4796.36 BogoMIPS (lpj=2398180)
Dec 13 16:17:20 tst kernel: [   54.485618] Mount-cache hash table entries: 512
Dec 13 16:17:20 tst kernel: [   54.491061] CPU: Trace cache: 12K uops, L1 D cache: 8K
Dec 13 16:17:20 tst kernel: [   54.496233] CPU: L2 cache: 512K
Dec 13 16:17:20 tst kernel: [   54.499384] CPU: Physical Processor ID: 0
Dec 13 16:17:20 tst kernel: [   54.503478] Intel machine check architecture supported.
Dec 13 16:17:20 tst kernel: [   54.508704] Intel machine check reporting enabled on CPU#0.
Dec 13 16:17:20 tst kernel: [   54.514277] CPU0: Intel P4/Xeon Extended MCE MSRs (12) available
Dec 13 16:17:20 tst kernel: [   54.520285] CPU0: Thermal monitoring enabled
Dec 13 16:17:20 tst kernel: [   54.524567] Compat vDSO mapped to ffffe000.
Dec 13 16:17:20 tst kernel: [   54.528765] Checking 'hlt' instruction... OK.
Dec 13 16:17:20 tst kernel: [   54.537264] lockdep: not fixing up alternatives.
Dec 13 16:17:20 tst kernel: [   54.541900] ACPI: Core revision 20070126
Dec 13 16:17:20 tst kernel: [   54.552016] CPU0: Intel(R) Xeon(TM) CPU 2.40GHz stepping 07
Dec 13 16:17:20 tst kernel: [   54.557743] lockdep: not fixing up alternatives.
Dec 13 16:17:20 tst kernel: [   54.562371] Booting processor 1/1 eip 2000
Dec 13 16:17:20 tst kernel: [   54.566473] CPU 1 irqstacks, hard=78517000 soft=7850f000
Dec 13 16:17:20 tst kernel: [   54.582033] Initializing CPU#1
Dec 13 16:17:20 tst kernel: [   54.642774] Calibrating delay using timer specific routine.. 4791.12 BogoMIPS (lpj=2395562)
Dec 13 16:17:20 tst kernel: [   54.642801] CPU: Trace cache: 12K uops, L1 D cache: 8K
Dec 13 16:17:20 tst kernel: [   54.642805] CPU: L2 cache: 512K
Dec 13 16:17:20 tst kernel: [   54.642808] CPU: Physical Processor ID: 0
Dec 13 16:17:20 tst kernel: [   54.642821] Intel machine check architecture supported.
Dec 13 16:17:20 tst kernel: [   54.642828] Intel machine check reporting enabled on CPU#1.
Dec 13 16:17:20 tst kernel: [   54.642832] CPU1: Intel P4/Xeon Extended MCE MSRs (12) available
Dec 13 16:17:20 tst kernel: [   54.642836] CPU1: Thermal monitoring enabled
Dec 13 16:17:20 tst kernel: [   54.643131] CPU1: Intel(R) Xeon(TM) CPU 2.40GHz stepping 07
Dec 13 16:17:20 tst kernel: [   54.693512] Total of 2 processors activated (9587.48 BogoMIPS).
Dec 13 16:17:20 tst kernel: [   54.699908] ENABLING IO-APIC IRQs
Dec 13 16:17:20 tst kernel: [   54.703511] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
Dec 13 16:17:20 tst kernel: [   54.820587] APIC timer registered as dummy, due to nmi_watchdog=1!
Dec 13 16:17:20 tst kernel: [   54.828039] checking TSC synchronization [CPU#0 -> CPU#1]: passed.
Dec 13 16:17:20 tst kernel: [   54.854258] Brought up 2 CPUs
Dec 13 16:17:20 tst kernel: [   54.857892] khelper used greatest stack depth: 3064 bytes left
Dec 13 16:17:20 tst kernel: [   54.863818] khelper used greatest stack depth: 3008 bytes left
Dec 13 16:17:20 tst kernel: [   54.870013] NET: Registered protocol family 16
Dec 13 16:17:20 tst kernel: [   54.875483] ACPI: bus type pci registered
Dec 13 16:17:20 tst kernel: [   54.879649] PCI: PCI BIOS revision 2.10 entry at 0xf0031, last bus=4
Dec 13 16:17:20 tst kernel: [   54.886012] PCI: Using configuration type 1
Dec 13 16:17:20 tst kernel: [   54.890211] Setting up standard PCI resources
Dec 13 16:17:20 tst kernel: [   54.943795] ACPI: Interpreter enabled
Dec 13 16:17:20 tst kernel: [   54.947479] ACPI: (supports S0 S5)
Dec 13 16:17:20 tst kernel: [   54.950978] ACPI: Using IOAPIC for interrupt routing
Dec 13 16:17:20 tst kernel: [   54.984730] ACPI: PCI Root Bridge [PCI0] (0000:00)
Dec 13 16:17:20 tst kernel: [   54.990548] PCI quirk: region 0400-047f claimed by ICH4 ACPI/GPIO/TCO
Dec 13 16:17:20 tst kernel: [   54.996994] PCI quirk: region 0500-053f claimed by ICH4 GPIO
Dec 13 16:17:20 tst kernel: [   55.005631] PCI: Transparent bridge - 0000:00:1e.0
Dec 13 16:17:20 tst kernel: [   55.019230] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 10 *11 12 14 15)
Dec 13 16:17:20 tst kernel: [   55.026987] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 9 10 11 12 14 15) *0, disabled.
Dec 13 16:17:20 tst kernel: [   55.035917] ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 *9 10 11 12 14 15)
Dec 13 16:17:20 tst kernel: [   55.043699] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 *5 6 7 9 10 11 12 14 15)
Dec 13 16:17:20 tst kernel: [   55.051449] ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 6 7 9 *10 11 12 14 15)
Dec 13 16:17:20 tst kernel: [   55.059200] ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 9 10 *11 12 14 15)
Dec 13 16:17:20 tst kernel: [   55.066943] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 9 10 11 12 14 15) *0, disabled.
Dec 13 16:17:20 tst kernel: [   55.075878] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 9 10 11 12 14 15) *0, disabled.
Dec 13 16:17:20 tst kernel: [   55.085090] Linux Plug and Play Support v0.97 (c) Adam Belay
Dec 13 16:17:20 tst kernel: [   55.090917] pnp: PnP ACPI init
Dec 13 16:17:20 tst kernel: [   55.094015] ACPI: bus type pnp registered
Dec 13 16:17:20 tst kernel: [   55.109861] pnp: PnP ACPI: found 14 devices
Dec 13 16:17:20 tst kernel: [   55.114054] ACPI: ACPI bus type pnp unregistered
Dec 13 16:17:20 tst kernel: [   55.119971] SCSI subsystem initialized
Dec 13 16:17:20 tst kernel: [   55.124378] usbcore: registered new interface driver usbfs
Dec 13 16:17:20 tst kernel: [   55.130233] usbcore: registered new interface driver hub
Dec 13 16:17:20 tst kernel: [   55.135840] usbcore: registered new device driver usb
Dec 13 16:17:20 tst kernel: [   55.141664] PCI: Using ACPI for IRQ routing
Dec 13 16:17:20 tst kernel: [   55.145864] PCI: If a device doesn't work, try "pci=routeirq".  If it helps, post a report
Dec 13 16:17:20 tst kernel: [   55.171434] Time: tsc clocksource has been installed.
Dec 13 16:17:20 tst kernel: [   55.179668] pnp: 00:09: iomem range 0xffa00000-0xffeffbff has been reserved
Dec 13 16:17:20 tst kernel: [   55.186642] pnp: 00:09: iomem range 0xfff00000-0xffffffff could not be reserved
Dec 13 16:17:20 tst kernel: [   55.193971] pnp: 00:0b: ioport range 0x680-0x6ff has been reserved
Dec 13 16:17:20 tst kernel: [   55.200177] pnp: 00:0c: iomem range 0xfec00000-0xfec00fff could not be reserved
Dec 13 16:17:20 tst kernel: [   55.207495] pnp: 00:0c: iomem range 0xfee00000-0xfee00fff could not be reserved
Dec 13 16:17:20 tst kernel: [   55.214825] pnp: 00:0d: iomem range 0x0-0x9ffff could not be reserved
Dec 13 16:17:20 tst kernel: [   55.221277] pnp: 00:0d: iomem range 0xc0000-0xdffff could not be reserved
Dec 13 16:17:20 tst kernel: [   55.228151] pnp: 00:0d: iomem range 0xe0000-0xfffff could not be reserved
Dec 13 16:17:20 tst kernel: [   55.234945] pnp: 00:0d: iomem range 0x100000-0x7fffffff could not be reserved
Dec 13 16:17:20 tst kernel: [   55.273920] PCI: Bridge: 0000:02:1d.0
Dec 13 16:17:20 tst kernel: [   55.277597]   IO window: a000-cfff
Dec 13 16:17:20 tst kernel: [   55.281020]   MEM window: fe700000-fe9fffff
Dec 13 16:17:20 tst kernel: [   55.285217]   PREFETCH window: ff800000-ff8fffff
Dec 13 16:17:20 tst kernel: [   55.289850] PCI: Bridge: 0000:02:1f.0
Dec 13 16:17:20 tst kernel: [   55.293525]   IO window: 9000-9fff
Dec 13 16:17:20 tst kernel: [   55.296949]   MEM window: fe600000-fe6fffff
Dec 13 16:17:20 tst kernel: [   55.301146]   PREFETCH window: ff700000-ff7fffff
Dec 13 16:17:20 tst kernel: [   55.305779] PCI: Bridge: 0000:00:02.0
Dec 13 16:17:20 tst kernel: [   55.309455]   IO window: 9000-cfff
Dec 13 16:17:20 tst kernel: [   55.312879]   MEM window: fe600000-feafffff
Dec 13 16:17:20 tst kernel: [   55.317075]   PREFETCH window: ff700000-ff9fffff
Dec 13 16:17:20 tst kernel: [   55.321717] PCI: Bridge: 0000:00:1e.0
Dec 13 16:17:20 tst kernel: [   55.325394]   IO window: 8000-8fff
Dec 13 16:17:20 tst kernel: [   55.328816]   MEM window: fc500000-fe5fffff
Dec 13 16:17:20 tst kernel: [   55.333013]   PREFETCH window: ff600000-ff6fffff
Dec 13 16:17:20 tst kernel: [   55.337831] NET: Registered protocol family 2
Dec 13 16:17:20 tst kernel: [   55.353425] IP route cache hash table entries: 65536 (order: 6, 262144 bytes)
Dec 13 16:17:20 tst kernel: [   55.361382] TCP established hash table entries: 65536 (order: 9, 2883584 bytes)
Dec 13 16:17:20 tst kernel: [   55.377484] TCP bind hash table entries: 65536 (order: 9, 2621440 bytes)
Dec 13 16:17:20 tst kernel: [   55.392412] TCP: Hash tables configured (established 65536 bind 65536)
Dec 13 16:17:20 tst kernel: [   55.398994] TCP reno registered
Dec 13 16:17:20 tst kernel: [   55.407856] Machine check exception polling timer started.
Dec 13 16:17:20 tst kernel: [   55.417278] Initializing RT-Tester: OK
Dec 13 16:17:20 tst kernel: [   55.421074] audit: initializing netlink socket (disabled)
Dec 13 16:17:20 tst kernel: [   55.426560] audit(1197562580.707:1): initialized
Dec 13 16:17:20 tst kernel: [   55.432376] VFS: Disk quotas dquot_6.5.1
Dec 13 16:17:20 tst kernel: [   55.436346] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Dec 13 16:17:20 tst kernel: [   55.443494] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
Dec 13 16:17:20 tst kernel: [   55.450902] io scheduler noop registered
Dec 13 16:17:20 tst kernel: [   55.454825] io scheduler anticipatory registered
Dec 13 16:17:20 tst kernel: [   55.459441] io scheduler deadline registered (default)
Dec 13 16:17:20 tst kernel: [   55.464654] io scheduler cfq registered
Dec 13 16:17:20 tst kernel: [   55.470663] input: Power Button (FF) as /devices/virtual/input/input0
Dec 13 16:17:20 tst kernel: [   55.477136] ACPI: Power Button (FF) [PWRF]
Dec 13 16:17:20 tst kernel: [   55.481603] input: Power Button (CM) as /devices/virtual/input/input1
Dec 13 16:17:20 tst kernel: [   55.488053] ACPI: Power Button (CM) [PWRB]
Dec 13 16:17:20 tst kernel: [   55.492466] input: Sleep Button (CM) as /devices/virtual/input/input2
Dec 13 16:17:20 tst kernel: [   55.498913] ACPI: Sleep Button (CM) [SLPB]
Dec 13 16:17:20 tst kernel: [   55.503825] ACPI: Processor [CPU1] (supports 8 throttling states)
Dec 13 16:17:20 tst kernel: [   55.510039] ACPI: Processor [CPU2] (supports 8 throttling states)
Dec 13 16:17:20 tst kernel: [   55.516225] ACPI Exception (processor_core-0818): AE_NOT_FOUND, Processor Device is not present [20070126]
Dec 13 16:17:20 tst kernel: [   55.525964] ACPI Exception (processor_core-0818): AE_NOT_FOUND, Processor Device is not present [20070126]
Dec 13 16:17:20 tst kernel: [   55.671419] Real Time Clock Driver v1.12ac
Dec 13 16:17:20 tst kernel: [   55.675711] intel_rng: FWH not detected
Dec 13 16:17:20 tst kernel: [   55.679676] Linux agpgart interface v0.102
Dec 13 16:17:20 tst kernel: [   55.684080] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
Dec 13 16:17:20 tst kernel: [   55.692034] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Dec 13 16:17:20 tst kernel: [   55.698548] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
Dec 13 16:17:20 tst kernel: [   55.706408] 00:05: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Dec 13 16:17:20 tst kernel: [   55.712863] 00:06: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
Dec 13 16:17:20 tst kernel: [   55.719658] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
Dec 13 16:17:20 tst kernel: [   55.726017] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
Dec 13 16:17:20 tst kernel: [   55.734239] ICH3: IDE controller at PCI slot 0000:00:1f.1
Dec 13 16:17:20 tst kernel: [   55.739652] PCI: Enabling device 0000:00:1f.1 (0005 -> 0007)
Dec 13 16:17:20 tst kernel: [   55.745325] ACPI: PCI Interrupt 0000:00:1f.1[A] -> GSI 18 (level, low) -> IRQ 16
Dec 13 16:17:20 tst kernel: [   55.752751] ICH3: chipset revision 2
Dec 13 16:17:20 tst kernel: [   55.756330] ICH3: not 100% native mode: will probe irqs later
Dec 13 16:17:20 tst kernel: [   55.762092]     ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:pio
Dec 13 16:17:20 tst kernel: [   55.769371]     ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:DMA, hdd:pio
Dec 13 16:17:20 tst kernel: [   55.867687] Clockevents: could not switch to one-shot mode:<6>Clockevents: could not switch to one-shot mode: lapic is not functional.
Dec 13 16:17:20 tst kernel: [   55.867698] Could not switch to high resolution mode on CPU 1
Dec 13 16:17:20 tst kernel: [   55.885499]  lapic is not functional.
Dec 13 16:17:20 tst kernel: [   55.889171] Could not switch to high resolution mode on CPU 0
Dec 13 16:17:20 tst kernel: [   56.064662] hda: QUANTUM FIREBALLP AS20.5, ATA DISK drive
Dec 13 16:17:20 tst kernel: [   56.681391] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
Dec 13 16:17:20 tst kernel: [   56.955701] hdc: QUANTUM FIREBALLP LM20.5, ATA DISK drive
Dec 13 16:17:20 tst kernel: [   57.572527] ide1 at 0x170-0x177,0x376 on irq 15
Dec 13 16:17:20 tst kernel: [   57.584630] hda: max request size: 128KiB
Dec 13 16:17:20 tst kernel: [   57.588869] hda: 40132503 sectors (20547 MB) w/1902KiB Cache, CHS=39813/16/63, UDMA(100)
Dec 13 16:17:20 tst kernel: [   57.597080] hda: cache flushes not supported
Dec 13 16:17:20 tst kernel: [   57.601507]  hda: hda1 hda2
Dec 13 16:17:20 tst kernel: [   57.611845] khelper used greatest stack depth: 2940 bytes left
Dec 13 16:17:20 tst kernel: [   57.612442] hdc: max request size: 128KiB
Dec 13 16:17:20 tst kernel: [   57.612746] hdc: 40132503 sectors (20547 MB) w/1900KiB Cache, CHS=39813/16/63, UDMA(66)
Dec 13 16:17:20 tst kernel: [   57.612756] hdc: cache flushes not supported
Dec 13 16:17:20 tst kernel: [   57.612920]  hdc: hdc1 hdc2
Dec 13 16:17:20 tst kernel: [   57.637982] ACPI: PCI Interrupt 0000:04:03.0[A] -> GSI 50 (level, low) -> IRQ 17
Dec 13 16:17:20 tst kernel: [   72.747542] scsi0 : Adaptec AIC79XX PCI-X SCSI HBA DRIVER, Rev 3.0
Dec 13 16:17:20 tst kernel: [   72.747545]         <Adaptec AIC7902 Ultra320 SCSI adapter>
Dec 13 16:17:20 tst kernel: [   72.747546]         aic7902: Ultra320 Wide Channel A, SCSI Id=7, PCI-X 67-100Mhz, 512 SCBs
Dec 13 16:17:20 tst kernel: [   72.768360] ACPI: PCI Interrupt 0000:04:03.1[B] -> GSI 51 (level, low) -> IRQ 18
Dec 13 16:17:20 tst kernel: [   76.631364] scsi_scan_0 used greatest stack depth: 2520 bytes left
Dec 13 16:17:20 tst kernel: [   87.882196] scsi1 : Adaptec AIC79XX PCI-X SCSI HBA DRIVER, Rev 3.0
Dec 13 16:17:20 tst kernel: [   87.882198]         <Adaptec AIC7902 Ultra320 SCSI adapter>
Dec 13 16:17:20 tst kernel: [   87.882200]         aic7902: Ultra320 Wide Channel B, SCSI Id=7, PCI-X 67-100Mhz, 512 SCBs
Dec 13 16:17:20 tst kernel: [   87.904660] PNP: PS/2 Controller [PNP0f03:PS2M] at 0x60,0x64 irq 12
Dec 13 16:17:20 tst kernel: [   87.904825] scsi 1:0:0:0: Direct-Access     SEAGATE  ST373455LW       0003 PQ: 0 ANSI: 3
Dec 13 16:17:20 tst kernel: [   87.904849]  target1:0:0: asynchronous
Dec 13 16:17:20 tst kernel: [   87.904852] scsi1:A:0:0: Tagged Queuing enabled.  Depth 32
Dec 13 16:17:20 tst kernel: [   87.904944]  target1:0:0: Beginning Domain Validation
Dec 13 16:17:20 tst kernel: [   87.907862]  target1:0:0: wide asynchronous
Dec 13 16:17:20 tst kernel: [   87.910049]  target1:0:0: FAST-160 WIDE SCSI 320.0 MB/s DT IU QAS RTI WRFLOW PCOMP (6.25 ns, offset 63)
Dec 13 16:17:20 tst kernel: [   87.946799] PNP: PS/2 controller doesn't have KBD irq; using default 1
Dec 13 16:17:20 tst kernel: [   87.955382] serio: i8042 KBD port at 0x60,0x64 irq 1
Dec 13 16:17:20 tst kernel: [   87.960375] serio: i8042 AUX port at 0x60,0x64 irq 12
Dec 13 16:17:20 tst kernel: [   87.965732] mice: PS/2 mouse device common for all mice
Dec 13 16:17:20 tst kernel: [   87.994346]  target1:0:0: Ending Domain Validation
Dec 13 16:17:20 tst kernel: [   88.219243] md: raid0 personality registered for level 0
Dec 13 16:17:20 tst kernel: [   88.224562] EDAC MC: Ver: 2.1.0 Oct 19 2007
Dec 13 16:17:20 tst kernel: [   88.229968] EDAC e7xxx: error reporting device not found:vendor 8086 device 0x2541 (broken BIOS?)
Dec 13 16:17:20 tst kernel: [   88.241336] TCP bic registered
Dec 13 16:17:20 tst kernel: [   88.244449] NET: Registered protocol family 1
Dec 13 16:17:20 tst kernel: [   88.248983] NET: Registered protocol family 10
Dec 13 16:17:20 tst kernel: [   88.253754] lo: Disabled Privacy Extensions
Dec 13 16:17:20 tst kernel: [   88.258113] NET: Registered protocol family 17
Dec 13 16:17:20 tst kernel: [   88.262584] Testing NMI watchdog ... OK.
Dec 13 16:17:20 tst kernel: [   88.287453] Starting balanced_irq
Dec 13 16:17:20 tst kernel: [   88.290949] Using IPI No-Shortcut mode
Dec 13 16:17:20 tst kernel: [   88.295710] scsi: waiting for bus probes to complete ...
Dec 13 16:17:20 tst kernel: [   91.635528] sd 1:0:0:0: [sda] 143374744 512-byte hardware sectors (73408 MB)
Dec 13 16:17:20 tst kernel: [   91.643690] sd 1:0:0:0: [sda] Write Protect is off
Dec 13 16:17:20 tst kernel: [   91.650350] sd 1:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
Dec 13 16:17:20 tst kernel: [   91.659576] sd 1:0:0:0: [sda] 143374744 512-byte hardware sectors (73408 MB)
Dec 13 16:17:20 tst kernel: [   91.667738] sd 1:0:0:0: [sda] Write Protect is off
Dec 13 16:17:20 tst kernel: [   91.674363] sd 1:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
Dec 13 16:17:20 tst kernel: [   91.682900]  sda: sda1 sda2 sda3 sda4 < sda5 >
Dec 13 16:17:20 tst kernel: [   91.701403] sd 1:0:0:0: [sda] Attached SCSI disk
Dec 13 16:17:20 tst kernel: [   91.706633] scsi_scan_1 used greatest stack depth: 1924 bytes left
Dec 13 16:17:20 tst kernel: [   91.707350] md: Autodetecting RAID arrays.
Dec 13 16:17:20 tst kernel: [   91.748018] md: autorun ...
Dec 13 16:17:20 tst kernel: [   91.750828] md: considering hdc2 ...
Dec 13 16:17:20 tst kernel: [   91.754445] md:  adding hdc2 ...
Dec 13 16:17:20 tst kernel: [   91.757715] md:  adding hda2 ...
Dec 13 16:17:20 tst kernel: [   91.761005] md: created md0
Dec 13 16:17:20 tst kernel: [   91.763816] md: bind<hda2>
Dec 13 16:17:20 tst kernel: [   91.766610] md: bind<hdc2>
Dec 13 16:17:20 tst kernel: [   91.769374] md: running: <hdc2><hda2>
Dec 13 16:17:20 tst kernel: [   91.773408] md0: setting max_sectors to 8, segment boundary to 2047
Dec 13 16:17:20 tst kernel: [   91.779679] blk_queue_segment_boundary: set to minimum fff
Dec 13 16:17:20 tst kernel: [   91.785167] raid0: looking at hdc2
Dec 13 16:17:20 tst kernel: [   91.788576] raid0:   comparing hdc2(18065024) with hdc2(18065024)
Dec 13 16:17:20 tst kernel: [   91.794687] raid0:   END
Dec 13 16:17:20 tst kernel: [   91.797223] raid0:   ==> UNIQUE
Dec 13 16:17:20 tst kernel: [   91.800366] raid0: 1 zones
Dec 13 16:17:20 tst kernel: [   91.803075] raid0: looking at hda2
Dec 13 16:17:20 tst kernel: [   91.806479] raid0:   comparing hda2(18065024) with hdc2(18065024)
Dec 13 16:17:20 tst kernel: [   91.812591] raid0:   EQUAL
Dec 13 16:17:20 tst kernel: [   91.815300] raid0: FINAL 1 zones
Dec 13 16:17:20 tst kernel: [   91.818531] raid0: done.
Dec 13 16:17:20 tst kernel: [   91.821075] raid0 : md_size is 36130048 blocks.
Dec 13 16:17:20 tst kernel: [   91.825612] raid0 : conf->hash_spacing is 36130048 blocks.
Dec 13 16:17:20 tst kernel: [   91.831100] raid0 : nb_zone is 1.
Dec 13 16:17:20 tst kernel: [   91.834416] raid0 : Allocating 4 bytes for hash.
Dec 13 16:17:20 tst kernel: [   91.839254] md: ... autorun DONE.
Dec 13 16:17:20 tst kernel: [   91.876228] kjournald starting.  Commit interval 5 seconds
Dec 13 16:17:20 tst kernel: [   91.876349] EXT3-fs: mounted filesystem with ordered data mode.
Dec 13 16:17:20 tst kernel: [   91.876402] VFS: Mounted root (ext3 filesystem) readonly.
Dec 13 16:17:20 tst kernel: [   91.877172] Freeing unused kernel memory: 524k freed
Dec 13 16:17:20 tst kernel: [   91.877244] Write protecting the kernel read-only data: 875k
Dec 13 16:17:20 tst kernel: [   92.655158] mount used greatest stack depth: 1680 bytes left
Dec 13 16:17:20 tst kernel: [   92.792468] awk used greatest stack depth: 1600 bytes left
Dec 13 16:17:20 tst kernel: [   95.049623] ACPI: PCI Interrupt 0000:00:1f.3[B] -> GSI 17 (level, low) -> IRQ 19
Dec 13 16:17:20 tst kernel: [   95.347541] Intel(R) PRO/1000 Network Driver - version 7.3.20-k2-NAPI
Dec 13 16:17:20 tst kernel: [   95.347549] Copyright (c) 1999-2006 Intel Corporation.
Dec 13 16:17:20 tst kernel: [   95.347796] ACPI: PCI Interrupt 0000:03:01.0[A] -> GSI 28 (level, low) -> IRQ 20
Dec 13 16:17:20 tst kernel: [   95.446444] e1000: 0000:03:01.0: e1000_check_options: Interrupt Throttling Rate (ints/sec) turned off
Dec 13 16:17:20 tst kernel: [   95.446832] e1000: 0000:03:01.0: e1000_probe: (PCI:66MHz:32-bit) 00:30:48:72:50:f2
Dec 13 16:17:20 tst kernel: [   95.587888] e1000: eth0: e1000_probe: Intel(R) PRO/1000 Network Connection
Dec 13 16:17:20 tst kernel: [   95.588077] ACPI: PCI Interrupt 0000:03:02.0[A] -> GSI 29 (level, low) -> IRQ 21
Dec 13 16:17:20 tst kernel: [   95.893000] e1000: 0000:03:02.0: e1000_probe: (PCI:66MHz:32-bit) 00:30:48:72:50:f3
Dec 13 16:17:20 tst kernel: [   96.080088] e1000: eth1: e1000_probe: Intel(R) PRO/1000 Network Connection
Dec 13 16:17:20 tst kernel: [   96.981772] sd 1:0:0:0: Attached scsi generic sg0 type 0
Dec 13 16:17:20 tst kernel: [   96.990620] USB Universal Host Controller Interface driver v3.0
Dec 13 16:17:20 tst kernel: [   96.990879] ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 16 (level, low) -> IRQ 22
Dec 13 16:17:20 tst kernel: [   96.990920] uhci_hcd 0000:00:1d.0: UHCI Host Controller
Dec 13 16:17:20 tst kernel: [   96.992318] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 1
Dec 13 16:17:20 tst kernel: [   96.992476] uhci_hcd 0000:00:1d.0: irq 22, io base 0x0000e000
Dec 13 16:17:20 tst kernel: [   96.993506] usb usb1: configuration #1 chosen from 1 choice
Dec 13 16:17:20 tst kernel: [   96.993821] hub 1-0:1.0: USB hub found
Dec 13 16:17:20 tst kernel: [   96.993892] hub 1-0:1.0: 2 ports detected
Dec 13 16:17:20 tst kernel: [   97.115184] ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 19 (level, low) -> IRQ 23
Dec 13 16:17:20 tst kernel: [   97.115303] uhci_hcd 0000:00:1d.1: UHCI Host Controller
Dec 13 16:17:20 tst kernel: [   97.120103] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 2
Dec 13 16:17:20 tst kernel: [   97.120198] uhci_hcd 0000:00:1d.1: irq 23, io base 0x0000e400
Dec 13 16:17:20 tst kernel: [   97.121005] usb usb2: configuration #1 chosen from 1 choice
Dec 13 16:17:20 tst kernel: [   97.121260] hub 2-0:1.0: USB hub found
Dec 13 16:17:20 tst kernel: [   97.121305] hub 2-0:1.0: 2 ports detected
Dec 13 16:17:20 tst kernel: [   97.223882] ACPI: PCI Interrupt 0000:00:1d.2[C] -> GSI 18 (level, low) -> IRQ 16
Dec 13 16:17:20 tst kernel: [   97.223926] uhci_hcd 0000:00:1d.2: UHCI Host Controller
Dec 13 16:17:20 tst kernel: [   97.230639] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 3
Dec 13 16:17:20 tst kernel: [   97.230729] uhci_hcd 0000:00:1d.2: irq 16, io base 0x0000e800
Dec 13 16:17:20 tst kernel: [   97.234123] usb usb3: configuration #1 chosen from 1 choice
Dec 13 16:17:20 tst kernel: [   97.234965] hub 3-0:1.0: USB hub found
Dec 13 16:17:20 tst kernel: [   97.235020] hub 3-0:1.0: 2 ports detected
Dec 13 16:17:20 tst kernel: [   98.239871] FDC 0 is a post-1991 82077
Dec 13 16:17:20 tst kernel: [   98.262789] parport_pc 00:08: reported by Plug and Play ACPI
Dec 13 16:17:20 tst kernel: [   98.262983] parport0: PC-style at 0x378, irq 7 [PCSPP]
Dec 13 16:17:20 tst kernel: [   98.493450] md: Autodetecting RAID arrays.
Dec 13 16:17:20 tst kernel: [   98.493457] md: autorun ...
Dec 13 16:17:20 tst kernel: [   98.493459] md: ... autorun DONE.
Dec 13 16:17:20 tst kernel: [   98.550322] device-mapper: ioctl: 4.11.0-ioctl (2006-10-12) initialised: [email protected]
Dec 13 16:17:20 tst kernel: [   99.301348] EXT3 FS on hda1, internal journal
Dec 13 16:17:20 tst kernel: [   99.399597] kjournald starting.  Commit interval 5 seconds
Dec 13 16:17:20 tst kernel: [   99.399953] EXT3 FS on md0, internal journal
Dec 13 16:17:20 tst kernel: [   99.399971] EXT3-fs: mounted filesystem with ordered data mode.
Dec 13 16:17:20 tst kernel: [   99.601744] SGI XFS with ACLs, security attributes, realtime, no debug enabled
Dec 13 16:17:20 tst kernel: [   99.603273] SGI XFS Quota Management subsystem
Dec 13 16:17:20 tst kernel: [   99.620839] XFS mounting filesystem sda1
Dec 13 16:17:20 tst kernel: [   99.656581] kjournald starting.  Commit interval 5 seconds
Dec 13 16:17:20 tst kernel: [   99.656923] EXT3 FS on sda3, internal journal
Dec 13 16:17:20 tst kernel: [   99.656939] EXT3-fs: mounted filesystem with ordered data mode.
Dec 13 16:17:20 tst kernel: [  102.464324] Adding 1048568k swap on /boot/swapfile.  Priority:-1 extents:315 across:1962812k
Dec 13 16:17:20 tst kernel: [  102.649851] rc.sysinit used greatest stack depth: 1396 bytes left
Dec 13 16:17:20 tst kernel: [  104.271930] e1000: eth0: e1000_watchdog: NIC Link is Up 100 Mbps Full Duplex, Flow Control: RX/TX
Dec 13 16:17:20 tst kernel: [  108.740087] ADDRCONF(NETDEV_UP): eth1: link is not ready
Dec 13 16:17:21 tst kernel: [  113.812680] w83627hf: Found W83627HF chip at 0x290
Dec 13 16:17:26 tst kernel: [  118.791911] input: PC Speaker as /devices/platform/pcspkr/input/input3
Dec 13 16:17:26 tst kernel: [  118.810752] RAMDISK driver initialized: 1 RAM disks of 1743200K size 512 blocksize
Dec 13 16:30:45 tst kernel: [  917.365831] 
Dec 13 16:30:45 tst kernel: [  917.365836] =============================================
Dec 13 16:30:45 tst kernel: [  917.372856] [ INFO: possible recursive locking detected ]
Dec 13 16:30:45 tst kernel: [  917.378269] 2.6.23-dbg #17
Dec 13 16:30:45 tst kernel: [  917.381435] ---------------------------------------------
Dec 13 16:30:45 tst kernel: [  917.386838] dbench/3538 is trying to acquire lock:
Dec 13 16:30:45 tst kernel: [  917.391687]  (&(&ip->i_iolock)->mr_lock){----}, at: [<f89ad79c>] xfs_ilock+0x90/0x9c [xfs]
Dec 13 16:30:45 tst kernel: [  917.400262] 
Dec 13 16:30:45 tst kernel: [  917.400264] but task is already holding lock:
Dec 13 16:30:45 tst kernel: [  917.406116]  (&(&ip->i_iolock)->mr_lock){----}, at: [<f89ad79c>] xfs_ilock+0x90/0x9c [xfs]
Dec 13 16:30:45 tst kernel: [  917.414503] 
Dec 13 16:30:45 tst kernel: [  917.414505] other info that might help us debug this:
Dec 13 16:30:45 tst kernel: [  917.421242] 3 locks held by dbench/3538:
Dec 13 16:30:45 tst kernel: [  917.425178]  #0:  (&inode->i_mutex){--..}, at: [<783626a6>] mutex_lock+0x1c/0x1f
Dec 13 16:30:45 tst kernel: [  917.432805]  #1:  (&(&ip->i_iolock)->mr_lock){----}, at: [<f89ad79c>] xfs_ilock+0x90/0x9c [xfs]
Dec 13 16:30:45 tst kernel: [  917.441696]  #2:  (&type->s_umount_key#17){----}, at: [<78191411>] writeback_inodes+0x88/0xd5
Dec 13 16:30:45 tst kernel: [  917.450578] 
Dec 13 16:30:45 tst kernel: [  917.450582] stack backtrace:
Dec 13 16:30:45 tst kernel: [  917.455011]  [<78103d59>] show_trace_log_lvl+0x1a/0x30
Dec 13 16:30:45 tst kernel: [  917.460279]  [<7810488d>] show_trace+0x12/0x14
Dec 13 16:30:45 tst kernel: [  917.464759]  [<781048a5>] dump_stack+0x16/0x18
Dec 13 16:30:45 tst kernel: [  917.469262]  [<7813f883>] __lock_acquire+0xdd1/0x106e
Dec 13 16:30:45 tst kernel: [  917.474360]  [<7813fb89>] lock_acquire+0x69/0x82
Dec 13 16:30:45 tst kernel: [  917.479000]  [<78136184>] down_write_nested+0x40/0x88
Dec 13 16:30:45 tst kernel: [  917.484195]  [<f89ad79c>] xfs_ilock+0x90/0x9c [xfs]
Dec 13 16:30:45 tst kernel: [  917.489180]  [<f89d13b7>] xfs_inactive+0x329/0x4ed [xfs]
Dec 13 16:30:45 tst kernel: [  917.494565]  [<f89dc052>] xfs_fs_clear_inode+0x7a/0xbe [xfs]
Dec 13 16:30:45 tst kernel: [  917.500415]  [<78188a78>] clear_inode+0xb2/0x14d
Dec 13 16:30:45 tst kernel: [  917.505078]  [<78188c0b>] generic_delete_inode+0xf8/0x105
Dec 13 16:30:45 tst kernel: [  917.510513]  [<78188d27>] generic_drop_inode+0x10f/0x141
Dec 13 16:30:45 tst kernel: [  917.515854]  [<78188226>] iput+0x5f/0x66
Dec 13 16:30:45 tst kernel: [  917.519836]  [<781911ae>] sync_sb_inodes+0x1f6/0x25c
Dec 13 16:30:45 tst kernel: [  917.525032]  [<7819142f>] writeback_inodes+0xa6/0xd5
Dec 13 16:30:45 tst kernel: [  917.530070]  [<7815c9f3>] balance_dirty_pages_ratelimited_nr+0xdd/0x204
Dec 13 16:30:45 tst kernel: [  917.536716]  [<781580e4>] generic_file_buffered_write+0x2e2/0x69c
Dec 13 16:30:45 tst kernel: [  917.542855]  [<f89db3fe>] xfs_write+0x619/0xaab [xfs]
Dec 13 16:30:45 tst kernel: [  917.547990]  [<f89d776e>] xfs_file_aio_write+0x70/0x7c [xfs]
Dec 13 16:30:45 tst kernel: [  917.553770]  [<78175d65>] do_sync_write+0xd0/0x106
Dec 13 16:30:45 tst kernel: [  917.558620]  [<78176552>] vfs_write+0x8b/0x149
Dec 13 16:30:45 tst kernel: [  917.563113]  [<78176bc4>] sys_write+0x3d/0x64
Dec 13 16:30:45 tst kernel: [  917.567526]  [<78102ca2>] sysenter_past_esp+0x5f/0x99
Dec 13 16:30:45 tst kernel: [  917.572635]  =======================
Dec 13 16:46:11 tst kernel: [ 1842.236343] dbench used greatest stack depth: 796 bytes left
Dec 13 16:46:11 tst kernel: [ 1842.248527] dbench used greatest stack depth: 544 bytes left
Dec 13 16:46:13 tst kernel: [ 1845.027574] dbench used greatest stack depth: 528 bytes left

[Index of Archives]     [Kernel Newbies]     [Netfilter]     [Bugtraq]     [Photo]     [Stuff]     [Gimp]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Video 4 Linux]     [Linux for the blind]     [Linux Resources]
  Powered by Linux