| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Mon, 17 Dec 2018 16:41:28 +0800
From: kernel test robot <rong.a.chen@...el.com>
To: Bart Van Assche <bvanassche@....org>
Cc: Peter Zijlstra <peterz@...radead.org>,
Waiman Long <longman@...hat.com>,
Johannes Berg <johannes@...solutions.net>,
LKML <linux-kernel@...r.kernel.org>,
Bart Van Assche <bart.vanassche@...disk.com>, lkp@...org
Subject: [LKP] [locking/lockdep] 15693f040b:
WARNING:at_kernel/locking/lockdep.c:#lockdep_free_key_range
FYI, we noticed the following commit (built with gcc-4.9):
commit: 15693f040b149ffff598cc048c2697b258d3901c ("locking/lockdep: Free lock classes that are no longer in use")
https://github.com/bvanassche/linux for-next
in testcase: locktorture
with following parameters:
runtime: 300s
test: cpuhotplug
test-description: This torture test consists of creating a number of kernel threads which acquire the lock and hold it for specific amount of time, thus simulating different critical region behaviors.
test-url: https://www.kernel.org/doc/Documentation/locking/locktorture.txt
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 512M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-------------------------------------------------------------+------------+------------+
| | b7001c6cce | 15693f040b |
+-------------------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 394 | 396 |
| WARNING:at_lib/debugobjects.c:#__debug_object_init | 394 | 396 |
| EIP:__debug_object_init | 394 | 396 |
| WARNING:possible_circular_locking_dependency_detected | 370 | 375 |
| WARNING:at_kernel/locking/lockdep.c:#lock_downgrade | 145 | 159 |
| EIP:lock_downgrade | 145 | 159 |
| BUG:soft_lockup-CPU##stuck_for#s | 24 | 21 |
| EIP:thread_lookup_test | 12 | 9 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 24 | 21 |
| EIP:memcmp | 3 | 3 |
| EIP:threadfunc | 4 | 2 |
| EIP:lock_acquire | 3 | 1 |
| EIP:lock_is_held_type | 2 | 2 |
| WARNING:at_net/sched/sch_generic.c:#dev_watchdog | 1 | |
| EIP:dev_watchdog | 1 | |
| WARNING:at_kernel/locking/lockdep.c:#lockdep_free_key_range | 0 | 22 |
| EIP:lockdep_free_key_range | 0 | 22 |
| EIP:lock_release | 0 | 2 |
| EIP:rht_deferred_worker | 0 | 2 |
+-------------------------------------------------------------+------------+------------+
[ 41.523113] WARNING: possible circular locking dependency detected
[ 41.524488] 4.20.0-rc6-00023-g15693f0 #1 Tainted: G W T
[ 41.525788] ------------------------------------------------------
[ 41.527034] lkp-setup-rootf/201 is trying to acquire lock:
[ 41.528420] (ptrval) (&(&port->lock)->rlock){-...}, at: tty_port_tty_get+0x20/0x50
[ 41.530377]
[ 41.530377] but task is already holding lock:
[ 41.531852] (ptrval) (&port_lock_key){-...}, at: serial8250_handle_irq+0x1d/0xd0
[ 41.533647]
[ 41.533647] which lock already depends on the new lock.
[ 41.533647]
[ 41.535350]
[ 41.535350] the existing dependency chain (in reverse order) is:
[ 41.536870]
[ 41.536870] -> #3 (&port_lock_key){-...}:
[ 41.538070]
[ 41.538070] -> #2 (console_owner){....}:
[ 41.539175]
[ 41.539175] -> #1 (&obj_hash[i].lock){-.-.}:
[ 41.540343]
[ 41.540343] -> #0 (&(&port->lock)->rlock){-...}:
[ 41.541832]
[ 41.541832] other info that might help us debug this:
[ 41.541832]
[ 41.543436] Chain exists of:
[ 41.543436] &(&port->lock)->rlock --> console_owner --> &port_lock_key
[ 41.543436]
[ 41.545757] Possible unsafe locking scenario:
[ 41.545757]
[ 41.546987] CPU0 CPU1
[ 41.547971] ---- ----
[ 41.548908] lock(&port_lock_key);
[ 41.549635] lock(console_owner);
[ 41.550824] lock(&port_lock_key);
[ 41.552075] lock(&(&port->lock)->rlock);
[ 41.552927]
[ 41.552927] *** DEADLOCK ***
[ 41.552927]
[ 41.554137] 6 locks held by lkp-setup-rootf/201:
[ 41.555602] #0: (ptrval) (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x31/0x40
[ 41.557907] #1: (ptrval) (&tty->atomic_write_lock){+.+.}, at: tty_write_lock+0x20/0x60
[ 41.560615] #2: (ptrval) (&tty->termios_rwsem){++++}, at: n_tty_write+0x6a/0x3e0
[ 41.562836] #3: (ptrval) (&ldata->output_lock){+.+.}, at: n_tty_write+0xf3/0x3e0
[ 41.565109] #4: (ptrval) (&(&i->lock)->rlock){-...}, at: serial8250_interrupt+0x1d/0xb0
[ 41.567598] #5: (ptrval) (&port_lock_key){-...}, at: serial8250_handle_irq+0x1d/0xd0
[ 41.570102]
[ 41.570102] stack backtrace:
[ 41.571472] CPU: 0 PID: 201 Comm: lkp-setup-rootf Tainted: G W T 4.20.0-rc6-00023-g15693f0 #1
[ 41.575755] Call Trace:
[ 41.576540] <IRQ>
[ 41.577181] ? dump_stack+0x16/0x26
[ 41.578273] ? print_circular_bug+0x18d/0x1e0
[ 41.579860] ? check_prev_add+0x72e/0xc00
[ 41.581405] ? print_shortest_lock_dependencies+0x1b0/0x1b0
[ 41.583118] ? __lock_acquire+0x10fc/0x1360
[ 41.584518] ? lock_acquire+0xbc/0x190
[ 41.585669] ? tty_port_tty_get+0x20/0x50
[ 41.586884] ? _raw_spin_lock_irqsave+0x4f/0x90
[ 41.588361] ? tty_port_tty_get+0x20/0x50
[ 41.589836] ? tty_port_tty_get+0x20/0x50
[ 41.590668] ? tty_port_default_wakeup+0xe/0x30
[ 41.591736] ? tty_port_tty_wakeup+0x10/0x20
[ 41.592611] ? uart_write_wakeup+0x17/0x30
[ 41.593431] ? serial8250_tx_chars+0x1a7/0x1f0
[ 41.594364] ? serial8250_handle_irq+0xa7/0xd0
[ 41.595431] ? serial8250_default_handle_irq+0x59/0x70
[ 41.596493] ? serial8250_interrupt+0x5c/0xb0
[ 41.597373] ? __handle_irq_event_percpu+0x6a/0x2a0
[ 41.598708] ? handle_irq_event_percpu+0x22/0x50
[ 41.600021] ? handle_irq_event+0x37/0x60
[ 41.600962] ? handle_level_irq+0x130/0x130
[ 41.602271] ? handle_edge_irq+0x69/0x1b0
[ 41.603347] ? handle_irq+0x61/0x80
[ 41.604100] </IRQ>
[ 41.604667] ? do_IRQ+0x57/0x120
[ 41.605323] ? common_interrupt+0xdd/0xec
[ 41.606186] ? common_interrupt+0xe4/0xec
[ 41.607052] ? trace_raw_output_preemptirq_template+0x4b/0x70
[ 41.608269] ? tty_paranoia_check+0x30/0x80
[ 41.609141] ? _raw_spin_unlock_irqrestore+0x57/0x70
[ 41.610160] ? uart_write+0x17d/0x1f0
[ 41.610926] ? n_tty_write+0x16a/0x3e0
[ 41.611867] ? __init_waitqueue_head+0x60/0x60
[ 41.612800] ? process_echoes+0x70/0x70
[ 41.613609] ? tty_write+0x144/0x2b0
[ 41.614382] ? process_echoes+0x70/0x70
[ 41.615263] ? release_one_tty+0xc0/0xc0
[ 41.616078] ? __vfs_write+0x2d/0x190
[ 41.616833] ? rw_verify_area+0x67/0x170
[ 41.617668] ? kvm_sched_clock_read+0x8/0x20
[ 41.618609] ? sched_clock_cpu+0x19/0xe0
[ 41.619398] ? vfs_write+0xb2/0x1d0
[ 41.620126] ? ksys_write+0x45/0xa0
[ 41.620854] ? sys_write+0x16/0x20
[ 41.621833] ? do_int80_syscall_32+0x6c/0x3a0
[ 41.623077] ? entry_INT80_32+0xda/0xda
-snb-quantal-i386-318, MAC 52:54:00:12:34:56, kernel 4.20.0-rc6-00023-g15693f0 1, serial console /dev/ttyS0
[ 41.981811] udevd[298]: starting version 175
[ 42.677599] WARNING: CPU: 0 PID: 362 at kernel/locking/lockdep.c:4480 lockdep_free_key_range+0x168/0x180
[ 42.680509] Modules linked in: qemu_fw_cfg
[ 42.681499] CPU: 0 PID: 362 Comm: modprobe Tainted: G W T 4.20.0-rc6-00023-g15693f0 #1
[ 42.683471] EIP: lockdep_free_key_range+0x168/0x180
[ 42.684919] Code: 20 0e ba 41 ff 75 f0 9d 8d 43 08 e8 12 91 ff ff e9 41 ff ff ff 90 8d 74 26 00 e8 43 89 ff ff 8d 76 00 e9 ea fe ff ff 8d 76 00 <0f> 0b e9 25 ff ff ff 90 0f 0b e9 1d ff ff ff 89 f6 8d bc 27 00 00
[ 42.689148] EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 5f862380
[ 42.690526] ESI: 60830000 EDI: 00004000 EBP: 503b9e68 ESP: 503b9e50
[ 42.691944] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068 EFLAGS: 00010246
[ 42.693488] CR0: 80050033 CR2: 3fa02eec CR3: 103a7000 CR4: 00040690
[ 42.694877] Call Trace:
[ 42.695592] ? load_module+0x5df/0x1740
[ 42.696427] ? map_vm_area+0x37/0x50
[ 42.697212] ? __might_fault+0x41/0xa0
[ 42.698071] ? remove_wait_queue+0x60/0x60
[ 42.698940] ? __might_fault+0x8b/0xa0
[ 42.699770] ? _copy_from_user+0x50/0x100
[ 42.700621] ? sys_init_module+0xfd/0x120
[ 42.701647] ? do_int80_syscall_32+0x6c/0x3a0
[ 42.702593] ? entry_INT80_32+0xda/0xda
[ 42.703367] irq event stamp: 0
[ 42.704042] hardirqs last enabled at (0): [<00000000>] (null)
[ 42.705693] hardirqs last disabled at (0): [<41054608>] copy_process+0x4c8/0x2300
[ 42.707347] softirqs last enabled at (0): [<41054608>] copy_process+0x4c8/0x2300
[ 42.709197] softirqs last disabled at (0): [<00000000>] (null)
[ 42.710411] ---[ end trace a1ac33b8d9cea0a1 ]---
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz
bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email
Thanks,
Rong Chen
View attachment "config-4.20.0-rc6-00023-g15693f0" of type "text/plain" (126133 bytes)
View attachment "job-script" of type "text/plain" (4293 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (17164 bytes)
Powered by blists - more mailing lists