I got below failure while my code was printk()ing so frequently.
[ 49.931115] left_op=38 right_op=48 left.type=1 right.type=1
[ 49.931550] 3562::not matched
[ 49.931559] left_op=38 right_op=48 left.type=1 right.type=1
[ 49.931561] 3562::not matched
[ 100.212171] BUG: soft lockup - CPU#0 stuck for 23s! [sh:3219]
[ 100.212171] Modules linked in: binfmt_misc ccsecurity [last unloaded: scsi_wait_scan]
[ 100.212171] irq event stamp: 42407026
[ 100.212171] hardirqs last enabled at (42407025): [<c139a185>] _raw_spin_unlock_irqrestore+0x35/0x60
[ 100.212171] hardirqs last disabled at (42407026): [<c139a604>] apic_timer_interrupt+0x28/0x34
[ 100.212171] softirqs last enabled at (42405952): [<c1040cb1>] __do_softirq+0xe1/0x130
[ 100.212171] softirqs last disabled at (42405947): [<c1004ad7>] do_softirq+0x87/0xd0
[ 100.212171] Modules linked in: binfmt_misc ccsecurity [last unloaded: scsi_wait_scan]
[ 100.212171]
[ 100.212171] Pid: 3219, comm: sh Not tainted 3.2.6-ccs-dev #1 VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform
[ 100.212171] EIP: 0060:[<c139a187>] EFLAGS: 00000282 CPU: 0
[ 100.212171] EIP is at _raw_spin_unlock_irqrestore+0x37/0x60
[ 100.212171] EAX: d7b9a6a0 EBX: c150ec60 ECX: 00000006 EDX: d7b9ab28
[ 100.212171] ESI: 00000282 EDI: 00001e01 EBP: dd725d8c ESP: dd725d84
[ 100.212171] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
[ 100.212171] Process sh (pid: 3219, ti=dd724000 task=d7b9a6a0 task.ti=dd724000)
[ 100.212171] Stack:
[ 100.212171] 00129e02 00000000 dd725db0 c103b825 00000001 ffffc000 00000282 00129e02
[ 100.212171] c1520380 dd725de8 00500001 dd725dc4 c103b9a2 dd978f30 dabb9db4 00000000
[ 100.212171] dd725df8 c1203fe0 d7b9a6a0 dd725dec dabb9db4 d7b9a6a0 00008802 00000000
[ 100.212171] Call Trace:
[ 100.212171] [<c103b825>] console_unlock+0x1e5/0x250
[ 100.212171] [<c103b9a2>] console_device+0x42/0x50
[ 100.212171] [<c1203fe0>] tty_open+0x3d0/0x4f0
[ 100.212171] [<c10ccdfa>] chrdev_open+0xba/0x190
[ 100.212171] [<c10c6c88>] __dentry_open+0x258/0x340
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10c6dde>] nameidata_to_filp+0x6e/0x80
[ 100.212171] [<c10ccd40>] ? cdev_put+0x20/0x20
[ 100.212171] [<c10d4e8f>] do_last+0x37f/0x780
[ 100.212171] [<c10d5f7b>] path_openat+0x9b/0x310
[ 100.212171] [<c10d62d0>] do_filp_open+0x30/0x80
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10e296c>] ? alloc_fd+0x14c/0x190
[ 100.212171] [<c10c80eb>] do_sys_open+0xeb/0x1b0
[ 100.212171] [<c10cd8e3>] ? sys_readlinkat+0x83/0xa0
[ 100.212171] [<c10c8219>] sys_open+0x29/0x40
[ 100.212171] [<c139aa4c>] sysenter_do_call+0x12/0x32
[ 100.212171] Code: 89 c3 89 74 24 04 8d 40 10 89 d6 ba 01 00 00 00 e8 ff 2d cd ff 89 d8 e8 98 11 e2 ff f7 c6 00 02 00 00 74 18 e8 1b 15 cd ff 56 9d <8b> 1c 24 8b 74 24 04 89 ec 5d c3 8d b6 00 00 00 00 56 9d e8 01
[ 100.212171] Call Trace:
[ 100.212171] [<c103b825>] console_unlock+0x1e5/0x250
[ 100.212171] [<c103b9a2>] console_device+0x42/0x50
[ 100.212171] [<c1203fe0>] tty_open+0x3d0/0x4f0
[ 100.212171] [<c10ccdfa>] chrdev_open+0xba/0x190
[ 100.212171] [<c10c6c88>] __dentry_open+0x258/0x340
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10c6dde>] nameidata_to_filp+0x6e/0x80
[ 100.212171] [<c10ccd40>] ? cdev_put+0x20/0x20
[ 100.212171] [<c10d4e8f>] do_last+0x37f/0x780
[ 100.212171] [<c10d5f7b>] path_openat+0x9b/0x310
[ 100.212171] [<c10d62d0>] do_filp_open+0x30/0x80
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10e296c>] ? alloc_fd+0x14c/0x190
[ 100.212171] [<c10c80eb>] do_sys_open+0xeb/0x1b0
[ 100.212171] [<c10cd8e3>] ? sys_readlinkat+0x83/0xa0
[ 100.212171] [<c10c8219>] sys_open+0x29/0x40
[ 100.212171] [<c139aa4c>] sysenter_do_call+0x12/0x32
[ 100.212171] Kernel panic - not syncing: softlockup: hung tasks
[ 100.212171] Pid: 3219, comm: sh Not tainted 3.2.6-ccs-dev #1
[ 100.212171] Call Trace:
[ 100.212171] [<c1396a90>] panic+0x57/0x166
[ 100.212171] [<c10879f1>] watchdog_timer_fn+0x171/0x180
[ 100.212171] [<c105a668>] hrtimer_run_queues+0xb8/0x270
[ 100.212171] [<c1087880>] ? touch_softlockup_watchdog_sync+0x30/0x30
[ 100.212171] [<c1046f08>] run_local_timers+0x8/0x20
[ 100.212171] [<c1046f4f>] update_process_times+0x2f/0x70
[ 100.212171] [<c1065b45>] tick_periodic+0x25/0x80
[ 100.212171] [<c1065bb9>] tick_handle_periodic+0x19/0x80
[ 100.212171] [<c101ca4f>] smp_apic_timer_interrupt+0x4f/0x90
[ 100.212171] [<c11ab574>] ? trace_hardirqs_off_thunk+0xc/0x18
[ 100.212171] [<c139a60b>] apic_timer_interrupt+0x2f/0x34
[ 100.212171] [<c139a187>] ? _raw_spin_unlock_irqrestore+0x37/0x60
[ 100.212171] [<c103b825>] console_unlock+0x1e5/0x250
[ 100.212171] [<c103b9a2>] console_device+0x42/0x50
[ 100.212171] [<c1203fe0>] tty_open+0x3d0/0x4f0
[ 100.212171] [<c10ccdfa>] chrdev_open+0xba/0x190
[ 100.212171] [<c10c6c88>] __dentry_open+0x258/0x340
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10c6dde>] nameidata_to_filp+0x6e/0x80
[ 100.212171] [<c10ccd40>] ? cdev_put+0x20/0x20
[ 100.212171] [<c10d4e8f>] do_last+0x37f/0x780
[ 100.212171] [<c10d5f7b>] path_openat+0x9b/0x310
[ 100.212171] [<c10d62d0>] do_filp_open+0x30/0x80
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10e296c>] ? alloc_fd+0x14c/0x190
[ 100.212171] [<c10c80eb>] do_sys_open+0xeb/0x1b0
[ 100.212171] [<c10cd8e3>] ? sys_readlinkat+0x83/0xa0
[ 100.212171] [<c10c8219>] sys_open+0x29/0x40
[ 100.212171] [<c139aa4c>] sysenter_do_call+0x12/0x32
[ 100.212171] ------------[ cut here ]------------
[ 100.212171] WARNING: at kernel/lockdep.c:2592 trace_hardirqs_on_caller+0x15d/0x1c0()
[ 100.212171] Hardware name: VMware Virtual Platform
[ 100.212171] Modules linked in: binfmt_misc ccsecurity [last unloaded: scsi_wait_scan]
[ 100.212171] Pid: 3219, comm: sh Not tainted 3.2.6-ccs-dev #1
[ 100.212171] Call Trace:
[ 100.212171] [<c103acbd>] warn_slowpath_common+0x6d/0xa0
[ 100.212171] [<c106b63d>] ? trace_hardirqs_on_caller+0x15d/0x1c0
[ 100.212171] [<c106b63d>] ? trace_hardirqs_on_caller+0x15d/0x1c0
[ 100.212171] [<c1396b60>] ? panic+0x127/0x166
[ 100.212171] [<c103ad0d>] warn_slowpath_null+0x1d/0x20
[ 100.212171] [<c106b63d>] trace_hardirqs_on_caller+0x15d/0x1c0
[ 100.212171] [<c106b6ab>] trace_hardirqs_on+0xb/0x10
[ 100.212171] [<c1396b60>] panic+0x127/0x166
[ 100.212171] [<c10879f1>] watchdog_timer_fn+0x171/0x180
[ 100.212171] [<c105a668>] hrtimer_run_queues+0xb8/0x270
[ 100.212171] [<c1087880>] ? touch_softlockup_watchdog_sync+0x30/0x30
[ 100.212171] [<c1046f08>] run_local_timers+0x8/0x20
[ 100.212171] [<c1046f4f>] update_process_times+0x2f/0x70
[ 100.212171] [<c1065b45>] tick_periodic+0x25/0x80
[ 100.212171] [<c1065bb9>] tick_handle_periodic+0x19/0x80
[ 100.212171] [<c101ca4f>] smp_apic_timer_interrupt+0x4f/0x90
[ 100.212171] [<c11ab574>] ? trace_hardirqs_off_thunk+0xc/0x18
[ 100.212171] [<c139a60b>] apic_timer_interrupt+0x2f/0x34
[ 100.212171] [<c139a187>] ? _raw_spin_unlock_irqrestore+0x37/0x60
[ 100.212171] [<c103b825>] console_unlock+0x1e5/0x250
[ 100.212171] [<c103b9a2>] console_device+0x42/0x50
[ 100.212171] [<c1203fe0>] tty_open+0x3d0/0x4f0
[ 100.212171] [<c10ccdfa>] chrdev_open+0xba/0x190
[ 100.212171] [<c10c6c88>] __dentry_open+0x258/0x340
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10c6dde>] nameidata_to_filp+0x6e/0x80
[ 100.212171] [<c10ccd40>] ? cdev_put+0x20/0x20
[ 100.212171] [<c10d4e8f>] do_last+0x37f/0x780
[ 100.212171] [<c10d5f7b>] path_openat+0x9b/0x310
[ 100.212171] [<c10d62d0>] do_filp_open+0x30/0x80
[ 100.212171] [<c139a1cd>] ? _raw_spin_unlock+0x1d/0x20
[ 100.212171] [<c10e296c>] ? alloc_fd+0x14c/0x190
[ 100.212171] [<c10c80eb>] do_sys_open+0xeb/0x1b0
[ 100.212171] [<c10cd8e3>] ? sys_readlinkat+0x83/0xa0
[ 100.212171] [<c10c8219>] sys_open+0x29/0x40
[ 100.212171] [<c139aa4c>] sysenter_do_call+0x12/0x32
[ 100.212171] ---[ end trace 982e5dcc48c519ad ]---
Lookingt at console_unlock()
1249 void console_unlock(void)
1250 {
1251 unsigned long flags;
1252 unsigned _con_start, _log_end;
1253 unsigned wake_klogd = 0, retry = 0;
1254
1255 if (console_suspended) {
1256 up(&console_sem);
1257 return;
1258 }
1259
1260 console_may_schedule = 0;
1261
1262 again:
1263 for ( ; ; ) {
1264 raw_spin_lock_irqsave(&logbuf_lock, flags);
1265 wake_klogd |= log_start - log_end;
1266 if (con_start == log_end)
1267 break; /* Nothing to print */
1268 _con_start = con_start;
1269 _log_end = log_end;
1270 con_start = log_end; /* Flush */
1271 raw_spin_unlock(&logbuf_lock);
1272 stop_critical_timings(); /* don't trace print latency */
1273 call_console_drivers(_con_start, _log_end);
1274 start_critical_timings();
1275 local_irq_restore(flags);
1276 }
1277 console_locked = 0;
1278
1279 /* Release the exclusive_console once it is used */
1280 if (unlikely(exclusive_console))
1281 exclusive_console = NULL;
1282
1283 raw_spin_unlock(&logbuf_lock);
1284
1285 up(&console_sem);
1286
1287 /*
1288 * Someone could have filled up the buffer again, so re-check if there's
1289 * something to flush. In case we cannot trylock the console_sem again,
1290 * there's a new owner and the console_unlock() from them will do the
1291 * flush, no worries.
1292 */
1293 raw_spin_lock(&logbuf_lock);
1294 if (con_start != log_end)
1295 retry = 1;
1296 raw_spin_unlock_irqrestore(&logbuf_lock, flags);
it is spinning here. Is
raw_spin_lock_irqsave(&logbuf_lock, flags);
raw_spin_unlock(&logbuf_lock);
up(&console_sem);
raw_spin_lock(&logbuf_lock);
raw_spin_unlock_irqrestore(&logbuf_lock, flags);
sequence safe even if debugging options are enabled?
1297
1298 if (retry && console_trylock())
1299 goto again;
1300
1301 if (wake_klogd)
1302 wake_up_klogd();
1303 }
$ grep LOCK .config
CONFIG_CLOCKSOURCE_WATCHDOG=y
CONFIG_GENERIC_CLOCKEVENTS=y
CONFIG_GENERIC_CLOCKEVENTS_BROADCAST=y
CONFIG_LOCKDEP_SUPPORT=y
# CONFIG_RWSEM_GENERIC_SPINLOCK is not set
CONFIG_HAVE_UNSTABLE_SCHED_CLOCK=y
CONFIG_BLOCK=y
# CONFIG_INLINE_SPIN_TRYLOCK is not set
# CONFIG_INLINE_SPIN_TRYLOCK_BH is not set
# CONFIG_INLINE_SPIN_LOCK is not set
# CONFIG_INLINE_SPIN_LOCK_BH is not set
# CONFIG_INLINE_SPIN_LOCK_IRQ is not set
# CONFIG_INLINE_SPIN_LOCK_IRQSAVE is not set
# CONFIG_INLINE_SPIN_UNLOCK is not set
# CONFIG_INLINE_SPIN_UNLOCK_BH is not set
# CONFIG_INLINE_SPIN_UNLOCK_IRQ is not set
# CONFIG_INLINE_SPIN_UNLOCK_IRQRESTORE is not set
# CONFIG_INLINE_READ_TRYLOCK is not set
# CONFIG_INLINE_READ_LOCK is not set
# CONFIG_INLINE_READ_LOCK_BH is not set
# CONFIG_INLINE_READ_LOCK_IRQ is not set
# CONFIG_INLINE_READ_LOCK_IRQSAVE is not set
# CONFIG_INLINE_READ_UNLOCK is not set
# CONFIG_INLINE_READ_UNLOCK_BH is not set
# CONFIG_INLINE_READ_UNLOCK_IRQ is not set
# CONFIG_INLINE_READ_UNLOCK_IRQRESTORE is not set
# CONFIG_INLINE_WRITE_TRYLOCK is not set
# CONFIG_INLINE_WRITE_LOCK is not set
# CONFIG_INLINE_WRITE_LOCK_BH is not set
# CONFIG_INLINE_WRITE_LOCK_IRQ is not set
# CONFIG_INLINE_WRITE_LOCK_IRQSAVE is not set
# CONFIG_INLINE_WRITE_UNLOCK is not set
# CONFIG_INLINE_WRITE_UNLOCK_BH is not set
# CONFIG_INLINE_WRITE_UNLOCK_IRQ is not set
# CONFIG_INLINE_WRITE_UNLOCK_IRQRESTORE is not set
CONFIG_GENERIC_CLOCKEVENTS_BUILD=y
CONFIG_GENERIC_CLOCKEVENTS_MIN_ADJUST=y
CONFIG_HAVE_MEMBLOCK=y
CONFIG_SPLIT_PTLOCK_CPUS=999999
# CONFIG_TELCLOCK is not set
CONFIG_I8253_LOCK=y
CONFIG_FILE_LOCKING=y
CONFIG_LOCKD=y
CONFIG_LOCKD_V4=y
CONFIG_LOCKUP_DETECTOR=y
CONFIG_HARDLOCKUP_DETECTOR=y
# CONFIG_BOOTPARAM_HARDLOCKUP_PANIC is not set
CONFIG_BOOTPARAM_HARDLOCKUP_PANIC_VALUE=0
CONFIG_BOOTPARAM_SOFTLOCKUP_PANIC=y
CONFIG_BOOTPARAM_SOFTLOCKUP_PANIC_VALUE=1
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_LOCK_ALLOC=y
CONFIG_PROVE_LOCKING=y
CONFIG_LOCKDEP=y
CONFIG_LOCK_STAT=y
CONFIG_DEBUG_LOCKDEP=y
CONFIG_DEBUG_LOCKING_API_SELFTESTS=y
# CONFIG_DEBUG_BLOCK_EXT_DEVT is not set
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[Other Archives]
[Linux Kernel Newbies]
[Linux Driver Development]
[Fedora Kernel]
[Linux Kernel Testers]
[Linux SH]
[Linux Omap]
[Linux Kbuild]
[Linux Tape]
[Linux Input]
[Linux Kernel Janitors]
[Linux Kernel Packagers]
[Linux Doc]
[Linux Man Pages]
[Linux API]
[Linux Memory Management]
[Linux Modules]
[Linux Standards]
[Kernel Announce]
[Netdev]
[Git]
[Linux PCI]
Linux CAN Development
[Linux I2C]
[Linux RDMA]
[Linux NUMA]
[Netfilter]
[Netfilter Devel]
[SELinux]
[Bugtraq]
[FIO]
[Linux Perf Users]
[Linux Serial]
[Linux PPP]
[Linux ISDN]
[Linux Next]
[Kernel Stable Commits]
[Linux Tip Commits]
[Kernel MM Commits]
[Linux Security Module]
[Filesystem Development]
[Ext3 Filesystem]
[Linux bcache]
[Ext4 Filesystem]
[Linux BTRFS]
[Linux CEPH Filesystem]
[Linux XFS]
[XFS]
[Linux NFS]
[Linux CIFS]
[Ecryptfs]
[Linux NILFS]
[Linux Cachefs]
[Reiser FS]
[Initramfs]
[Linux FB Devel]
[Linux OpenGL]
[DRI Devel]
[Fastboot]
[Linux RT Users]
[Linux RT Stable]
[eCos]
[Corosync]
[Linux Clusters]
[LVS Devel]
[Hot Plug]
[Linux Virtualization]
[KVM]
[KVM PPC]
[KVM ia64]
[Linux Containers]
[Linux Hexagon]
[Linux Cgroups]
[Util Linux]
[Wireless]
[Linux Bluetooth]
[Bluez Devel]
[Ethernet Bridging]
[Embedded Linux]
[Barebox]
[Linux MMC]
[Linux IIO]
[Sparse]
[Smatch]
[Linux Arch]
[x86 Platform Driver]
[Linux ACPI]
[Linux IBM ACPI]
[LM Sensors]
[CPU Freq]
[Linux Power Management]
[Linmodems]
[Linux DCCP]
[Linux SCTP]
[ALSA Devel]
[Linux USB]
[Linux PA RISC]
[Linux Samsung SOC]
[MIPS Linux]
[IBM S/390 Linux]
[ARM Linux]
[ARM Kernel]
[ARM MSM]
[Tegra Devel]
[Sparc Linux]
[Linux Security]
[Linux Sound]
[Linux Media]
[Video 4 Linux]
[Linux IRDA Users]
[Linux for the blind]
[Linux RAID]
[Linux ATA RAID]
[Device Mapper]
[Linux SCSI]
[SCSI Target Devel]
[Linux SCSI Target Infrastructure]
[Linux IDE]
[Linux SMP]
[Linux AXP]
[Linux Alpha]
[Linux M68K]
[Linux ia64]
[Linux 8086]
[Linux x86_64]
[Linux Config]
[Linux Apps]
[Linux MSDOS]
[Linux X.25]
[Linux Crypto]
[DM Crypt]
[Linux Trace Users]
[Linux Btrace]
[Linux Watchdog]
[Utrace Devel]
[Linux C Programming]
[Linux Assembly]
[Dash]
[DWARVES]
[Hail Devel]
[Linux Kernel Debugger]
[Linux gcc]
[Gcc Help]
[X.Org]
[Wine]
 |
 |
[Older Kernel Discussion]
[Yosemite National Park Forum]
[Large Format Photos]
[Gimp]
[Yosemite Photos]
[Stuff]