New issue
Advanced search Search tips

Issue 884938 link

Starred by 2 users
Status: Duplicate
Merged: issue 891024
Owner:
mutexlox@chromium.org
Closed: Oct 4
Cc:
smbar...@chromium.org
dgreid@chromium.org
za...@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

apic_timer_interrupt panic after coming back from suspend

Project Member Reported by smbar...@chromium.org, Sep 18 
The guest kernel panicked shortly after resuming. See logs here: https://listnr.corp.google.com/report/85656457019

2018-09-12T16:14:44.300102+02:00 INFO VM(5)[11732]: [36551.272275] watchdog: BUG: soft lockup - CPU#0 stuck for 30721s! [swapper/0:0]#015
2018-09-12T16:14:44.301586+02:00 INFO VM(5)[11732]: [36551.273264] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.14.67-07156-gc116f2c8c400 #1#015
2018-09-12T16:14:44.302521+02:00 INFO VM(5)[11732]: [36551.273264] task: ffffffff81e1a480 task.stack: ffffffff81e00000#015
2018-09-12T16:14:44.303056+02:00 INFO VM(5)[11732]: [36551.273264] RIP: 0010:native_safe_halt+0x2/0x3#015
2018-09-12T16:14:44.304336+02:00 INFO VM(5)[11732]: [36551.273264] RSP: 0018:ffffffff81e03ee0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10#015
2018-09-12T16:14:44.305538+02:00 INFO VM(5)[11732]: [36551.273264] RAX: ffffffff81e1a400 RBX: ffffffff81e1a480 RCX: 00000000000f7746#015
2018-09-12T16:14:44.306722+02:00 INFO VM(5)[11732]: [36551.273264] RDX: ffffffff81e3b880 RSI: 0000000000000000 RDI: 0000000000000000#015
2018-09-12T16:14:44.307940+02:00 INFO VM(5)[11732]: [36551.273264] RBP: 0000000000000000 R08: ffffffff81e0a328 R09: 0000000000021568#015
2018-09-12T16:14:44.308981+02:00 INFO VM(5)[11732]: [36551.273264] R10: 00000000000000f4 R11: ffffffff81648e98 R12: 0000000000000000#015
2018-09-12T16:14:44.310203+02:00 INFO VM(5)[11732]: [36551.273264] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000#015
2018-09-12T16:14:44.311658+02:00 INFO VM(5)[11732]: [36551.273264] FS:  0000000000000000(0000) GS:ffff880170800000(0000) knlGS:0000000000000000#015
2018-09-12T16:14:44.312645+02:00 INFO VM(5)[11732]: [36551.273264] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033#015
2018-09-12T16:14:44.313685+02:00 INFO VM(5)[11732]: [36551.273264] CR2: 00007fc5486858dc CR3: 0000000002014006 CR4: 00000000003606b0#015
2018-09-12T16:14:44.315400+02:00 INFO VM(5)[11732]: [36551.273264] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000#015
2018-09-12T16:14:44.316629+02:00 INFO VM(5)[11732]: [36551.273264] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400#015
2018-09-12T16:14:44.317317+02:00 INFO VM(5)[11732]: [36551.273264] Call Trace:#015
2018-09-12T16:14:44.317958+02:00 INFO VM(5)[11732]: [36551.273264]  default_idle+0x5/0x8#015
2018-09-12T16:14:44.318534+02:00 INFO VM(5)[11732]: [36551.273264]  do_idle+0xc7/0x189#015
2018-09-12T16:14:44.319219+02:00 INFO VM(5)[11732]: [36551.273264]  cpu_startup_entry+0x14/0x16#015
2018-09-12T16:14:44.319879+02:00 INFO VM(5)[11732]: [36551.273264]  start_kernel+0x315/0x362#015
2018-09-12T16:14:44.320596+02:00 INFO VM(5)[11732]: [36551.273264]  ? start_kernel+0x362/0x362#015
2018-09-12T16:14:44.321353+02:00 INFO VM(5)[11732]: [36551.273264]  secondary_startup_64+0xa5/0xb0#015
2018-09-12T16:14:44.324598+02:00 INFO VM(5)[11732]: [36551.273264] Code: 01 c9 f0 0f ba 36 15 0f ae f0 0f ba 26 03 0f 92 04 24 80 3c 24 00 74 0c 65 81 24 25 14 4d 01 00 ff ff ff 7f 48 83 c4 03 c3 fb f4 <c3> f4 c3 e8 12 5d a4 ff 84 c0 0f 84 ac 18 9d ff e9 fd 5c a4 ff #015
2018-09-12T16:14:44.325645+02:00 INFO VM(5)[11732]: [36551.273264] Kernel panic - not syncing: softlockup: hung tasks#015
2018-09-12T16:14:44.327221+02:00 INFO VM(5)[11732]: [36551.273264] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G             L  4.14.67-07156-gc116f2c8c400 #1#015
2018-09-12T16:14:44.327688+02:00 INFO VM(5)[11732]: [36551.273264] Call Trace:#015
2018-09-12T16:14:44.328094+02:00 INFO VM(5)[11732]: [36551.273264]  <IRQ>#015
2018-09-12T16:14:44.328728+02:00 INFO VM(5)[11732]: [36551.273264]  dump_stack+0x43/0x59#015
2018-09-12T16:14:44.329297+02:00 INFO VM(5)[11732]: [36551.273264]  panic+0xef/0x25b#015
2018-09-12T16:14:44.329997+02:00 INFO VM(5)[11732]: [36551.273264]  ? show_regs+0x117/0x126#015
2018-09-12T16:14:44.330740+02:00 INFO VM(5)[11732]: [36551.273264]  ? get_timestamp+0xa/0xa#015
2018-09-12T16:14:44.331517+02:00 INFO VM(5)[11732]: [36551.273264]  watchdog_timer_fn+0x1f1/0x1f1#015
2018-09-12T16:14:44.332319+02:00 INFO VM(5)[11732]: [36551.273264]  __hrtimer_run_queues+0x7e/0xdb#015
2018-09-12T16:14:44.333131+02:00 INFO VM(5)[11732]: [36551.273264]  hrtimer_interrupt+0x5e/0x11e#015
2018-09-12T16:14:44.333971+02:00 INFO VM(5)[11732]: [36551.273264]  smp_apic_timer_interrupt+0x5e/0x90#015
2018-09-12T16:14:44.334811+02:00 INFO VM(5)[11732]: [36551.273264]  apic_timer_interrupt+0x7d/0x90#015
2018-09-12T16:14:44.335132+02:00 INFO VM(5)[11732]: [36551.273264]  </IRQ>#015
2018-09-12T16:14:44.335973+02:00 INFO VM(5)[11732]: [36551.273264] RIP: 0010:native_safe_halt+0x2/0x3#015
2018-09-12T16:14:44.337314+02:00 INFO VM(5)[11732]: [36551.273264] RSP: 0018:ffffffff81e03ee0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10#015
2018-09-12T16:14:44.338622+02:00 INFO VM(5)[11732]: [36551.273264] RAX: ffffffff81e1a400 RBX: ffffffff81e1a480 RCX: 00000000000f7746#015
2018-09-12T16:14:44.340015+02:00 INFO VM(5)[11732]: [36551.273264] RDX: ffffffff81e3b880 RSI: 0000000000000000 RDI: 0000000000000000#015
2018-09-12T16:14:44.341296+02:00 INFO VM(5)[11732]: [36551.273264] RBP: 0000000000000000 R08: ffffffff81e0a328 R09: 0000000000021568#015
2018-09-12T16:14:44.342622+02:00 INFO VM(5)[11732]: [36551.273264] R10: 00000000000000f4 R11: ffffffff81648e98 R12: 0000000000000000#015
2018-09-12T16:14:44.343952+02:00 INFO VM(5)[11732]: [36551.273264] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000#015
2018-09-12T16:14:44.344755+02:00 INFO VM(5)[11732]: [36551.273264]  ? down_write_failed+0x170/0x170#015
2018-09-12T16:14:44.345386+02:00 INFO VM(5)[11732]: [36551.273264]  default_idle+0x5/0x8#015
2018-09-12T16:14:44.345956+02:00 INFO VM(5)[11732]: [36551.273264]  do_idle+0xc7/0x189#015
2018-09-12T16:14:44.346660+02:00 INFO VM(5)[11732]: [36551.273264]  cpu_startup_entry+0x14/0x16#015
2018-09-12T16:14:44.347367+02:00 INFO VM(5)[11732]: [36551.273264]  start_kernel+0x315/0x362#015
2018-09-12T16:14:44.348120+02:00 INFO VM(5)[11732]: [36551.273264]  ? start_kernel+0x362/0x362#015
2018-09-12T16:14:44.348967+02:00 INFO VM(5)[11732]: [36551.273264]  secondary_startup_64+0xa5/0xb0#015
2018-09-12T16:14:44.349878+02:00 INFO VM(5)[11732]: [36551.273264] Kernel Offset: disabled#015
2018-09-12T16:14:44.350337+02:00 INFO VM(5)[11732]: [36551.273264] Rebooting in 1 seconds..#015

Comment 1 by smbar...@chromium.org, Sep 26

Cc: smbar...@chromium.org
Owner: mutexlox@chromium.org
mutexlox@ I'm going to throw this one your way since I suspect it's related to our general tsc/time issues (from the "CPU#0 stuck for 30721s!" message). Feel free to kick this back to me if that ends up not being the case.

Comment 2 by mutexlox@chromium.org, Oct 4

Mergedinto: 891024
Status: Duplicate (was: Assigned)
I agree that this seems related; it also seems like the same issue as  https://crbug.com/891024 ; deduping this into that one.
►

Sign in to add a comment