Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Save mhiramat/0b1241f64c372b7ad7cb9521ac7f1adf to your computer and use it in GitHub Desktop.
Save mhiramat/0b1241f64c372b7ad7cb9521ac7f1adf to your computer and use it in GitHub Desktop.
/ # [ 1.854550] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
exit
[ 11.672737] ACPI: Preparing to enter system sleep state S5
[ 11.676601] reboot: Power down
[ 11.681659] ------------[ cut here ]------------
[ 11.682686] sched: Unexpected reschedule of offline CPU#6!
[ 11.683625] WARNING: CPU: 0 PID: 1262 at /home/mhiramat/ksrc/linux/arch/x86/kernel/smp.c:128 native_smp_send_reschedule+0x39/0x40
[ 11.685473] Modules linked in:
[ 11.686047] CPU: 0 PID: 1262 Comm: init Not tainted 4.19.5 #18
[ 11.687023] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.10.1-0-g8891697-prebuilt.qemu-project.org 04/01/2014
[ 11.688969] RIP: 0010:native_smp_send_reschedule+0x39/0x40
[ 11.689917] Code: 0f 92 c0 84 c0 74 15 48 8b 05 33 62 33 01 be fd 00 00 00 48 8b 40 30 e9 45 48 d7 00 89 fe 48 c7 c7 80 d6 2e 82 e8 d7 60 02 00 <0f> 0b c3 0f 1f 40 00 0f 1f 44 00 00 8b 05 85 b1 cf 01 85 c0 75 30
[ 11.692621] RSP: 0018:ffffc900003bfc58 EFLAGS: 00010086
[ 11.693458] RAX: 0000000000000000 RBX: ffff88801b248000 RCX: 0000000000000000
[ 11.694559] RDX: 00000000ffffffff RSI: 0000000000000001 RDI: 0000000000000001
[ 11.695616] RBP: ffff88801b248700 R08: 0000000000000000 R09: 0000000000000000
[ 11.696679] R10: ffffffff810ee0a8 R11: ffffffff81120b37 R12: 0000000000000046
[ 11.697696] R13: 0000000000022180 R14: 0000000000000000 R15: 0000000000000006
[ 11.698714] FS: 0000000000000000(0000) GS:ffff88801dc00000(0000) knlGS:0000000000000000
[ 11.700032] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 11.700877] CR2: 000000000283f008 CR3: 000000001f554000 CR4: 00000000000006f0
[ 11.702014] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 11.703250] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 11.704498] Call Trace:
[ 11.704974] try_to_wake_up+0x264/0x5b0
[ 11.705740] __wake_up_common+0x9a/0x160
[ 11.706473] complete+0x3b/0x50
[ 11.707002] mm_release+0xac/0x130
[ 11.707648] do_exit+0x153/0xc50
[ 11.708232] __se_sys_reboot+0x1a4/0x220
[ 11.709063] ? __lock_acquire+0x2b0/0x18c0
[ 11.709790] ? calculate_sigpending+0x22/0x40
[ 11.710587] ? __free_pages_ok+0x1fe/0x3c0
[ 11.711471] ? __free_pages_ok+0x20c/0x3c0
[ 11.712230] ? do_syscall_64+0x2a/0x460
[ 11.713026] do_syscall_64+0x6f/0x460
[ 11.713691] ? trace_hardirqs_off_thunk+0x1a/0x1c
[ 11.714453] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 11.715411] RIP: 0033:0x4aea36
[ 11.716004] Code: ff 0f 83 8d 7a 01 00 c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 63 d7 be 69 19 12 28 48 c7 c7 ad de e1 fe b8 a9 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 02 f3 c3 48 c7 c2 e0 ff ff ff f7 d8 64 89 02
[ 11.718823] RSP: 002b:00007ffd0a0922a8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a9
[ 11.720108] RAX: ffffffffffffffda RBX: 000000004321fedc RCX: 00000000004aea36
[ 11.721233] RDX: 000000004321fedc RSI: 0000000028121969 RDI: fffffffffee1dead
[ 11.722316] RBP: 000000000000000c R08: 0000000000000000 R09: 000000000000001a
[ 11.723502] R10: 0000000000000008 R11: 0000000000000246 R12: 0000000040009400
[ 11.724716] R13: 00007ffd0a092598 R14: 0000000000000000 R15: 0000000000000000
[ 11.725932] irq event stamp: 1354
[ 11.726495] hardirqs last enabled at (1353): [<ffffffff810019d9>] trace_hardirqs_on_thunk+0x1a/0x1c
[ 11.728023] hardirqs last disabled at (1354): [<ffffffff81adf9b0>] _raw_spin_lock_irqsave+0x20/0x60
[ 11.729354] softirqs last enabled at (1298): [<ffffffff81e00221>] __do_softirq+0x221/0x470
[ 11.730655] softirqs last disabled at (1275): [<ffffffff810bb1e3>] irq_exit+0xe3/0xf0
[ 11.731952] ---[ end trace 11bfb4c1722c711c ]---
[ 11.732929]
[ 11.732930] ======================================================
[ 11.732930] WARNING: possible circular locking dependency detected
[ 11.732931] 4.19.5 #18 Not tainted
[ 11.732931] ------------------------------------------------------
[ 11.732931] init/1262 is trying to acquire lock:
[ 11.732932] (____ptrval____) (console_owner){....}, at: console_unlock+0x184/0x650
[ 11.732933]
[ 11.732933] but task is already holding lock:
[ 11.732934] (____ptrval____) (&p->pi_lock){-.-.}, at: try_to_wake_up+0x3e/0x5b0
[ 11.732935]
[ 11.732935] which lock already depends on the new lock.
[ 11.732936]
[ 11.732936]
[ 11.732936] the existing dependency chain (in reverse order) is:
[ 11.732937]
[ 11.732937] -> #3 (&p->pi_lock){-.-.}:
[ 11.732938] try_to_wake_up+0x3e/0x5b0
[ 11.732939] __wake_up_common+0x9a/0x160
[ 11.732939] __wake_up_common_lock+0x7c/0xc0
[ 11.732939] tty_port_default_wakeup+0x1b/0x30
[ 11.732940] serial8250_tx_chars+0x1ea/0x200
[ 11.732940] serial8250_handle_irq.part.14+0xb3/0xd0
[ 11.732940] serial8250_default_handle_irq+0x4a/0x60
[ 11.732941] serial8250_interrupt+0x5d/0xd0
[ 11.732941] __handle_irq_event_percpu+0x5e/0x2f0
[ 11.732942] handle_irq_event_percpu+0x30/0x70
[ 11.732942] handle_irq_event+0x34/0x60
[ 11.732942] handle_edge_irq+0xdd/0x1b0
[ 11.732943] handle_irq+0x1c/0x30
[ 11.732943] do_IRQ+0x57/0x120
[ 11.732943] ret_from_intr+0x0/0x22
[ 11.732943] native_safe_halt+0x2/0x10
[ 11.732944] default_idle+0x1f/0x180
[ 11.732944] default_idle_call+0x24/0x40
[ 11.732944] do_idle+0x1c7/0x280
[ 11.732945] cpu_startup_entry+0x6f/0x80
[ 11.732945] start_secondary+0x1a4/0x1e0
[ 11.732945] secondary_startup_64+0xa4/0xb0
[ 11.732946]
[ 11.732946] -> #2 (&tty->write_wait){-...}:
[ 11.732947] __wake_up_common_lock+0x63/0xc0
[ 11.732948] tty_port_default_wakeup+0x1b/0x30
[ 11.732948] serial8250_tx_chars+0x1ea/0x200
[ 11.732948] serial8250_handle_irq.part.14+0xb3/0xd0
[ 11.732949] serial8250_default_handle_irq+0x4a/0x60
[ 11.732949] serial8250_interrupt+0x5d/0xd0
[ 11.732949] __handle_irq_event_percpu+0x5e/0x2f0
[ 11.732950] handle_irq_event_percpu+0x30/0x70
[ 11.732967] handle_irq_event+0x34/0x60
[ 11.732968] handle_edge_irq+0xdd/0x1b0
[ 11.732968] handle_irq+0x1c/0x30
[ 11.732968] do_IRQ+0x57/0x120
[ 11.732969] ret_from_intr+0x0/0x22
[ 11.732969] native_safe_halt+0x2/0x10
[ 11.732969] default_idle+0x1f/0x180
[ 11.732970] default_idle_call+0x24/0x40
[ 11.732970] do_idle+0x1c7/0x280
[ 11.732970] cpu_startup_entry+0x6f/0x80
[ 11.732971] start_secondary+0x1a4/0x1e0
[ 11.732971] secondary_startup_64+0xa4/0xb0
[ 11.732971]
[ 11.732971] -> #1 (&port_lock_key){-...}:
[ 11.732973] serial8250_console_write+0x25b/0x2d0
[ 11.732973] console_unlock+0x545/0x650
[ 11.732973] register_console+0x1b4/0x3b0
[ 11.732974] univ8250_console_init+0x24/0x27
[ 11.732974] console_init+0x196/0x2f1
[ 11.732974] start_kernel+0x381/0x4fe
[ 11.732975] secondary_startup_64+0xa4/0xb0
[ 11.732975]
[ 11.732975] -> #0 (console_owner){....}:
[ 11.732976] console_unlock+0x1e4/0x650
[ 11.732977] vprintk_emit+0xf2/0x2c0
[ 11.732977] printk+0x52/0x6e
[ 11.732977] __warn_printk+0x4b/0x90
[ 11.732978] native_smp_send_reschedule+0x39/0x40
[ 11.732978] try_to_wake_up+0x264/0x5b0
[ 11.732978] __wake_up_common+0x9a/0x160
[ 11.732979] complete+0x3b/0x50
[ 11.732979] mm_release+0xac/0x130
[ 11.732979] do_exit+0x153/0xc50
[ 11.732980] __se_sys_reboot+0x1a4/0x220
[ 11.732980] do_syscall_64+0x6f/0x460
[ 11.732980] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 11.732981]
[ 11.732981] other info that might help us debug this:
[ 11.732981]
[ 11.732982] Chain exists of:
[ 11.732982] console_owner --> &tty->write_wait --> &p->pi_lock
[ 11.732984]
[ 11.732984] Possible unsafe locking scenario:
[ 11.732984]
[ 11.732985] CPU0 CPU1
[ 11.732985] ---- ----
[ 11.732985] lock(&p->pi_lock);
[ 11.732986] lock(&tty->write_wait);
[ 11.732987] lock(&p->pi_lock);
[ 11.732988] lock(console_owner);
[ 11.732989]
[ 11.732989] *** DEADLOCK ***
[ 11.732989]
[ 11.732989] 5 locks held by init/1262:
[ 11.732990] #0: (____ptrval____) (system_transition_mutex){+.+.}, at: __se_sys_reboot+0x198/0x220
[ 11.732991] #1: (____ptrval____) (&(&p->alloc_lock)->rlock){+.+.}, at: mm_release+0x90/0x130
[ 11.732993] #2: (____ptrval____) (&x->wait#12){....}, at: complete+0x18/0x50
[ 11.732994] #3: (____ptrval____) (&p->pi_lock){-.-.}, at: try_to_wake_up+0x3e/0x5b0
[ 11.732996] #4: (____ptrval____) (console_lock){+.+.}, at: vprintk_emit+0xe9/0x2c0
[ 11.732998]
[ 11.732998] stack backtrace:
[ 11.732998] CPU: 0 PID: 1262 Comm: init Not tainted 4.19.5 #18
[ 11.732999] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.10.1-0-g8891697-prebuilt.qemu-project.org 04/01/2014
[ 11.732999] Call Trace:
[ 11.732999] dump_stack+0x7c/0xbb
[ 11.733000] print_circular_bug.isra.18+0x1cc/0x2b0
[ 11.733000] __lock_acquire+0x16ab/0x18c0
[ 11.733000] ? sprintf+0x51/0x70
[ 11.733001] ? lock_acquire+0xab/0x1c0
[ 11.733001] lock_acquire+0xab/0x1c0
[ 11.733001] ? console_unlock+0x184/0x650
[ 11.733002] console_unlock+0x1e4/0x650
[ 11.733002] ? console_unlock+0x184/0x650
[ 11.733002] vprintk_emit+0xf2/0x2c0
[ 11.733003] printk+0x52/0x6e
[ 11.733003] __warn_printk+0x4b/0x90
[ 11.733003] ? try_to_wake_up+0x3e/0x5b0
[ 11.733004] ? select_task_rq_fair+0x138/0xce0
[ 11.733004] native_smp_send_reschedule+0x39/0x40
[ 11.733004] try_to_wake_up+0x264/0x5b0
[ 11.733005] __wake_up_common+0x9a/0x160
[ 11.733005] complete+0x3b/0x50
[ 11.733005] mm_release+0xac/0x130
[ 11.733005] do_exit+0x153/0xc50
[ 11.733006] __se_sys_reboot+0x1a4/0x220
[ 11.733006] ? __lock_acquire+0x2b0/0x18c0
[ 11.733006] ? calculate_sigpending+0x22/0x40
[ 11.733007] ? __free_pages_ok+0x1fe/0x3c0
[ 11.733007] ? __free_pages_ok+0x20c/0x3c0
[ 11.733007] ? do_syscall_64+0x2a/0x460
[ 11.733008] do_syscall_64+0x6f/0x460
[ 11.733008] ? trace_hardirqs_off_thunk+0x1a/0x1c
[ 11.733008] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 11.733009] RIP: 0033:0x4aea36
[ 11.733009] Code: ff 0f 83 8d 7a 01 00 c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 63 d7 be 69 19 12 28 48 c7 c7 ad de e1 fe b8 a9 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 02 f3 c3 48 c7 c2 e0 ff ff ff f7 d8 64 89 02
[ 11.733010] RSP: 002b:00007ffd0a0922a8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a9
[ 11.733010] RAX: ffffffffffffffda RBX: 000000004321fedc RCX: 00000000004aea36
[ 11.733011] RDX: 000000004321fedc RSI: 0000000028121969 RDI: fffffffffee1dead
[ 11.733011] RBP: 000000000000000c R08: 0000000000000000 R09: 000000000000001a
[ 11.733012] R10: 0000000000000008 R11: 0000000000000246 R12: 0000000040009400
[ 11.733012] R13: 00007ffd0a092598 R14: 0000000000000000 R15: 0000000000000000
@mhiramat
Copy link
Author

This can track back to 4.17.
4.16 or older has another error.

https://gist.github.com/mhiramat/bfbdb775f8b8d5706f0c2002ee40427e

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment