[syzbot] [serial?] INFO: task hung in vcs_open (8)

[syzbot] [serial?] INFO: task hung in vcs_open (8)

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit:    88264981f208 Merge tag 'sched_ext-for-6.12' of git://git.k..
git tree:       upstream
console+strace: https://syzkaller.appspot.com/x/log.txt?x=1187c19f980000
kernel config:  https://syzkaller.appspot.com/x/.config?x=74ffdb3b3fad1a43
dashboard link: https://syzkaller.appspot.com/bug?extid=8a192e8d090fa9a31135
compiler:       Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=16aa3ca9980000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=1587c19f980000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/87eaf0ad6d60/disk-88264981.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/30c01cf8bc82/vmlinux-88264981.xz
kernel image: https://storage.googleapis.com/syzbot-assets/a1407424ea54/bzImage-88264981.xz
mounted in repro: https://storage.googleapis.com/syzbot-assets/a8a56914d1d8/mount_6.gz

Bisection is inconclusive: the issue happens on the oldest tested release.

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=16154c80580000
final oops:     https://syzkaller.appspot.com/x/report.txt?x=15154c80580000
console output: https://syzkaller.appspot.com/x/log.txt?x=11154c80580000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+8a192e8d090fa9a31135@syzkaller.appspotmail.com

INFO: task syz-executor199:5270 blocked for more than 147 seconds.
      Not tainted 6.11.0-syzkaller-08481-g88264981f208 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor199 state:D stack:27360 pid:5270  tgid:5255  ppid:5233   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5315 [inline]
 __schedule+0x1843/0x4ae0 kernel/sched/core.c:6674
 __schedule_loop kernel/sched/core.c:6751 [inline]
 schedule+0x14b/0x320 kernel/sched/core.c:6766
 schedule_timeout+0xb0/0x310 kernel/time/timer.c:2591
 ___down_common kernel/locking/semaphore.c:225 [inline]
 __down_common+0x346/0x7f0 kernel/locking/semaphore.c:246
 down+0x84/0xc0 kernel/locking/semaphore.c:63
 console_lock+0x145/0x1b0 kernel/printk/printk.c:2808
 vcs_open+0x5d/0xd0 drivers/tty/vt/vc_screen.c:763
 chrdev_open+0x521/0x600 fs/char_dev.c:414
 do_dentry_open+0x978/0x1460 fs/open.c:958
 vfs_open+0x3e/0x330 fs/open.c:1088
 do_open fs/namei.c:3774 [inline]
 path_openat+0x2c84/0x3590 fs/namei.c:3933
 do_filp_open+0x235/0x490 fs/namei.c:3960


---
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.
For information about bisection process see: https://goo.gl/tpsmEJ#bisection

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want syzbot to run the reproducer, reply with:
#syz test: git://repo/address.git branch-or-commit-hash
If you attach or paste a git patch, syzbot will apply it before testing.

If you want to overwrite report's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the report is a duplicate of another one, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

Re: [syzbot] [serial?] INFO: task hung in vcs_open (8)

[Lizhi Xu]

limit the nilfs erros message output

#syz test

diff --git a/fs/nilfs2/dir.c b/fs/nilfs2/dir.c
index fe5b1a30c509..0a89dda75414 100644
--- a/fs/nilfs2/dir.c
+++ b/fs/nilfs2/dir.c
@@ -32,6 +32,7 @@
 #include <linux/pagemap.h>
 #include "nilfs.h"
 #include "page.h"
