linux-kernel - [BUG][next-20170606][bisected 411fe24e6b] WARNING: CPU: 10 PID: 0 at kernel/time/tick-sched.c:791

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-next>] [day] [month] [year] [list]

Message-Id: <1496820413.15415.10.camel@abdul.in.ibm.com>
Date:   Wed, 07 Jun 2017 12:56:53 +0530
From:   Abdul Haleem <abdhalee@...ux.vnet.ibm.com>
To:     fweisbec@...il.com, linuxppc-dev <linuxppc-dev@...ts.ozlabs.org>
Cc:     linux-kernel <linux-kernel@...r.kernel.org>, tglx@...utronix.de,
        Stephen Rothwell <sfr@...b.auug.org.au>,
        sachinp <sachinp@...ux.vnet.ibm.com>
Subject: [BUG][next-20170606][bisected 411fe24e6b] WARNING: CPU: 10 PID: 0
 at kernel/time/tick-sched.c:791

Hi,

Test: Trinity (https://github.com/kernelslacker/trinity)
Machine : Power 8 PowerVM LPAR
Kernel : 4.12.0-rc4-next-20170606
gcc : version 5.2.1
config : attached

With commit (411fe24e6b : nohz: Fix collision between tick and other
hrtimers), a WARNING is seen while running trinity syscall fuzzer

In file kernel/time/tick-sched.c at line 791, a WARN_ON_ONCE is being
triggered from tick_nohz_stop_sched_tick function.

    /* Skip reprogram of event if its not changed */
    if (ts->tick_stopped && (expires == ts->next_tick)) {
        /* Sanity check: make sure clockevent is actually programmed */
        if (likely(dev->next_event <= ts->next_tick))
            goto out;

        WARN_ON_ONCE(1);
        printk_once("basemono: %llu ts->next_tick: %llu dev->next_event: %llu timer->active: %d timer->expires: %llu\n",
                basemono, ts->next_tick, dev->next_event,
                hrtimer_active(&ts->sched_timer), hrtimer_get_expires(&ts->sched_timer));
    }

Trace logs:
[22934.302780] ------------[ cut here ]------------
[22934.302787] WARNING: CPU: 10 PID: 0 at kernel/time/tick-sched.c:791
__tick_nohz_idle_enter+0x2e8/0x570
[22934.302788] Modules linked in: pseries_rng(E) rtc_generic(E)
vmx_crypto(E) autofs4(E) [last unloaded: torture]
[22934.302796] CPU: 10 PID: 0 Comm: swapper/10 Tainted: G      D W   E
4.12.0-rc4-next-20170606-autotest #1
[22934.302798] task: c000000777ddb800 task.stack: c000000777e50000
[22934.302799] NIP: c0000000001ac628 LR: c0000000001ac4b8 CTR:
c000000000025030
[22934.302801] REGS: c000000777e53740 TRAP: 0700   Tainted: G      D W
E    (4.12.0-rc4-next-20170606-autotest)
[22934.302802] MSR: 8000000000029033 <SF,EE,ME,IR,DR,RI,LE>
[22934.302808]   CR: 28002428  XER: 00000000
[22934.302809] CFAR: c0000000001ac514 SOFTE: 0 
               GPR00: c0000000001ac4b8 c000000777e539c0 c000000001536c00
7fffffffffffffff 
               GPR04: 0000000000000000 0000000000000240 c000000001576c00
c000000001401e10 
               GPR08: 0000000000632690 000014dbda7cb800 7fffeb2425c050ff
0000000000000000 
               GPR12: c000000000025030 c00000000e746900 c000000777e53f90
c000000777e4c080 
               GPR16: c000000000eecf00 c000000000ed83e8 c000000777e4c000
c000000777e4c000 
               GPR20: c000000001429b10 0000000000000001 0000000000000002
000014dbda7cb933 
               GPR24: c00000077fd80400 0000000000000001 000014dbda3faf00
000000000000000a 
               GPR28: c000000001571db8 000014dbda7cb862 000014dbda7cb800
c00000077fd91a10 
[22934.302835] NIP [c0000000001ac628] __tick_nohz_idle_enter+0x2e8/0x570
[22934.302837] LR [c0000000001ac4b8] __tick_nohz_idle_enter+0x178/0x570
[22934.302838] Call Trace:
[22934.302840] [c000000777e539c0] [c0000000001ac4b8]
__tick_nohz_idle_enter+0x178/0x570 (unreliable)
[22934.302844] [c000000777e53a80] [c0000000000fc274] irq_exit+0xf4/0x120
[22934.302847] [c000000777e53aa0] [c0000000000258b4] timer_interrupt
+0xa4/0xe0
[22934.302851] [c000000777e53ad0] [c000000000008f54] decrementer_common
+0x114/0x120
[22934.302855] --- interrupt: 901 at snooze_loop+0x1b0/0x1f0
                   LR = snooze_loop+0x54/0x1f0
[22934.302857] [c000000777e53df0] [c0000000009ed1b4] cpuidle_enter_state
+0x174/0x460
[22934.302860] [c000000777e53e50] [c000000000157bd0] call_cpuidle
+0x70/0xd0
[22934.302863] [c000000777e53e90] [c0000000001580d0] do_idle+0x2b0/0x310
[22934.302866] [c000000777e53f00] [c000000000158358] cpu_startup_entry
+0x38/0x40
[22934.302869] [c000000777e53f30] [c000000000047d60] start_secondary
+0x340/0x390
[22934.302872] [c000000777e53f90] [c00000000000a880]
start_secondary_resume+0x10/0x14
[22934.302873] Instruction dump:
[22934.302874] 409efef0 3860ffff 78630040 4bfffee4 60000000 60420000
e93f0058 7fbe4800 
[22934.302879] 409eff30 eaf80018 7fbeb800 409cff58 <0fe00000> 3ce20004
8927b740 2f890000 
[22934.302884] ---[ end trace aad28e52ad829bbd ]---
[22934.302887] basemono: 22934492000000 ts->next_tick: 22934496000000
dev->next_event: 22934496000307 timer->active: 1 timer->expires:
22934496000000

-- 
Regard's

Abdul Haleem
IBM Linux Technology Centre



View attachment "Tul-vm-config" of type "text/plain" (187078 bytes)