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
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180428064314.GD6376@yexl-desktop>
Date:   Sat, 28 Apr 2018 14:43:14 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     Gaurav Kohli <gkohli@...eaurora.org>
Cc:     peterz@...radead.org, tglx@...utronix.de, mpe@...erman.id.au,
        mingo@...nel.org, bigeasy@...utronix.de,
        linux-kernel@...r.kernel.org, linux-arm-msm@...r.kernel.org,
        Gaurav Kohli <gkohli@...eaurora.org>,
        Neeraj Upadhyay <neeraju@...eaurora.org>, lkp@...org
Subject: [lkp-robot] [kthread/smpboot]  cad8e99675:
 inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage


FYI, we noticed the following commit (built with gcc-6):

commit: cad8e9967526d263d9a4f04ca763b2d76c045750 ("kthread/smpboot: Serialize kthread parking against wakeup")
url: https://github.com/0day-ci/linux/commits/Gaurav-Kohli/kthread-smpboot-Serialize-kthread-parking-against-wakeup/20180426-185404


in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+------------------------------------------------------------------+-----------+------------+
|                                                                  | v4.17-rc2 | cad8e99675 |
+------------------------------------------------------------------+-----------+------------+
| boot_successes                                                   | 60        | 0          |
| boot_failures                                                    | 34        | 10         |
| invoked_oom-killer:gfp_mask=0x                                   | 20        | 4          |
| Mem-Info                                                         | 20        | 4          |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 11        |            |
| Out_of_memory:Kill_process                                       | 9         | 4          |
| RIP:__clear_user                                                 | 1         | 1          |
| WARNING:inconsistent_lock_state                                  | 6         | 10         |
| inconsistent{HARDIRQ-ON-W}->{IN-HARDIRQ-W}usage                  | 6         |            |
| calltrace:neigh_periodic_work                                    | 2         |            |
| RIP:e1000_watchdog                                               | 4         |            |
| BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h   | 6         |            |
| calltrace:irq_exit                                               | 2         |            |
| IP-Config:Auto-configuration_of_network_failed                   | 8         | 4          |
| RIP:native_safe_halt                                             | 2         |            |
| inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage                  | 0         | 10         |
+------------------------------------------------------------------+-----------+------------+



[   21.664248] WARNING: inconsistent lock state
[   21.664989] 4.17.0-rc2-00001-gcad8e99 #1 Not tainted
[   21.665824] --------------------------------
[   21.666510] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[   21.667591] cpuhp/0/14 [HC0[0]:SC0[0]:HE1:SE1] takes:
[   21.668441]         (ptrval) (&p->pi_lock){?.-.}, at: smpboot_thread_fn+0x183/0x42c
[   21.669715] {IN-HARDIRQ-W} state was registered at:
[   21.670739]   lock_acquire+0x99/0xc9
[   21.671341]   _raw_spin_lock_irqsave+0x45/0x59
[   21.672062]   try_to_wake_up+0x8f/0x528
[   21.672733]   wake_up_process+0x10/0x12
[   21.673434]   hrtimer_wakeup+0x27/0x2c
[   21.674068]   __hrtimer_run_queues+0x163/0x1d4
[   21.674785]   hrtimer_run_queues+0x175/0x1b4
[   21.675518]   run_local_timers+0x30/0x7f
[   21.676206]   update_process_times+0x22/0x4f
[   21.686136]   tick_periodic+0xc4/0xca
[   21.689746]   tick_handle_periodic+0x29/0x7b
[   21.690518]   smp_apic_timer_interrupt+0x9d/0xb1
[   21.691318]   apic_timer_interrupt+0xf/0x20
[   21.692022]   native_safe_halt+0x6/0x8
[   21.692635]   default_idle+0x13/0x1c
[   21.693253]   arch_cpu_idle+0xa/0xc
[   21.697213]   default_idle_call+0x35/0x38
[   21.697891]   do_idle+0x181/0x2bf
[   21.698467]   cpu_startup_entry+0x1a/0x1c
[   21.699156]   rest_init+0x22c/0x232
[   21.699752]   start_kernel+0x4fc/0x520
[   21.700309]   x86_64_start_reservations+0x24/0x26
[   21.701909]   x86_64_start_kernel+0x6f/0x72
[   21.702553]   secondary_startup_64+0xa5/0xb0
[   21.703294] irq event stamp: 1401
[   21.703834] hardirqs last  enabled at (1401): [<ffffffffbd3ef4f3>] _raw_spin_unlock_irq+0x27/0x4b
[   21.705223] hardirqs last disabled at (1400): [<ffffffffbd3e69e3>] __schedule+0x23b/0xccc
[   21.706490] softirqs last  enabled at (1206): [<ffffffffbd60028d>] __do_softirq+0x28d/0x2db
[   21.707466] softirqs last disabled at (1181): [<ffffffffbcab67cf>] irq_exit+0x67/0x100
[   21.708244] 
[   21.708244] other info that might help us debug this:
[   21.709009]  Possible unsafe locking scenario:
[   21.709009] 
[   21.709919]        CPU0
[   21.710300]        ----
[   21.710696]   lock(&p->pi_lock);
[   21.711199]   <Interrupt>
[   21.711614]     lock(&p->pi_lock);
[   21.712146] 
[   21.712146]  *** DEADLOCK ***
[   21.712146] 
[   21.713108] no locks held by cpuhp/0/14.
[   21.713773] 
[   21.713773] stack backtrace:
[   21.714502] CPU: 0 PID: 14 Comm: cpuhp/0 Not tainted 4.17.0-rc2-00001-gcad8e99 #1
[   21.715747] Call Trace:
[   21.716174]  dump_stack+0x9c/0xe9
[   21.716756]  print_usage_bug+0x321/0x330
[   21.717533]  mark_lock+0x4f5/0x779
[   21.718122]  ? finish_task_switch+0x274/0x325
[   21.718653]  ? print_shortest_lock_dependencies+0x1c6/0x1c6
[   21.719230]  __lock_acquire+0x4a0/0x888
[   21.719606]  lock_acquire+0x99/0xc9
[   21.719992]  ? smpboot_thread_fn+0x183/0x42c
[   21.720457]  _raw_spin_lock+0x2d/0x3c
[   21.720885]  ? smpboot_thread_fn+0x183/0x42c
[   21.721285]  smpboot_thread_fn+0x183/0x42c
[   21.721703]  ? sort_range+0x1d/0x1d
[   21.722105]  ? preempt_count_sub+0x13/0xb5
[   21.722542]  ? schedule+0xdd/0xe9
[   21.722934]  kthread+0x1db/0x1eb
[   21.723245]  ? sort_range+0x1d/0x1d
[   21.723620]  ? kthread_create_on_node+0xa1/0xa1
[   21.724137]  ret_from_fork+0x24/0x30
[   21.730948] numa_remove_cpu cpu 0 node 0: mask now 1
[   21.733638] CPU 0 is now offline
[   21.735209] debug: unmapping init [mem 0xffffffffbe187000-0xffffffffbe2affff]
[   21.736225] Write protecting the kernel read-only data: 20480k
[   21.739451] debug: unmapping init [mem 0xffff88000ec07000-0xffff88000edfffff]
[   21.741223] debug: unmapping init [mem 0xffff88000f2dc000-0xffff88000f3fffff]
[   21.798549] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[   21.815648] random: init: uninitialized urandom read (12 bytes read)
[   21.876844] hwclock (101) used greatest stack depth: 27928 bytes left
[   21.886110] plymouthd (99) used greatest stack depth: 27656 bytes left
[   21.906815] sh (104) used greatest stack depth: 27640 bytes left
[   21.953005] mountall (108) used greatest stack depth: 26776 bytes left
[   21.976917] random: trinity: uninitialized urandom read (4 bytes read)
mountall: Event failed
[   22.102893] random: mountall: uninitialized urandom read (12 bytes read)
[   22.154174] init: Failed to create pty - disabling logging for job
[   22.155285] init: Temporary process spawn error: No such file or directory
[   22.191738] init: Failed to create pty - disabling logging for job
[   22.193058] init: Temporary process spawn error: No such file or directory
[   22.301682] init: Failed to create pty - disabling logging for job
[   22.302812] init: Temporary process spawn error: No such file or directory
[   22.307684] init: Failed to create pty - disabling logging for job
[   22.308793] init: Temporary process spawn error: No such file or directory
[   22.427189] init: Failed to create pty - disabling logging for job
[   22.428994] init: Temporary process spawn error: No such file or directory
[   22.439238] init: Failed to create pty - disabling logging for job
[   22.440420] init: Temporary process spawn error: No such file or directory
[   22.451555] init: Failed to create pty - disabling logging for job
[   22.452662] init: Temporary process spawn error: No such file or directory
[   22.477652] init: Failed to create pty - disabling logging for job


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



Thanks,
Xiaolong

View attachment "config-4.17.0-rc2-00001-gcad8e99" of type "text/plain" (94148 bytes)

View attachment "job-script" of type "text/plain" (4073 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (16768 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