+#include <linux/ratelimit.h>
 
 static inline unsigned int nilfs_rec_len_from_disk(__le16 dlen)
 {
@@ -115,6 +116,7 @@ static bool nilfs_check_folio(struct folio *folio, char *kaddr)
 	size_t limit = folio_size(folio);
 	struct nilfs_dir_entry *p;
 	char *error;
+	static DEFINE_RATELIMIT_STATE(rs, DEFAULT_RATELIMIT_INTERVAL * 5, 1);
 
 	if (dir->i_size < folio_pos(folio) + limit) {
 		limit = dir->i_size - folio_pos(folio);
@@ -148,9 +150,11 @@ static bool nilfs_check_folio(struct folio *folio, char *kaddr)
 	/* Too bad, we had an error */
 
 Ebadsize:
-	nilfs_error(sb,
-		    "size of directory #%lu is not a multiple of chunk size",
-		    dir->i_ino);
+	if (__ratelimit(&rs)) {
+		nilfs_error(sb,
+			    "size of directory #%lu is not a multiple of chunk size",
+			    dir->i_ino);
+	}
 	goto fail;
 Eshort:
 	error = "rec_len is smaller than minimal";
@@ -167,18 +171,22 @@ static bool nilfs_check_folio(struct folio *folio, char *kaddr)
 Einumber:
 	error = "disallowed inode number";
 bad_entry:
-	nilfs_error(sb,
+	if (__ratelimit(&rs)) {
+		nilfs_error(sb,
 		    "bad entry in directory #%lu: %s - offset=%lu, inode=%lu, rec_len=%zd, name_len=%d",
 		    dir->i_ino, error, (folio->index << PAGE_SHIFT) + offs,
 		    (unsigned long)le64_to_cpu(p->inode),
 		    rec_len, p->name_len);
+	}
 	goto fail;
 Eend:
 	p = (struct nilfs_dir_entry *)(kaddr + offs);
-	nilfs_error(sb,
-		    "entry in directory #%lu spans the page boundary offset=%lu, inode=%lu",
-		    dir->i_ino, (folio->index << PAGE_SHIFT) + offs,
-		    (unsigned long)le64_to_cpu(p->inode));
+	if (__ratelimit(&rs)) {
+		nilfs_error(sb,
+			    "entry in directory #%lu spans the page boundary offset=%lu, inode=%lu",
+			    dir->i_ino, (folio->index << PAGE_SHIFT) + offs,
+			    (unsigned long)le64_to_cpu(p->inode));
+	}
 fail:
 	return false;
 }

Re: [syzbot] [serial?] INFO: task hung in vcs_open (8)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
no output from test machine



Tested on:

commit:         075dbe9f Merge tag 'soc-ep93xx-dt-6.12' of git://git.k..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=1305aaa9980000
kernel config:  https://syzkaller.appspot.com/x/.config?x=f7f1af2ec501f918
dashboard link: https://syzkaller.appspot.com/bug?extid=8a192e8d090fa9a31135
compiler:       Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
patch:          https://syzkaller.appspot.com/x/patch.diff?x=158be59f980000

[PATCH] nilfs2: add ratelimiting to nilfs2 message

[Lizhi Xu]

Syzbot report a task hung in vcs_open.
When rec_len too small in nilfs_check_folio, it can result in a huge flood
of messages being sent to the console. It eventually caused tty to hung when
retrieving the console_lock().

Reported-by: syzbot+8a192e8d090fa9a31135@syzkaller.appspotmail.com
Closes: https://syzkaller.appspot.com/bug?extid=8a192e8d090fa9a31135
Signed-off-by: Lizhi Xu <lizhi.xu@windriver.com>
---
 fs/nilfs2/dir.c | 24 ++++++++++++++++--------
 1 file changed, 16 insertions(+), 8 deletions(-)

diff --git a/fs/nilfs2/dir.c b/fs/nilfs2/dir.c
index fe5b1a30c509..0a89dda75414 100644
--- a/fs/nilfs2/dir.c
+++ b/fs/nilfs2/dir.c
@@ -32,6 +32,7 @@
 #include <linux/pagemap.h>
 #include "nilfs.h"
 #include "page.h"
+#include <linux/ratelimit.h>
 
 static inline unsigned int nilfs_rec_len_from_disk(__le16 dlen)
 {
@@ -115,6 +116,7 @@ static bool nilfs_check_folio(struct folio *folio, char *kaddr)
 	size_t limit = folio_size(folio);
 	struct nilfs_dir_entry *p;
 	char *error;
+	static DEFINE_RATELIMIT_STATE(rs, DEFAULT_RATELIMIT_INTERVAL * 5, 1);
 
 	if (dir->i_size < folio_pos(folio) + limit) {
 		limit = dir->i_size - folio_pos(folio);
@@ -148,9 +150,11 @@ static bool nilfs_check_folio(struct folio *folio, char *kaddr)
 	/* Too bad, we had an error */
 
 Ebadsize:
-	nilfs_error(sb,
-		    "size of directory #%lu is not a multiple of chunk size",
-		    dir->i_ino);
+	if (__ratelimit(&rs)) {
+		nilfs_error(sb,
+			    "size of directory #%lu is not a multiple of chunk size",
+			    dir->i_ino);
+	}
 	goto fail;
 Eshort:
 	error = "rec_len is smaller than minimal";
@@ -167,18 +171,22 @@ static bool nilfs_check_folio(struct folio *folio, char *kaddr)
 Einumber:
 	error = "disallowed inode number";
 bad_entry:
-	nilfs_error(sb,
+	if (__ratelimit(&rs)) {
+		nilfs_error(sb,
 		    "bad entry in directory #%lu: %s - offset=%lu, inode=%lu, rec_len=%zd, name_len=%d",
 		    dir->i_ino, error, (folio->index << PAGE_SHIFT) + offs,
 		    (unsigned long)le64_to_cpu(p->inode),
 		    rec_len, p->name_len);
+	}
 	goto fail;
 Eend:
 	p = (struct nilfs_dir_entry *)(kaddr + offs);
-	nilfs_error(sb,
-		    "entry in directory #%lu spans the page boundary offset=%lu, inode=%lu",
-		    dir->i_ino, (folio->index << PAGE_SHIFT) + offs,
-		    (unsigned long)le64_to_cpu(p->inode));
+	if (__ratelimit(&rs)) {
+		nilfs_error(sb,
+			    "entry in directory #%lu spans the page boundary offset=%lu, inode=%lu",
+			    dir->i_ino, (folio->index << PAGE_SHIFT) + offs,
+			    (unsigned long)le64_to_cpu(p->inode));
+	}
 fail:
 	return false;
 }
-- 
2.43.0

Re: [PATCH] nilfs2: add ratelimiting to nilfs2 message

[Jiri Slaby]

You should have aimed this at the nilfs developers...

On 27. 09. 24, 4:13, Lizhi Xu wrote:
> Syzbot report a task hung in vcs_open.
> When rec_len too small in nilfs_check_folio, it can result in a huge flood
> of messages being sent to the console. It eventually caused tty to hung when
> retrieving the console_lock().
> 
> Reported-by: syzbot+8a192e8d090fa9a31135@syzkaller.appspotmail.com
> Closes: https://syzkaller.appspot.com/bug?extid=8a192e8d090fa9a31135
> Signed-off-by: Lizhi Xu <lizhi.xu@windriver.com>

-- 
js
suse labs

Re: [PATCH] nilfs2: add ratelimiting to nilfs2 message

[Lizhi Xu]

On Fri, 27 Sep 2024 06:59:22 +0200, Jiri Slaby wrote: 
> You should have aimed this at the nilfs developers...
I don't get it.

BR,
Lizhi

Re: [PATCH] nilfs2: add ratelimiting to nilfs2 message

[Jiri Slaby]

On 27. 09. 24, 11:16, Lizhi Xu wrote:
> On Fri, 27 Sep 2024 06:59:22 +0200, Jiri Slaby wrote:
>> You should have aimed this at the nilfs developers...
> I don't get it.

You are sending nilfs changes to tty maintainers which is not about right.

-- 
js
suse labs

Re: [PATCH] nilfs2: add ratelimiting to nilfs2 message

[Lizhi Xu]

On Fri, 27 Sep 2024 12:46:44 +0200, Jiri Slaby wrote:
> On 27. 09. 24, 11:16, Lizhi Xu wrote:
> > On Fri, 27 Sep 2024 06:59:22 +0200, Jiri Slaby wrote:
> >> You should have aimed this at the nilfs developers...
> > I don't get it.
> 
> You are sending nilfs changes to tty maintainers which is not about right.
Got it, Thanks.

BR,
Lizhi

Re: [syzbot] [serial?] INFO: task hung in vcs_open (8)

[Ryusuke Konishi]

On Fri, Sep 27, 2024 at 2:36 AM syzbot
<syzbot+8a192e8d090fa9a31135@syzkaller.appspotmail.com> wrote:
>
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit:    88264981f208 Merge tag 'sched_ext-for-6.12' of git://git.k..
> git tree:       upstream
> console+strace: https://syzkaller.appspot.com/x/log.txt?x=1187c19f980000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=74ffdb3b3fad1a43
> dashboard link: https://syzkaller.appspot.com/bug?extid=8a192e8d090fa9a31135
> compiler:       Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=16aa3ca9980000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=1587c19f980000
>
> Downloadable assets:
> disk image: https://storage.googleapis.com/syzbot-assets/87eaf0ad6d60/disk-88264981.raw.xz
> vmlinux: https://storage.googleapis.com/syzbot-assets/30c01cf8bc82/vmlinux-88264981.xz
> kernel image: https://storage.googleapis.com/syzbot-assets/a1407424ea54/bzImage-88264981.xz
> mounted in repro: https://storage.googleapis.com/syzbot-assets/a8a56914d1d8/mount_6.gz
>
> Bisection is inconclusive: the issue happens on the oldest tested release.
>
> bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=16154c80580000
> final oops:     https://syzkaller.appspot.com/x/report.txt?x=15154c80580000
> console output: https://syzkaller.appspot.com/x/log.txt?x=11154c80580000
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+8a192e8d090fa9a31135@syzkaller.appspotmail.com
>
> INFO: task syz-executor199:5270 blocked for more than 147 seconds.
>       Not tainted 6.11.0-syzkaller-08481-g88264981f208 #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor199 state:D stack:27360 pid:5270  tgid:5255  ppid:5233   flags:0x00004006
> Call Trace:
>  <TASK>
>  context_switch kernel/sched/core.c:5315 [inline]
>  __schedule+0x1843/0x4ae0 kernel/sched/core.c:6674
>  __schedule_loop kernel/sched/core.c:6751 [inline]
>  schedule+0x14b/0x320 kernel/sched/core.c:6766
>  schedule_timeout+0xb0/0x310 kernel/time/timer.c:2591
>  ___down_common kernel/locking/semaphore.c:225 [inline]
>  __down_common+0x346/0x7f0 kernel/locking/semaphore.c:246
>  down+0x84/0xc0 kernel/locking/semaphore.c:63
>  console_lock+0x145/0x1b0 kernel/printk/printk.c:2808
>  vcs_open+0x5d/0xd0 drivers/tty/vt/vc_screen.c:763
>  chrdev_open+0x521/0x600 fs/char_dev.c:414
>  do_dentry_open+0x978/0x1460 fs/open.c:958
>  vfs_open+0x3e/0x330 fs/open.c:1088
>  do_open fs/namei.c:3774 [inline]
>  path_openat+0x2c84/0x3590 fs/namei.c:3933
>  do_filp_open+0x235/0x490 fs/namei.c:3960
>
>
> ---
> 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.
> For information about bisection process see: https://goo.gl/tpsmEJ#bisection
>
> If the report is already addressed, let syzbot know by replying with:
> #syz fix: exact-commit-title
>
> If you want syzbot to run the reproducer, reply with:
> #syz test: git://repo/address.git branch-or-commit-hash
> If you attach or paste a git patch, syzbot will apply it before testing.
>
> If you want to overwrite report's subsystems, reply with:
> #syz set subsystems: new-subsystem
> (See the list of subsystem names on the web dashboard)
>
> If the report is a duplicate of another one, reply with:
> #syz dup: exact-subject-of-another-report
>
> If you want to undo deduplication, reply with:
> #syz undup
>

The problem caused by this reproducer seems to be an issue on the
nilfs side based on testing with Lizhi's patch (not all logs recorded
are like that), so I will add a nilfs tag:

#syz set subsystems: nilfs, serial

Ryusuke Konishi