* [syzbot] [kernel?] WARNING: ODEBUG bug in __mod_timer @ 2023-05-29 14:31 syzbot 2023-05-29 14:39 ` [PATCH] debugobjects: turn off debug_objects_enabled from debug_objects_oom() Tetsuo Handa 0 siblings, 1 reply; 5+ messages in thread From: syzbot @ 2023-05-29 14:31 UTC (permalink / raw) To: linux-kernel, syzkaller-bugs Hello, syzbot found the following issue on: HEAD commit: 44bf136283e5 Add linux-next specific files for 20230420 git tree: linux-next console output: https://syzkaller.appspot.com/x/log.txt?x=1026a757c80000 kernel config: https://syzkaller.appspot.com/x/.config?x=ba413c0527139246 dashboard link: https://syzkaller.appspot.com/bug?extid=7937ba6a50bdd00fffdf compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2 Unfortunately, I don't have any reproducer for this issue yet. Downloadable assets: disk image: https://storage.googleapis.com/syzbot-assets/db069eb0e403/disk-44bf1362.raw.xz vmlinux: https://storage.googleapis.com/syzbot-assets/9f9f4ca6cfb8/vmlinux-44bf1362.xz kernel image: https://storage.googleapis.com/syzbot-assets/e53d01b894f7/bzImage-44bf1362.xz IMPORTANT: if you fix the issue, please add the following tag to the commit: Reported-by: syzbot+7937ba6a50bdd00fffdf@syzkaller.appspotmail.com WARNING: CPU: 1 PID: 5171 at lib/debugobjects.c:505 debug_print_object+0x194/0x2c0 lib/debugobjects.c:505 Modules linked in: CPU: 1 PID: 5171 Comm: kworker/1:5 Not tainted 6.3.0-rc7-next-20230420-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/30/2023 Workqueue: rcu_gp wait_rcu_exp_gp RIP: 0010:debug_print_object+0x194/0x2c0 lib/debugobjects.c:505 Code: df 48 89 fe 48 c1 ee 03 80 3c 16 00 0f 85 c7 00 00 00 48 8b 14 dd c0 0f a7 8a 50 4c 89 ee 48 c7 c7 80 03 a7 8a e8 7c ec 35 fd <0f> 0b 58 83 05 86 75 63 0a 01 48 83 c4 20 5b 5d 41 5c 41 5d 41 5e RSP: 0018:ffffc900056af890 EFLAGS: 00010282 RAX: 0000000000000000 RBX: 0000000000000005 RCX: 0000000000000000 RDX: ffff88801e71d7c0 RSI: ffffffff814be0c7 RDI: 0000000000000001 RBP: 0000000000000001 R08: 0000000000000001 R09: 0000000000000000 R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff8a4ecb40 R13: ffffffff8aa70a60 R14: ffffc900056af950 R15: ffffffff817267d0 FS: 0000000000000000(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 0000000020404030 CR3: 000000002bc8b000 CR4: 00000000003526e0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: <TASK> debug_object_assert_init+0x20f/0x310 lib/debugobjects.c:912 debug_timer_assert_init kernel/time/timer.c:792 [inline] debug_assert_init kernel/time/timer.c:837 [inline] __mod_timer+0x9b/0xe80 kernel/time/timer.c:1020 schedule_timeout+0x149/0x2b0 kernel/time/timer.c:2166 synchronize_rcu_expedited_wait_once kernel/rcu/tree_exp.h:572 [inline] synchronize_rcu_expedited_wait kernel/rcu/tree_exp.h:624 [inline] rcu_exp_wait_wake+0x2ae/0x1550 kernel/rcu/tree_exp.h:693 process_one_work+0x99a/0x15e0 kernel/workqueue.c:2405 worker_thread+0x67d/0x10c0 kernel/workqueue.c:2552 kthread+0x33e/0x440 kernel/kthread.c:379 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308 </TASK> --- This report is generated by a bot. It may contain errors. See https://goo.gl/tpsmEJ for more information about syzbot. syzbot engineers can be reached at syzkaller@googlegroups.com. syzbot will keep track of this issue. See: https://goo.gl/tpsmEJ#status for how to communicate with syzbot. If the bug is already fixed, let syzbot know by replying with: #syz fix: exact-commit-title If you want to change bug's subsystems, reply with: #syz set subsystems: new-subsystem (See the list of subsystem names on the web dashboard) If the bug is a duplicate of another bug, reply with: #syz dup: exact-subject-of-another-report If you want to undo deduplication, reply with: #syz undup ^ permalink raw reply [flat|nested] 5+ messages in thread
* [PATCH] debugobjects: turn off debug_objects_enabled from debug_objects_oom() 2023-05-29 14:31 [syzbot] [kernel?] WARNING: ODEBUG bug in __mod_timer syzbot @ 2023-05-29 14:39 ` Tetsuo Handa 2023-06-06 22:35 ` Thomas Gleixner 0 siblings, 1 reply; 5+ messages in thread From: Tetsuo Handa @ 2023-05-29 14:39 UTC (permalink / raw) To: syzbot, syzkaller-bugs, Thomas Gleixner Cc: linux-kernel, Stephen Boyd, Andrew Morton, Peter Zijlstra, wuchi syzbot is reporting false positive ODEBUG message immediately after ODEBUG was disabled due to OOM. [ 1062.309646][T22911] ODEBUG: Out of memory. ODEBUG disabled [ 1062.886755][ T5171] ------------[ cut here ]------------ [ 1062.892770][ T5171] ODEBUG: assert_init not available (active state 0) object: ffffc900056afb20 object type: timer_list hint: process_timeout+0x0/0x40 This race happened because debug_objects_oom() emitted OOM message but did not turn off debug_objects_enabled, and debug_print_object() did not check debug_objects_enabled when calling WARN(). CPU 0 [ T5171] CPU 1 [T22911] -------------- -------------- debug_object_assert_init() { if (!debug_objects_enabled) return; db = get_bucket((unsigned long) addr); // Finds a bucket, but... debug_objects_oom() { pr_warn("Out of memory. ODEBUG disabled\n"); // all buckets get emptied here, and... hlist_move_list(&db->list, &freelist); } lookup_object_or_alloc(addr, db, descr, false, true) { lookup_object(addr, b) { return NULL; // this bucket is already empty. } if (!descr->is_static_object || !descr->is_static_object(addr)) return ERR_PTR(-ENOENT); } if (!obj) { // obj == ERR_PTR(-ENOENT) because non-static object. debug_objects_oom(); return; } debug_print_object(&o, "assert_init") { // False positive due to not checking debug_objects_enabled. WARN(1, KERN_ERR "ODEBUG: %s %s (active state %u) " "object: %p object type: %s hint: %pS\n", ...); } } Reported-by: syzbot <syzbot+7937ba6a50bdd00fffdf@syzkaller.appspotmail.com> Closes: https://syzkaller.appspot.com/bug?extid=7937ba6a50bdd00fffdf Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> --- lib/debugobjects.c | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/lib/debugobjects.c b/lib/debugobjects.c index 984985c39c9b..63974e9edac5 100644 --- a/lib/debugobjects.c +++ b/lib/debugobjects.c @@ -466,6 +466,7 @@ static void debug_objects_oom(void) unsigned long flags; int i; + debug_objects_enabled = 0; pr_warn("Out of memory. ODEBUG disabled\n"); for (i = 0; i < ODEBUG_HASH_SIZE; i++, db++) { @@ -502,10 +503,10 @@ static void debug_print_object(struct debug_obj *obj, char *msg) void *hint = descr->debug_hint ? descr->debug_hint(obj->object) : NULL; limit++; - WARN(1, KERN_ERR "ODEBUG: %s %s (active state %u) " - "object: %p object type: %s hint: %pS\n", - msg, obj_states[obj->state], obj->astate, - obj->object, descr->name, hint); + WARN(debug_objects_enabled, KERN_ERR + "ODEBUG: %s %s (active state %u) object: %p object type: %s hint: %pS\n", + msg, obj_states[obj->state], obj->astate, + obj->object, descr->name, hint); } debug_objects_warnings++; } -- 2.18.4 ^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH] debugobjects: turn off debug_objects_enabled from debug_objects_oom() 2023-05-29 14:39 ` [PATCH] debugobjects: turn off debug_objects_enabled from debug_objects_oom() Tetsuo Handa @ 2023-06-06 22:35 ` Thomas Gleixner 2023-06-07 10:19 ` [PATCH v2] debugobjects: recheck debug_objects_enabled before reporting Tetsuo Handa 0 siblings, 1 reply; 5+ messages in thread From: Thomas Gleixner @ 2023-06-06 22:35 UTC (permalink / raw) To: Tetsuo Handa, syzbot, syzkaller-bugs Cc: linux-kernel, Stephen Boyd, Andrew Morton, Peter Zijlstra, wuchi Tetsuo! On Mon, May 29 2023 at 23:39, Tetsuo Handa wrote: > syzbot is reporting false positive ODEBUG message immediately after > ODEBUG was disabled due to OOM. > > [ 1062.309646][T22911] ODEBUG: Out of memory. ODEBUG disabled > [ 1062.886755][ T5171] ------------[ cut here ]------------ > [ 1062.892770][ T5171] ODEBUG: assert_init not available (active state 0) object: ffffc900056afb20 object type: timer_list hint: process_timeout+0x0/0x40 > > This race happened because debug_objects_oom() emitted OOM message but did > not turn off debug_objects_enabled, and debug_print_object() did not check > debug_objects_enabled when calling WARN(). > > CPU 0 [ T5171] CPU 1 [T22911] > -------------- -------------- > debug_object_assert_init() { > if (!debug_objects_enabled) > return; > db = get_bucket((unsigned long) addr); // Finds a bucket, but... > debug_objects_oom() { > pr_warn("Out of memory. ODEBUG disabled\n"); > // all buckets get emptied here, and... > hlist_move_list(&db->list, &freelist); > } > lookup_object_or_alloc(addr, db, descr, false, true) { > lookup_object(addr, b) { > return NULL; // this bucket is already empty. > } > if (!descr->is_static_object || !descr->is_static_object(addr)) > return ERR_PTR(-ENOENT); > } > if (!obj) { // obj == ERR_PTR(-ENOENT) because non-static object. > debug_objects_oom(); > return; > } > debug_print_object(&o, "assert_init") { > // False positive due to not checking debug_objects_enabled. > WARN(1, KERN_ERR "ODEBUG: %s %s (active state %u) " > "object: %p object type: %s hint: %pS\n", ...); > } > } The above is undecodable gibberish. Something like this is completely sufficient: CPU 0 [ T5171] CPU 1 [T22911] -------------- -------------- debug_object_assert_init() { db = get_bucket(addr); debug_objects_oom() { pr_warn("Out of memory. ODEBUG disabled\n"); // all buckets get emptied here } lookup_object_or_alloc(addr, db, ...) // Due to OOM: return ERR_PTR(-ENOENT); ... // Emits assert_init message and warning debug_print_object(&o, "assert_init"); } And this: > This race happened because debug_objects_oom() emitted OOM message but did > not turn off debug_objects_enabled is completely wrong. Why? The place where debug_objects_enabled is set to 0 is way before debug_objects_oom() is invoked. That place _cannot_ invoke debug_objects_oom() because it holds a hash bucket lock. There are exactly three places which invoke debug_objects_oom() and for all three places the pattern is exactly the same: lock_bucket(); obj = lookup_object_or_alloc(); unlock_bucket(); if (!obj) debug_objects_oom(); The place which clears debug_objects_enabled is unsurprisingly lookup_object_or_alloc() itself, which _cannot_ invoke debug_objects_oom() because it is invoked with the hash bucket lock held. There is even a comment to that effect: /* Out of memory. Do the cleanup outside of the locked region */ debug_objects_enabled = 0; return NULL; So at the point where debug_objects_oom() is invoked @debug_objects_enabled is already 0. But you claim that this is required, right? > @@ -466,6 +466,7 @@ static void debug_objects_oom(void) > unsigned long flags; > int i; > > + debug_objects_enabled = 0; > pr_warn("Out of memory. ODEBUG disabled\n"); Q: What is setting a variable which is already 0 to 0 solving? A: Absolutely nothing Now this: > @@ -502,10 +503,10 @@ static void debug_print_object(struct de > void *hint = descr->debug_hint ? > descr->debug_hint(obj->object) : NULL; > limit++; > - WARN(1, KERN_ERR "ODEBUG: %s %s (active state %u) " > - "object: %p object type: %s hint: %pS\n", > - msg, obj_states[obj->state], obj->astate, > - obj->object, descr->name, hint); > + WARN(debug_objects_enabled, KERN_ERR > + "ODEBUG: %s %s (active state %u) object: %p object type: %s hint: %pS\n", > + msg, obj_states[obj->state], obj->astate, > + obj->object, descr->name, hint); > } Q: Why is this related to the WARN() itself? A: It's not related at all The obvious fix is: --- a/lib/debugobjects.c +++ b/lib/debugobjects.c @@ -498,6 +498,14 @@ static void debug_print_object(struct de const struct debug_obj_descr *descr = obj->descr; static int limit; + /* + * OOM handling is asynchronous for performance reasons. So the + * call site might have raced with a concurrent OOM which cleared + * the hash buckets. + */ + if (!debug_objects_enabled) + return; + if (limit < 5 && descr != descr_test) { void *hint = descr->debug_hint ? descr->debug_hint(obj->object) : NULL; Along with a understandable changelog, no? Thanks, tglx ^ permalink raw reply [flat|nested] 5+ messages in thread
* [PATCH v2] debugobjects: recheck debug_objects_enabled before reporting 2023-06-06 22:35 ` Thomas Gleixner @ 2023-06-07 10:19 ` Tetsuo Handa 2023-06-07 12:20 ` [tip: core/debugobjects] debugobjects: Recheck " tip-bot2 for Tetsuo Handa 0 siblings, 1 reply; 5+ messages in thread From: Tetsuo Handa @ 2023-06-07 10:19 UTC (permalink / raw) To: Thomas Gleixner, syzbot, syzkaller-bugs Cc: linux-kernel, Stephen Boyd, Andrew Morton, Peter Zijlstra, wuchi syzbot is reporting false positive ODEBUG message immediately after ODEBUG was disabled due to OOM. We should recheck debug_objects_enabled before reporting. [ 1062.309646][T22911] ODEBUG: Out of memory. ODEBUG disabled [ 1062.886755][ T5171] ------------[ cut here ]------------ [ 1062.892770][ T5171] ODEBUG: assert_init not available (active state 0) object: ffffc900056afb20 object type: timer_list hint: process_timeout+0x0/0x40 CPU 0 [ T5171] CPU 1 [T22911] -------------- -------------- debug_object_assert_init() { if (!debug_objects_enabled) return; db = get_bucket((unsigned long) addr); // Finds a bucket, but... lookup_object_or_alloc() { debug_objects_enabled = 0; return NULL; } debug_objects_oom() { pr_warn("Out of memory. ODEBUG disabled\n"); // all buckets get emptied here, and } lookup_object_or_alloc(addr, db, descr, false, true) { // this bucket is already empty. return ERR_PTR(-ENOENT); } // Emits false positive warning. debug_print_object(&o, "assert_init"); } Reported-by: syzbot <syzbot+7937ba6a50bdd00fffdf@syzkaller.appspotmail.com> Closes: https://syzkaller.appspot.com/bug?extid=7937ba6a50bdd00fffdf Suggested-by: Thomas Gleixner <tglx@linutronix.de> Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> --- Changes in v2: No need to turn off debug_objects_enabled from debug_objects_oom(). lib/debugobjects.c | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/lib/debugobjects.c b/lib/debugobjects.c index 984985c39c9b..ab3bbcb78471 100644 --- a/lib/debugobjects.c +++ b/lib/debugobjects.c @@ -498,6 +498,15 @@ static void debug_print_object(struct debug_obj *obj, char *msg) const struct debug_obj_descr *descr = obj->descr; static int limit; + /* + * Don't report if lookup_object_or_alloc() by the current thread + * failed because lookup_object_or_alloc()/debug_objects_oom() by + * concurrent thread turned off debug_objects_enabled and cleared + * the hash buckets. + */ + if (!debug_objects_enabled) + return; + if (limit < 5 && descr != descr_test) { void *hint = descr->debug_hint ? descr->debug_hint(obj->object) : NULL; -- 2.18.4 ^ permalink raw reply related [flat|nested] 5+ messages in thread
* [tip: core/debugobjects] debugobjects: Recheck debug_objects_enabled before reporting 2023-06-07 10:19 ` [PATCH v2] debugobjects: recheck debug_objects_enabled before reporting Tetsuo Handa @ 2023-06-07 12:20 ` tip-bot2 for Tetsuo Handa 0 siblings, 0 replies; 5+ messages in thread From: tip-bot2 for Tetsuo Handa @ 2023-06-07 12:20 UTC (permalink / raw) To: linux-tip-commits Cc: syzbot, Thomas Gleixner, Tetsuo Handa, x86, linux-kernel The following commit has been merged into the core/debugobjects branch of tip: Commit-ID: 8b64d420fe2450f82848178506d3e3a0bd195539 Gitweb: https://git.kernel.org/tip/8b64d420fe2450f82848178506d3e3a0bd195539 Author: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> AuthorDate: Wed, 07 Jun 2023 19:19:02 +09:00 Committer: Thomas Gleixner <tglx@linutronix.de> CommitterDate: Wed, 07 Jun 2023 14:16:12 +02:00 debugobjects: Recheck debug_objects_enabled before reporting syzbot is reporting false a positive ODEBUG message immediately after ODEBUG was disabled due to OOM. [ 1062.309646][T22911] ODEBUG: Out of memory. ODEBUG disabled [ 1062.886755][ T5171] ------------[ cut here ]------------ [ 1062.892770][ T5171] ODEBUG: assert_init not available (active state 0) object: ffffc900056afb20 object type: timer_list hint: process_timeout+0x0/0x40 CPU 0 [ T5171] CPU 1 [T22911] -------------- -------------- debug_object_assert_init() { if (!debug_objects_enabled) return; db = get_bucket(addr); lookup_object_or_alloc() { debug_objects_enabled = 0; return NULL; } debug_objects_oom() { pr_warn("Out of memory. ODEBUG disabled\n"); // all buckets get emptied here, and } lookup_object_or_alloc(addr, db, descr, false, true) { // this bucket is already empty. return ERR_PTR(-ENOENT); } // Emits false positive warning. debug_print_object(&o, "assert_init"); } Recheck debug_object_enabled in debug_print_object() to avoid that. Reported-by: syzbot <syzbot+7937ba6a50bdd00fffdf@syzkaller.appspotmail.com> Suggested-by: Thomas Gleixner <tglx@linutronix.de> Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> Signed-off-by: Thomas Gleixner <tglx@linutronix.de> Link: https://lore.kernel.org/r/492fe2ae-5141-d548-ebd5-62f5fe2e57f7@I-love.SAKURA.ne.jp Closes: https://syzkaller.appspot.com/bug?extid=7937ba6a50bdd00fffdf --- lib/debugobjects.c | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/lib/debugobjects.c b/lib/debugobjects.c index 984985c..a517256 100644 --- a/lib/debugobjects.c +++ b/lib/debugobjects.c @@ -498,6 +498,15 @@ static void debug_print_object(struct debug_obj *obj, char *msg) const struct debug_obj_descr *descr = obj->descr; static int limit; + /* + * Don't report if lookup_object_or_alloc() by the current thread + * failed because lookup_object_or_alloc()/debug_objects_oom() by a + * concurrent thread turned off debug_objects_enabled and cleared + * the hash buckets. + */ + if (!debug_objects_enabled) + return; + if (limit < 5 && descr != descr_test) { void *hint = descr->debug_hint ? descr->debug_hint(obj->object) : NULL; ^ permalink raw reply related [flat|nested] 5+ messages in thread
end of thread, other threads:[~2023-06-07 12:21 UTC | newest] Thread overview: 5+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2023-05-29 14:31 [syzbot] [kernel?] WARNING: ODEBUG bug in __mod_timer syzbot 2023-05-29 14:39 ` [PATCH] debugobjects: turn off debug_objects_enabled from debug_objects_oom() Tetsuo Handa 2023-06-06 22:35 ` Thomas Gleixner 2023-06-07 10:19 ` [PATCH v2] debugobjects: recheck debug_objects_enabled before reporting Tetsuo Handa 2023-06-07 12:20 ` [tip: core/debugobjects] debugobjects: Recheck " tip-bot2 for Tetsuo Handa
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox