On Thu, Nov 06, 2014 at 07:46:16AM -0800, Christoph Hellwig wrote: > Without help from Paul I can't even make sense of the message.. It looks to me like the SUN4U architecture is failing to invoke rcu_irq_enter() on entry to the smp_call_function_single_client() IPI handler. And I am not seeing any sign of this in the call sequence in 3.17. Does the following patch help? ------------------------------------------------------------------------ diff --git a/arch/sparc/kernel/smp_64.c b/arch/sparc/kernel/smp_64.c index 302c476413d5..971a488264ff 100644 --- a/arch/sparc/kernel/smp_64.c +++ b/arch/sparc/kernel/smp_64.c @@ -822,7 +822,9 @@ void __irq_entry smp_call_function_client(int irq, struct pt_regs *regs) void __irq_entry smp_call_function_single_client(int irq, struct pt_regs *regs) { clear_softint(1 << irq); + irq_enter(); generic_smp_call_function_single_interrupt(); + irq_exit(); } static void tsb_sync(void *info) ------------------------------------------------------------------------ If there is something bad about invoking all of irq_enter() and irq_exit() for this handler on SPARC, perhaps this would be better: ------------------------------------------------------------------------ diff --git a/arch/sparc/kernel/smp_64.c b/arch/sparc/kernel/smp_64.c index 302c476413d5..ce3e329c3ccc 100644 --- a/arch/sparc/kernel/smp_64.c +++ b/arch/sparc/kernel/smp_64.c @@ -822,7 +822,9 @@ void __irq_entry smp_call_function_client(int irq, struct pt_regs *regs) void __irq_entry smp_call_function_single_client(int irq, struct pt_regs *regs) { clear_softint(1 << irq); + rcu_irq_enter(); generic_smp_call_function_single_interrupt(); + rcu_irq_exit(); } static void tsb_sync(void *info) ------------------------------------------------------------------------ Do either of these help? Thanx, Paul > On Thu, Nov 06, 2014 at 05:45:43PM +0200, Meelis Roos wrote: > > I tested a machine with multiple scsi adapters today with latest kernel > > and found the following warning in the logs. It is probably from QLA1040 > > adapter initialization, full dmesg is below. Adaptec SCSI card dumps is > > normal on this server, it is usually there and seems to be harmless > > (maybe a supurious IRQ somewhere - but this should not be relevant). > > > > The message is not there for scsi_mod.use_blk_mq=0 boot. > > > > Booting 3.17.0 with scsi_mod.use_blk_mq=1 does not show this message > > either. > > > > [ 188.275021] =============================== > > [ 188.309351] [ INFO: suspicious RCU usage. ] > > [ 188.343737] 3.18.0-rc3-00068-g20f3963-dirty #54 Not tainted > > [ 188.394786] ------------------------------- > > [ 188.429170] include/linux/rcupdate.h:883 rcu_read_lock() used > > illegally while idle! > > [ 188.505235] > > other info that might help us debug this: > > > > [ 188.554230] > > RCU used illegally from idle CPU! > > rcu_scheduler_active = 1, debug_locks = 0 > > [ 188.637587] RCU used illegally from extended quiescent state! > > [ 188.690684] 3 locks held by swapper/7/0: > > [ 188.721932] #0: (&x->wait#11){......}, at: [<0000000000495de8>] complete+0x8/0x60 > > [ 188.797994] #1: (&p->pi_lock){-.-.-.}, at: [<000000000048510c>] try_to_wake_up+0xc/0x400 > > [ 188.881343] #2: (rcu_read_lock){......}, at: [<000000000048a910>] select_task_rq_fair+0x90/0xb40 > > [ 188.973043]stack backtrace: > > [ 188.993879] CPU: 7 PID: 0 Comm: swapper/7 Not tainted 3.18.0-rc3-00068-g20f3963-dirty #54 > > [ 189.076187] Call Trace: > > [ 189.089719] [0000000000499360] lockdep_rcu_suspicious+0xe0/0x100 > > [ 189.147035] [000000000048a99c] select_task_rq_fair+0x11c/0xb40 > > [ 189.202253] [00000000004852d8] try_to_wake_up+0x1d8/0x400 > > [ 189.252258] [000000000048554c] default_wake_function+0xc/0x20 > > [ 189.306435] [0000000000495554] __wake_up_common+0x34/0x80 > > [ 189.356448] [00000000004955b4] __wake_up_locked+0x14/0x40 > > [ 189.406456] [0000000000495e08] complete+0x28/0x60 > > [ 189.448142] [0000000000636e28] blk_end_sync_rq+0x8/0x20 > > [ 189.496057] [0000000000639898] __blk_mq_end_request+0x18/0x60 > > [ 189.550249] [00000000006ee014] scsi_end_request+0x94/0x180 > > [ 189.601286] [00000000006ee334] scsi_io_completion+0x1d4/0x600 > > [ 189.655463] [00000000006e51c4] scsi_finish_command+0xc4/0xe0 > > [ 189.708598] [00000000006ed958] scsi_softirq_done+0x118/0x140 > > [ 189.761735] [00000000006398ec] __blk_mq_complete_request_remote+0xc/0x20 > > [ 189.827383] [00000000004c75d0] generic_smp_call_function_single_interrupt+0x150/0x1c0 > > [ 189.906581] [000000000043e514] smp_call_function_single_client+0x14/0x40 > > > > > > Full dmesg: > > > > [ 0.000000] PROMLIB: Sun IEEE Boot Prom 'OBP 3.2.30 2002/10/25 14:03' > > [ 0.000000] PROMLIB: Root node compatible: > > [ 0.000000] Linux version 3.18.0-rc3-00068-g20f3963-dirty (mroos@korvits) (gcc version 4.9.1 (Debian 4.9.1-18) ) #54 SMP Thu Nov 6 14:37:34 EET 2014 > > [ 0.000000] debug: ignoring loglevel setting. > > [ 0.000000] bootconsole [earlyprom0] enabled > > [ 0.000000] ARCH: SUN4U > > [ 0.000000] Ethernet address: 08:00:20:b6:ee:e2 > > [ 0.000000] MM: PAGE_OFFSET is 0xfffff80000000000 (max_phys_bits == 40) > > [ 0.000000] MM: VMALLOC [0x0000000100000000 --> 0x0000060000000000] > > [ 0.000000] MM: VMEMMAP [0x0000060000000000 --> 0x00000c0000000000] > > [ 0.000000] Kernel: Using 6 locked TLB entries for main kernel image. > > [ 0.000000] Remapping the kernel... done. > > [ 0.000000] kmemleak: Kernel memory leak detector disabled > > [ 0.000000] OF stdout device is: /central@1f,0/fhc@0,f8800000/zs@0,902000:a > > [ 0.000000] PROM: Built device tree with 169763 bytes of memory. > > [ 0.000000] Top of RAM: 0x7fcf2000, Total RAM: 0x7f8c0000 > > [ 0.000000] Memory hole size: 4MB > > [ 0.000000] Allocated 2113536 bytes for kernel page tables. > > [ 0.000000] Zone ranges: > > [ 0.000000] Normal [mem 0x00000000-0x7fcf1fff] > > [ 0.000000] Movable zone start for each node > > [ 0.000000] Early memory node ranges > > [ 0.000000] node 0: [mem 0x00000000-0x7f7ddfff] > > [ 0.000000] node 0: [mem 0x7fc00000-0x7fcd1fff] > > [ 0.000000] node 0: [mem 0x7fce2000-0x7fcf1fff] > > [ 0.000000] Initmem setup node 0 [mem 0x00000000-0x7fcf1fff] > > [ 0.000000] On node 0 totalpages: 261216 > > [ 0.000000] Normal zone: 2301 pages used for memmap > > [ 0.000000] Normal zone: 0 pages reserved > > [ 0.000000] Normal zone: 261216 pages, LIFO batch:15 > > [ 0.000000] Booting Linux... > > [ 0.000000] CPU CAPS: [flush,stbar,swap,muldiv,v9,mul32,div32,v8plus] > > [ 0.000000] CPU CAPS: [vis] > > [ 0.000000] PERCPU: Embedded 7 pages/cpu @fffff8007f000000 s15808 r8192 d33344 u2097152 > > [ 0.000000] pcpu-alloc: s15808 r8192 d33344 u2097152 alloc=1*4194304 > > [ 0.000000] pcpu-alloc: [0] 6 7 > > [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 258915 > > [ 0.000000] Kernel command line: root=/dev/sda2 ro debug ignore_loglevel > > [ 0.000000] PID hash table entries: 4096 (order: 2, 32768 bytes) > > [ 0.000000] Dentry cache hash table entries: 262144 (order: 8, 2097152 bytes) > > [ 0.000000] Inode-cache hash table entries: 131072 (order: 7, 1048576 bytes) > > [ 0.000000] Sorting __ex_table... > > [ 0.000000] Memory: 2037784K/2089728K available (4533K kernel code, 305K rwdata, 1504K rodata, 576K init, 14539K bss, 51944K reserved) > > [ 0.000000] Hierarchical RCU implementation. > > [ 0.000000] RCU lockdep checking is enabled. > > [ 0.000000] RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=8. > > [ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=8 > > [ 0.000000] NR_IRQS:2048 nr_irqs:2048 1 > > [ 161.238391] clocksource: mult[2800000] shift[24] > > [ 161.277473] clockevent: mult[66666666] shift[32] > > [ 161.318721] Console: colour dummy device 80x25 > > [ 161.355382] console [tty0] enabled > > [ 161.380218] bootconsole [earlyprom0] disabled > > [ 161.416696] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar > > [ 161.416740] ... MAX_LOCKDEP_SUBCLASSES: 8 > > [ 161.416765] ... MAX_LOCK_DEPTH: 48 > > [ 161.416790] ... MAX_LOCKDEP_KEYS: 8191 > > [ 161.416816] ... CLASSHASH_SIZE: 4096 > > [ 161.416841] ... MAX_LOCKDEP_ENTRIES: 32768 > > [ 161.416867] ... MAX_LOCKDEP_CHAINS: 65536 > > [ 161.416892] ... CHAINHASH_SIZE: 32768 > > [ 161.416918] memory used by lock dependency info: 8159 kB > > [ 161.416949] per task-struct memory footprint: 1920 bytes > > [ 161.416978] ------------------------ > > [ 161.416999] | Locking API testsuite: > > [ 161.417019] ---------------------------------------------------------------------------- > > [ 161.417061] | spin |wlock |rlock |mutex | wsem | rsem | > > [ 161.417104] -------------------------------------------------------------------------- > > [ 161.417173] A-A deadlock: ok | ok | ok | ok | ok | ok | > > [ 161.457494] A-B-B-A deadlock: ok | ok | ok | ok | ok | ok | > > [ 161.495480] A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok | > > [ 161.533653] A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok | > > [ 161.571829] A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok | > > [ 161.610241] A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok | > > [ 161.648630] A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok | > > [ 161.687043] double unlock: ok | ok | ok | ok | ok | ok | > > [ 161.724876] initialize held: ok | ok | ok | ok | ok | ok | > > [ 161.762661] bad unlock order: ok | ok | ok | ok | ok | ok | > > [ 161.800701] -------------------------------------------------------------------------- > > [ 161.800747] recursive read-lock: | ok | | ok | > > [ 161.813409] recursive read-lock #2: | ok | | ok | > > [ 161.826070] mixed read-write-lock: | ok | | ok | > > [ 161.838756] mixed write-read-lock: | ok | | ok | > > [ 161.851441] -------------------------------------------------------------------------- > > [ 161.851489] hard-irqs-on + irq-safe-A/12: ok | ok | ok | > > [ 161.870404] soft-irqs-on + irq-safe-A/12: ok | ok | ok | > > [ 161.889387] hard-irqs-on + irq-safe-A/21: ok | ok | ok | > > [ 161.908303] soft-irqs-on + irq-safe-A/21: ok | ok | ok | > > [ 161.927281] sirq-safe-A => hirqs-on/12: ok | ok | ok | > > [ 161.946218] sirq-safe-A => hirqs-on/21: ok | ok | ok | > > [ 161.965194] hard-safe-A + irqs-on/12: ok | ok | ok | > > [ 161.984110] soft-safe-A + irqs-on/12: ok | ok | ok | > > [ 162.003086] hard-safe-A + irqs-on/21: ok | ok | ok | > > [ 162.022023] soft-safe-A + irqs-on/21: ok | ok | ok | > > [ 162.041005] hard-safe-A + unsafe-B #1/123: ok | ok | ok | > > [ 162.060021] soft-safe-A + unsafe-B #1/123: ok | ok | ok | > > [ 162.079090] hard-safe-A + unsafe-B #1/132: ok | ok | ok | > > [ 162.098089] soft-safe-A + unsafe-B #1/132: ok | ok | ok | > > [ 162.117160] hard-safe-A + unsafe-B #1/213: ok | ok | ok | > > [ 162.136184] soft-safe-A + unsafe-B #1/213: ok | ok | ok | > > [ 162.155258] hard-safe-A + unsafe-B #1/231: ok | ok | ok | > > [ 162.174253] soft-safe-A + unsafe-B #1/231: ok | ok | ok | > > [ 162.193316] hard-safe-A + unsafe-B #1/312: ok | ok | ok | > > [ 162.212268] soft-safe-A + unsafe-B #1/312: ok | ok | ok | > > [ 162.231264] hard-safe-A + unsafe-B #1/321: ok | ok | ok | > > [ 162.250265] soft-safe-A + unsafe-B #1/321: ok | ok | ok | > > [ 162.269312] hard-safe-A + unsafe-B #2/123: ok | ok | ok | > > [ 162.288321] soft-safe-A + unsafe-B #2/123: ok | ok | ok | > > [ 162.307393] hard-safe-A + unsafe-B #2/132: ok | ok | ok | > > [ 162.326395] soft-safe-A + unsafe-B #2/132: ok | ok | ok | > > [ 162.345469] hard-safe-A + unsafe-B #2/213: ok | ok | ok | > > [ 162.364485] soft-safe-A + unsafe-B #2/213: ok | ok | ok | > > [ 162.383569] hard-safe-A + unsafe-B #2/231: ok | ok | ok | > > [ 162.402578] soft-safe-A + unsafe-B #2/231: ok | ok | ok | > > [ 162.421652] hard-safe-A + unsafe-B #2/312: ok | ok | ok | > > [ 162.440662] soft-safe-A + unsafe-B #2/312: ok | ok | ok | > > [ 162.459750] hard-safe-A + unsafe-B #2/321: ok | ok | ok | > > [ 162.478756] soft-safe-A + unsafe-B #2/321: ok | ok | ok | > > [ 162.497822] hard-irq lock-inversion/123: ok | ok | ok | > > [ 162.516832] soft-irq lock-inversion/123: ok | ok | ok | > > [ 162.535924] hard-irq lock-inversion/132: ok | ok | ok | > > [ 162.554942] soft-irq lock-inversion/132: ok | ok | ok | > > [ 162.574036] hard-irq lock-inversion/213: ok | ok | ok | > > [ 162.593071] soft-irq lock-inversion/213: ok | ok | ok | > > [ 162.612151] hard-irq lock-inversion/231: ok | ok | ok | > > [ 162.631163] soft-irq lock-inversion/231: ok | ok | ok | > > [ 162.650245] hard-irq lock-inversion/312: ok | ok | ok | > > [ 162.669272] soft-irq lock-inversion/312: ok | ok | ok | > > [ 162.688368] hard-irq lock-inversion/321: ok | ok | ok | > > [ 162.707370] soft-irq lock-inversion/321: ok | ok | ok | > > [ 162.726457] hard-irq read-recursion/123: ok | > > [ 162.732811] soft-irq read-recursion/123: ok | > > [ 162.739223] hard-irq read-recursion/132: ok | > > [ 162.745568] soft-irq read-recursion/132: ok | > > [ 162.751969] hard-irq read-recursion/213: ok | > > [ 162.758313] soft-irq read-recursion/213: ok | > > [ 162.764715] hard-irq read-recursion/231: ok | > > [ 162.771062] soft-irq read-recursion/231: ok | > > [ 162.777472] hard-irq read-recursion/312: ok | > > [ 162.783817] soft-irq read-recursion/312: ok | > > [ 162.790220] hard-irq read-recursion/321: ok | > > [ 162.796571] soft-irq read-recursion/321: ok | > > [ 162.802972] -------------------------------------------------------------------------- > > [ 162.803016] | Wound/wait tests | > > [ 162.803039] --------------------- > > [ 162.803064] ww api failures: ok | ok | ok | > > [ 162.822112] ww contexts mixing: ok | ok | > > [ 162.834785] finishing ww context: ok | ok | ok | ok | > > [ 162.860095] locking mismatches: ok | ok | ok | > > [ 162.879128] EDEADLK handling: ok | ok | ok | ok | ok | ok | ok | ok | ok | ok | > > [ 162.942686] spinlock nest unlocked: ok | > > [ 162.949005] ----------------------------------------------------- > > [ 162.949044] |block | try |context| > > [ 162.949082] ----------------------------------------------------- > > [ 162.949121] context: ok | ok | ok | > > [ 162.968211] try: ok | ok | ok | > > [ 162.987181] block: ok | ok | ok | > > [ 163.006186] spinlock: ok | ok | ok | > > [ 163.025283] ------------------------------------------------------- > > [ 163.025322] Good, all 253 testcases passed! | > > [ 163.025349] --------------------------------- > > [ 163.027126] ODEBUG: selftest passed > > [ 163.027345] kmemleak: Early log buffer exceeded (3329), please increase DEBUG_KMEMLEAK_EARLY_LOG_SIZE > > [ 163.169263] Calibrating delay using timer specific routine.. 804.17 BogoMIPS (lpj=4020880) > > [ 163.169341] pid_max: default: 32768 minimum: 301 > > [ 163.170354] Mount-cache hash table entries: 4096 (order: 2, 32768 bytes) > > [ 163.170426] Mountpoint-cache hash table entries: 4096 (order: 2, 32768 bytes) > > [ 163.191280] CPU 7: synchronized TICK with master CPU (last diff -8 cycles, maxerr 677 cycles) > > [ 163.191904] Brought up 2 CPUs > > [ 163.196096] devtmpfs: initialized > > [ 163.199102] Performance events: No support for PMU type 'ultra12' > > [ 163.282260] atomic64_test: passed > > [ 163.284207] kworker/u4:0 (20) used greatest stack depth: 8216 bytes left > > [ 163.300285] device-tree: Duplicate name in base, renamed to "fhc#1" > > [ 163.307412] device-tree: Duplicate name in base, renamed to "counter-timer#1" > > [ 163.312131] device-tree: Duplicate name in base, renamed to "fhc#2" > > [ 163.314228] device-tree: Duplicate name in base, renamed to "counter-timer#2" > > [ 163.318010] device-tree: Duplicate name in base, renamed to "counter-timer#3" > > [ 163.323548] device-tree: Duplicate name in base, renamed to "fhc#3" > > [ 163.325699] device-tree: Duplicate name in base, renamed to "counter-timer#4" > > [ 163.330745] device-tree: Duplicate name in base, renamed to "counter-timer#5" > > [ 163.333752] NET: Registered protocol family 16 > > [ 163.344321] kworker/u4:0 (31) used greatest stack depth: 7976 bytes left > > [ 163.347152] kworker/u4:0 (34) used greatest stack depth: 7896 bytes left > > [ 163.390763] SYSIO: UPA portID ffffffff, at 000001c400000000 > > [ 163.400388] SYSIO: UPA portID ffffffff, at 000001c600000000 > > [ 163.410018] SYSIO: UPA portID ffffffff, at 000001d400000000 > > [ 163.420198] SYSIO: UPA portID ffffffff, at 000001d600000000 > > [ 163.439052] /pci@e,4000: PCI IO[1dc02010000] MEM[1dd80000000] > > [ 163.439288] /pci@e,4000: PSYCHO PCI Bus Module ver[4:0] > > [ 163.439377] PCI: Scanning PBM /pci@e,4000 > > [ 163.440634] psycho f01bf7bc: PCI host bridge to bus 0000:00 > > [ 163.440713] pci_bus 0000:00: root bus resource [io 0x1dc02010000-0x1dc0201ffff] (bus address [0x0000-0xffff]) > > [ 163.440818] pci_bus 0000:00: root bus resource [mem 0x1dd80000000-0x1ddffffffff] (bus address [0x00000000-0x7fffffff]) > > [ 163.440929] pci_bus 0000:00: root bus resource [bus 00] > > [ 163.445838] /pci@e,2000: PCI IO[1dc02000000] MEM[1dd00000000] > > [ 163.445927] /pci@e,2000: PSYCHO PCI Bus Module ver[4:0] > > [ 163.445984] PCI: Scanning PBM /pci@e,2000 > > [ 163.446800] psycho f01c88e0: PCI host bridge to bus 0001:80 > > [ 163.446876] pci_bus 0001:80: root bus resource [io 0x1dc02000000-0x1dc0200ffff] (bus address [0x0000-0xffff]) > > [ 163.446983] pci_bus 0001:80: root bus resource [mem 0x1dd00000000-0x1dd7fffffff] (bus address [0x00000000-0x7fffffff]) > > [ 163.447088] pci_bus 0001:80: root bus resource [bus 80] > > [ 163.457405] /pci@f,4000: PCI IO[1de02010000] MEM[1df80000000] > > [ 163.457494] /pci@f,4000: PSYCHO PCI Bus Module ver[4:0] > > [ 163.457549] PCI: Scanning PBM /pci@f,4000 > > [ 163.458367] psycho f01ca118: PCI host bridge to bus 0002:00 > > [ 163.458443] pci_bus 0002:00: root bus resource [io 0x1de02010000-0x1de0201ffff] (bus address [0x0000-0xffff]) > > [ 163.458547] pci_bus 0002:00: root bus resource [mem 0x1df80000000-0x1dfffffffff] (bus address [0x00000000-0x7fffffff]) > > [ 163.458653] pci_bus 0002:00: root bus resource [bus 00] > > [ 163.461719] /pci@f,2000: PCI IO[1de02000000] MEM[1df00000000] > > [ 163.461804] /pci@f,2000: PSYCHO PCI Bus Module ver[4:0] > > [ 163.461859] PCI: Scanning PBM /pci@f,2000 > > [ 163.462668] psycho f01d320c: PCI host bridge to bus 0003:80 > > [ 163.462743] pci_bus 0003:80: root bus resource [io 0x1de02000000-0x1de0200ffff] (bus address [0x0000-0xffff]) > > [ 163.462855] pci_bus 0003:80: root bus resource [mem 0x1df00000000-0x1df7fffffff] (bus address [0x00000000-0x7fffffff]) > > [ 163.462964] pci_bus 0003:80: root bus resource [bus 80] > > [ 163.580345] vgaarb: loaded > > [ 163.584298] SCSI subsystem initialized > > [ 163.592449] /central/fhc@0,f8800000/eeprom@0,908000: Mostek regs at 0x1fff8908000 > > [ 163.595898] fhc: Board #1, Version[1] PartID[fa0] Manuf[3e] (Central) > > [ 163.596622] fhc: Board #3, Version[1] PartID[fa0] Manuf[3e] (JTAG Master) > > [ 163.597384] fhc: Board #1, Version[1] PartID[fa0] Manuf[3e] > > [ 163.598197] fhc: Board #5, Version[1] PartID[fa0] Manuf[3e] > > [ 163.598978] fhc: Board #7, Version[1] PartID[fa0] Manuf[3e] > > [ 163.600178] clock_board: Detected 5 slot Enterprise system. > > [ 163.690823] DMA-API: preallocated 32768 debug entries > > [ 163.690902] DMA-API: debugging enabled by kernel config > > [ 163.693159] Switched to clocksource tick > > [ 163.703829] kworker/u4:0 (280) used greatest stack depth: 7752 bytes left > > [ 163.754938] NET: Registered protocol family 2 > > [ 163.757716] TCP established hash table entries: 16384 (order: 4, 131072 bytes) > > [ 163.758687] TCP bind hash table entries: 16384 (order: 7, 1048576 bytes) > > [ 163.768861] TCP: Hash tables configured (established 16384 bind 16384) > > [ 163.769822] TCP: reno registered > > [ 163.769975] UDP hash table entries: 1024 (order: 4, 163840 bytes) > > [ 163.771566] UDP-Lite hash table entries: 1024 (order: 4, 163840 bytes) > > [ 163.775400] NET: Registered protocol family 1 > > [ 163.775741] PCI: CLS 0 bytes, default 64 > > [ 163.784319] futex hash table entries: 512 (order: 3, 65536 bytes) > > [ 163.784865] ====[ backtrace testing ]=========== > > [ 163.784908] Testing a backtrace from process context. > > [ 163.784952] The following trace is a kernel self test and not a bug! > > [ 163.785015] CPU: 6 PID: 1 Comm: swapper/6 Not tainted 3.18.0-rc3-00068-g20f3963-dirty #54 > > [ 163.785076] Call Trace: > > [ 163.785122] [00000000004cd80c] backtrace_regression_test+0x2c/0x100 > > [ 163.785183] [0000000000426ea4] do_one_initcall+0xe4/0x1e0 > > [ 163.785250] [0000000000a40b44] kernel_init_freeable+0x120/0x1d0 > > [ 163.785326] [0000000000865a84] kernel_init+0x4/0x100 > > [ 163.785389] [0000000000406104] ret_from_fork+0x1c/0x2c > > [ 163.785436] [0000000000000000] (null) > > [ 163.785477] Testing a backtrace from irq context. > > [ 163.785519] The following trace is a kernel self test and not a bug! > > [ 163.786004] CPU: 6 PID: 3 Comm: ksoftirqd/6 Not tainted 3.18.0-rc3-00068-g20f3963-dirty #54 > > [ 163.786068] Call Trace: > > [ 163.786116] [00000000004cd7c4] backtrace_test_irq_callback+0x4/0x20 > > [ 163.786183] [000000000045f278] tasklet_action+0x98/0x120 > > [ 163.786238] [000000000045f3f0] __do_softirq+0xf0/0x240 > > [ 163.786294] [000000000045f568] run_ksoftirqd+0x28/0x80 > > [ 163.786373] [000000000047e3e4] smpboot_thread_fn+0x244/0x280 > > [ 163.786440] [0000000000479ef0] kthread+0xb0/0xe0 > > [ 163.786496] [0000000000406104] ret_from_fork+0x1c/0x2c > > [ 163.786546] [0000000000000000] (null) > > [ 163.786707] Testing a saved backtrace. > > [ 163.786753] The following trace is a kernel self test and not a bug! > > [ 163.786810] [<00000000004cd8a8>] backtrace_regression_test+0xc8/0x100 > > [ 163.786888] [<0000000000426ea4>] do_one_initcall+0xe4/0x1e0 > > [ 163.786952] [<0000000000a40b44>] kernel_init_freeable+0x120/0x1d0 > > [ 163.787022] [<0000000000865a84>] kernel_init+0x4/0x100 > > [ 163.787088] [<0000000000406104>] ret_from_fork+0x1c/0x2c > > [ 163.787153] [< (null)>] (null) > > [ 163.787207] ====[ end of backtrace testing ]==== > > [ 163.787332] audit: initializing netlink subsys (disabled) > > [ 163.787886] audit: type=2000 audit(2.050:1): initialized > > [ 163.791649] HugeTLB registered 8 MB page size, pre-allocated 0 pages > > [ 163.797716] msgmni has been set to 3980 > > [ 163.803398] io scheduler noop registered > > [ 163.803651] io scheduler cfq registered (default) > > [ 163.803717] start plist test > > [ 163.826582] end plist test > > [ 163.831561] test_string_helpers: Running tests... > > [ 164.044577] zs f005de3c: ttyS0 at MMIO 0x1fff8902000 (irq = 2, base_baud = 307200) is a zs (ESCC) > > [ 164.044724] Console: ttyS0 (SunZilog zs0) > > [ 179.468351] console [ttyS0] enabled > > [ 179.496405] zs f005de3c: ttyS1 at MMIO 0x1fff8902004 (irq = 2, base_baud = 307200) is a zs (ESCC) > > [ 179.795321] f005df14: Keyboard at MMIO 0x1fff8904000 (irq = 2) is a zs > > [ 179.855846] f005df14: Mouse at MMIO 0x1fff8904004 (irq = 2) is a zs > > [ 179.954009] loop: module loaded > > [ 179.975578] PCI: Enabling device: (0003:80:02.0), cmd 3 > > [ 185.152853] scsi0: Missing case in ahd_handle_scsiint. status = 0 > > [ 185.208135] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<< > > scsi0: Dumping Card State at program address 0x0 Mode 0x33 > > [ 185.334228] Card was paused > > [ 185.351888] INTSTAT[0x8]:(SCSIINT) SELOID[0x0] SELID[0x0] HS_MAILBOX[0x0] > > [ 185.418562] INTCTL[0x0] SEQINTSTAT[0x0] SAVED_MODE[0x25] DFFSTAT[0x33]:(CURRFIFO_NONE|FIFO0FREE|FIFO1FREE) > > [ 185.519625] SCSISIGI[0x0]:(P_DATAOUT) SCSIPHASE[0x0] SCSIBUS[0x0] > > [ 185.577970] LASTPHASE[0x1]:(P_DATAOUT|P_BUSFREE) SCSISEQ0[0x0] > > [ 185.633186] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI) SEQCTL0[0x0] SEQINTCTL[0x0] > > [ 185.701952] SEQ_FLAGS[0x0] SEQ_FLAGS2[0x0] QFREEZE_COUNT[0x0] > > [ 185.756130] KERNEL_QFREEZE_COUNT[0x0] MK_MESSAGE_SCB[0xff00] MK_MESSAGE_SCSIID[0xff] > > [ 185.834268] SSTAT0[0x0] SSTAT1[0x0] SSTAT2[0x0] SSTAT3[0x0] PERRDIAG[0x0] > > [ 185.900952] SIMODE1[0xa4]:(ENSCSIPERR|ENSCSIRST|ENSELTIMO) LQISTAT0[0x0] > > [ 185.966586] LQISTAT1[0x0] LQISTAT2[0x0] LQOSTAT0[0x0] LQOSTAT1[0x0] > > [ 186.027015] LQOSTAT2[0x0] > > [ 186.043701] > > SCB Count = 8 CMDS_PENDING = 0 LASTSCB 0xffff CURRSCB 0x0 NEXTSCB 0x0 > > [ 186.119786] qinstart = 0 qinfifonext = 0 > > QINFIFO: > > WAITING_TID_QUEUES: > > [ 186.183326] Pending list: > > Total 0 > > [ 186.208314] Kernel Free SCB list: 7 6 5 4 3 2 1 0 > > [ 186.249973] Sequencer Complete DMA-inprog list: > > [ 186.289562] Sequencer Complete list: > > [ 186.317694] Sequencer DMA-Up and Complete list: > > [ 186.357284] Sequencer On QFreeze and Complete list: > > [ 186.401059] > > > > scsi0: FIFO0 Free, LONGJMP == 0x803b, SCB 0x0 > > [ 186.454230] SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS) > > [ 186.544821] SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL) > > [ 186.622965] SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0] > > [ 186.689642] SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0 > > [ 186.766758] HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL) > > > > scsi0: FIFO1 Free, LONGJMP == 0x80bc, SCB 0x0 > > [ 186.878272] SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS) > > [ 186.968863] SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL) > > [ 187.047006] SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0] > > [ 187.113688] SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0 > > [ 187.190796] HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL) > > LQIN: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 > > [ 187.342907] scsi0: LQISTATE = 0x0, LQOSTATE = 0x0, OPTIONMODE = 0x52 > > [ 187.403351] scsi0: OS_SPACE_CNT = 0x20 MAXCMDCNT = 0x0 > > [ 187.449192] scsi0: SAVED_SCSIID = 0x0 SAVED_LUN = 0x0 > > > > [ 187.496052] SIMODE0[0x6c]:(ENOVERRUN|ENIOERR|ENSELDI|ENSELDO) > > [ 187.550231] CCSCBCTL[0x0] > > [ 187.566913] scsi0: REG0 == 0x45d1, SINDEX = 0x0, DINDEX = 0x0 > > [ 187.620062] scsi0: SCBPTR == 0x1ff, SCB_NEXT == 0xff00, SCB_NEXT2 == 0x0 > > [ 187.684665] CDB ff 1 0 0 0 0 > > [ 187.703390] STACK: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 > > <<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>> > > [ 187.806958] scsi host0: Adaptec AIC79XX PCI-X SCSI HBA DRIVER, Rev 3.0 > > <Adaptec 29320ALP PCIx Ultra320 SCSI adapter> > > aic7901: Ultra320 Wide Channel A, SCSI Id=7, PCI 33 or 66MHz, 512 SCBs > > [ 188.016407] qla1280: QLA1040 found on PCI bus 0, dev 3 > > [ 188.060231] PCI: Enabling device: (0002:00:03.0), cmd 7 > > > > [ 188.275021] =============================== > > [ 188.309351] [ INFO: suspicious RCU usage. ] > > [ 188.343737] 3.18.0-rc3-00068-g20f3963-dirty #54 Not tainted > > [ 188.394786] ------------------------------- > > [ 188.429170] include/linux/rcupdate.h:883 rcu_read_lock() used illegally while idle! > > [ 188.505235] > > other info that might help us debug this: > > > > [ 188.554230] > > RCU used illegally from idle CPU! > > rcu_scheduler_active = 1, debug_locks = 0 > > [ 188.637587] RCU used illegally from extended quiescent state! > > [ 188.690684] 3 locks held by swapper/7/0: > > [ 188.721932] #0: (&x->wait#11){......}, at: [<0000000000495de8>] complete+0x8/0x60 > > [ 188.797994] #1: (&p->pi_lock){-.-.-.}, at: [<000000000048510c>] try_to_wake_up+0xc/0x400 > > [ 188.881343] #2: (rcu_read_lock){......}, at: [<000000000048a910>] select_task_rq_fair+0x90/0xb40 > > [ 188.973043] > > stack backtrace: > > [ 188.993879] CPU: 7 PID: 0 Comm: swapper/7 Not tainted 3.18.0-rc3-00068-g20f3963-dirty #54 > > [ 189.076187] Call Trace: > > [ 189.089719] [0000000000499360] lockdep_rcu_suspicious+0xe0/0x100 > > [ 189.147035] [000000000048a99c] select_task_rq_fair+0x11c/0xb40 > > [ 189.202253] [00000000004852d8] try_to_wake_up+0x1d8/0x400 > > [ 189.252258] [000000000048554c] default_wake_function+0xc/0x20 > > [ 189.306435] [0000000000495554] __wake_up_common+0x34/0x80 > > [ 189.356448] [00000000004955b4] __wake_up_locked+0x14/0x40 > > [ 189.406456] [0000000000495e08] complete+0x28/0x60 > > [ 189.448142] [0000000000636e28] blk_end_sync_rq+0x8/0x20 > > [ 189.496057] [0000000000639898] __blk_mq_end_request+0x18/0x60 > > [ 189.550249] [00000000006ee014] scsi_end_request+0x94/0x180 > > [ 189.601286] [00000000006ee334] scsi_io_completion+0x1d4/0x600 > > [ 189.655463] [00000000006e51c4] scsi_finish_command+0xc4/0xe0 > > [ 189.708598] [00000000006ed958] scsi_softirq_done+0x118/0x140 > > [ 189.761735] [00000000006398ec] __blk_mq_complete_request_remote+0xc/0x20 > > [ 189.827383] [00000000004c75d0] generic_smp_call_function_single_interrupt+0x150/0x1c0 > > [ 189.906581] [000000000043e514] smp_call_function_single_client+0x14/0x40 > > [ 190.269728] random: nonblocking pool is initialized > > [ 190.828808] scsi(1:0): Resetting SCSI BUS > > [ 193.862671] scsi host1: QLogic QLA1040 PCI to SCSI Host Adapter > > Firmware version: 7.65.06, Driver version 3.27.1 > > [ 193.976290] blk-mq: reduced tag depth to 10240 > > [ 194.037930] qla2xxx [0000:00:00.0]-0005: : QLogic Fibre Channel HBA Driver: 8.07.00.16-k. > > [ 194.118405] PCI: Enabling device: (0001:80:02.0), cmd 3 > > [ 194.165280] qla2xxx [0001:80:02.0]-001d: : Found an ISP2200 irq 49 iobase 0x000001dd00002000. > > [ 194.353211] qla2xxx 0001:80:02.0: Direct firmware load for ql2200_fw.bin failed with error -2 > > [ 194.437839] qla2xxx 0001:80:02.0: Falling back to user helper > > [ 194.491932] scsi 1:0:2:0: Direct-Access IBM DDYS-T18350M S96H PQ: 0 ANSI: 3 > > [ 194.573022] scsi(1:0:2:0): Sync: period 10, offset 12, Wide, Tagged queuing: depth 31 > > [ 194.823272] scsi 1:0:4:0: Direct-Access IBM DDYS-T18350M S80D PQ: 0 ANSI: 3 > > [ 194.903416] scsi(1:0:4:0): Sync: period 10, offset 12, Wide, Tagged queuing: depth 31 > > [ 195.662569] scsi 1:0:10:0: Direct-Access HP 9.10GB A 80-6331 PQ: 0 ANSI: 2 > > [ 195.743713] scsi(1:0:10:0): Sync: period 10, offset 12, Wide, Tagged queuing: depth 31 > > [ 195.830214] scsi 1:0:11:0: Direct-Access IBM DDRS-34560D DC1B PQ: 0 ANSI: 2 > > [ 195.911336] scsi(1:0:11:0): Sync: period 10, offset 12, Wide, Tagged queuing: depth 31 > > [ 196.006929] scsi 1:0:12:0: Direct-Access HP 4.26GB A 80-0430 0430 PQ: 0 ANSI: 2 > > [ 196.087903] scsi(1:0:12:0): Sync: period 10, offset 12, Wide, Tagged queuing: depth 31 > > [ 196.187208] scsi 1:0:13:0: Direct-Access HP 2.13GB A 80-0430 0430 PQ: 0 ANSI: 2 > > [ 196.268525] scsi(1:0:13:0): Sync: period 10, offset 12, Wide, Tagged queuing: depth 31 > > [ 254.692919] qla2xxx [0001:80:02.0]-0063:2: Failed to load firmware image (ql2200_fw.bin). > > [ 254.773218] qla2xxx [0001:80:02.0]-0083:2: Fimware image unavailable. > > [ 254.834679] qla2xxx [0001:80:02.0]-0084:2: Firmware images can be retrieved from: http://ldriver.qlogic.com/firmware/. > > [ 254.947216] qla2xxx [0001:80:02.0]-00cf:2: Setup chip ****FAILED****. > > [ 255.008657] qla2xxx [0001:80:02.0]-00d6:2: Failed to initialize adapter - Adapter flags 2. > > [ 255.097006] sunhme.c:v3.10 August 26, 2008 David S. Miller (davem@xxxxxxxxxxxxx) > > [ 255.170460] eth0: HAPPY MEAL (SBUS) 10/100baseT Ethernet 08:00:20:b6:ee:e2 > > [ 255.235445] sd 1:0:4:0: [sdb] 35843670 512-byte logical blocks: (18.3 GB/17.0 GiB) > > [ 255.237573] eth1: Quattro HME slot 0 (SBUS) 10/100baseT Ethernet 08:00:20:93:79:94 > > [ 255.239977] eth2: Quattro HME slot 1 (SBUS) 10/100baseT Ethernet 08:00:20:93:79:95 > > [ 255.242388] eth3: Quattro HME slot 2 (SBUS) 10/100baseT Ethernet 08:00:20:93:79:96 > > [ 255.244859] eth4: Quattro HME slot 3 (SBUS) 10/100baseT Ethernet 08:00:20:93:79:97 > > [ 255.247283] eth5: HAPPY MEAL (SBUS) 10/100baseT Ethernet 08:00:20:b6:ee:e2 > > [ 255.247840] PCI: Enabling device: (0000:00:01.1), cmd 2 > > [ 255.250196] eth6: HAPPY MEAL (PCI/CheerIO) 10/100BaseT Ethernet 08:00:20:b6:ee:e2 > > [ 255.251312] sd 1:0:2:0: [sda] 35843670 512-byte logical blocks: (18.3 GB/17.0 GiB) > > [ 255.310326] sd 1:0:2:0: [sda] Write Protect is off > > [ 255.310343] sd 1:0:2:0: [sda] Mode Sense: cb 00 00 08 > > [ 255.310591] sd 1:0:10:0: [sdc] 17773524 512-byte logical blocks: (9.10 GB/8.47 GiB) > > [ 255.310697] sd 1:0:11:0: [sdd] 8925000 512-byte logical blocks: (4.56 GB/4.25 GiB) > > [ 255.311960] mousedev: PS/2 mouse device common for all mice > > [ 255.315824] rtc-m48t59 rtc-m48t59.0: rtc core: registered m48t59 as rtc0 > > [ 255.317082] TCP: cubic registered > > [ 255.317108] NET: Registered protocol family 17 > > [ 255.318580] registered taskstats version 1 > > [ 255.385635] sd 1:0:12:0: [sde] 8330543 512-byte logical blocks: (4.26 GB/3.97 GiB) > > [ 255.385792] sd 1:0:10:0: [sdc] Write Protect is off > > [ 255.385809] sd 1:0:10:0: [sdc] Mode Sense: 9f 00 10 08 > > [ 255.385905] sd 1:0:11:0: [sdd] Write Protect is off > > [ 255.385921] sd 1:0:11:0: [sdd] Mode Sense: b9 00 00 08 > > [ 255.460208] rtc-m48t59 rtc-m48t59.0: setting system clock to 2014-11-06 14:44:49 UTC (1415285089) > > [ 255.460593] sd 1:0:2:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA > > [ 255.460897] sd 1:0:12:0: [sde] Write Protect is off > > [ 255.460913] sd 1:0:12:0: [sde] Mode Sense: 9f 00 10 08 > > [ 255.535967] sd 1:0:10:0: [sdc] Write cache: disabled, read cache: enabled, supports DPO and FUA > > [ 255.536140] sd 1:0:13:0: [sdf] 4165272 512-byte logical blocks: (2.13 GB/1.98 GiB) > > [ 255.536319] sd 1:0:11:0: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA > > [ 255.611389] sd 1:0:12:0: [sde] Write cache: disabled, read cache: enabled, supports DPO and FUA > > [ 255.611526] sd 1:0:13:0: [sdf] Write Protect is off > > [ 255.611542] sd 1:0:13:0: [sdf] Mode Sense: 9f 00 10 08 > > [ 255.724337] sd 1:0:13:0: [sdf] Write cache: disabled, read cache: enabled, supports DPO and FUA > > [ 255.960802] sda: sda1 sda2 sda3 sda4 > > [ 256.036886] sdd: unknown partition table > > [ 256.038024] sdc: unknown partition table > > [ 256.161971] sde: unknown partition table > > [ 256.226521] sdf: unknown partition table > > [ 256.287571] sd 1:0:2:0: [sda] Attached SCSI disk > > [ 256.320837] sd 1:0:11:0: [sdd] Attached SCSI disk > > [ 256.321195] sd 1:0:10:0: [sdc] Attached SCSI disk > > [ 256.438589] sd 1:0:12:0: [sde] Attached SCSI disk > > [ 256.484470] sd 1:0:13:0: [sdf] Attached SCSI disk > > [ 257.730003] sd 1:0:4:0: [sdb] Write Protect is off > > [ 257.769724] sd 1:0:4:0: [sdb] Mode Sense: cb 00 00 08 > > [ 257.816196] sd 1:0:4:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA > > [ 257.932380] sdb: unknown partition table > > [ 257.967850] sd 1:0:4:0: [sdb] Attached SCSI disk > > [ 258.009691] EXT4-fs (sda2): mounting ext3 file system using the ext4 subsystem > > [ 258.103029] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null) > > [ 258.177139] VFS: Mounted root (ext3 filesystem) readonly on device 8:2. > > [ 258.268770] devtmpfs: mounted > > [ 259.504165] stty (523) used greatest stack depth: 5544 bytes left > > [ 261.465793] systemd-udevd[610]: starting version 215 > > [ 262.297628] hme f009fba8 eth7: renamed from eth2 > > [ 262.430354] systemd-udevd[634]: renamed network interface eth2 to eth7 > > [ 262.430471] hme f0099bf4 eth9: renamed from eth1 > > [ 262.553566] systemd-udevd[648]: renamed network interface eth1 to eth9 > > [ 262.633511] hme f008d070 eth1: renamed from eth0 > > [ 262.697674] hwclock (658) used greatest stack depth: 4168 bytes left > > [ 262.773763] hme f00ab960 eth8: renamed from eth4 > > [ 262.873209] systemd-udevd[635]: renamed network interface eth0 to eth1 > > [ 262.918444] hme 0000:00:01.1 eth0: renamed from eth6 > > [ 262.918716] systemd-udevd[640]: renamed network interface eth4 to eth8 > > [ 263.053804] systemd-udevd[643]: renamed network interface eth6 to eth0 > > [ 263.114350] hme f01673a8 eth2: renamed from eth5 > > [ 263.192734] hme f00a5a84 eth10: renamed from eth3 > > [ 263.238837] systemd-udevd[641]: renamed network interface eth5 to eth2 > > [ 263.355961] systemd-udevd[639]: renamed network interface eth3 to eth10 > > [ 267.436399] Adding 787176k swap on /dev/sda4. Priority:-1 extents:1 across:787176k > > [ 267.775195] EXT4-fs (sda2): re-mounted. Opts: (null) > > [ 268.309702] EXT4-fs (sda2): re-mounted. Opts: errors=remount-ro > > [ 272.239364] EXT4-fs (sda1): mounting ext3 file system using the ext4 subsystem > > [ 272.321644] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null) > > [ 280.082651] eth0: Link is up using internal transceiver at 100Mb/s, Full Duplex. > > [ 284.153738] basename (1686) used greatest stack depth: 3752 bytes left > > > > -- > > Meelis Roos (mroos@xxxxxxxx) > ---end quoted text--- > > -- To unsubscribe from this list: send the line "unsubscribe linux-scsi" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html