lkml.org 
[lkml]   [2022]   [Jul]   [3]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
SubjectRe: [syzbot] INFO: task hung in do_read_cache_folio
From
Hello,

syzbot tried to test the proposed patch but the build/boot failed:

77][ T1] UDP-Lite hash table entries: 4096 (order: 7, 655360 bytes, vmalloc)
[ 2.362158][ T1] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 2.364873][ T1] RPC: Registered named UNIX socket transport module.
[ 2.365877][ T1] RPC: Registered udp transport module.
[ 2.366631][ T1] RPC: Registered tcp transport module.
[ 2.367410][ T1] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 2.370320][ T1] NET: Registered PF_XDP protocol family
[ 2.371131][ T1] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
[ 2.372238][ T1] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
[ 2.373216][ T1] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[ 2.374290][ T1] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfefff window]
[ 2.376304][ T1] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 2.377453][ T1] PCI: CLS 0 bytes, default 64
[ 2.383304][ T1] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 2.384474][ T1] software IO TLB: mapped [mem 0x00000000b5a00000-0x00000000b9a00000] (64MB)
[ 2.385755][ T1] ACPI: bus type thunderbolt registered
[ 2.394707][ T1] kvm: no hardware support for 'kvm_intel'
[ 2.395523][ T1] has_svm: svm not available
[ 2.396210][ T1] kvm: no hardware support for 'kvm_amd'
[ 2.397006][ T1] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x206eb2111f5, max_idle_ns: 440795222471 ns
[ 2.399479][ T56] kworker/u4:1 (56) used greatest stack depth: 27744 bytes left
[ 2.401142][ T1] clocksource: Switched to clocksource tsc
[ 2.414938][ T61] kworker/u4:1 (61) used greatest stack depth: 26920 bytes left
[ 5.312580][ T1] Initialise system trusted keyrings
[ 5.314897][ T1] workingset: timestamp_bits=40 max_order=21 bucket_order=0
[ 5.348172][ T1] zbud: loaded
[ 5.355655][ T1] DLM installed
[ 5.361452][ T1] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 5.370982][ T1] NFS: Registering the id_resolver key type
[ 5.372080][ T1] Key type id_resolver registered
[ 5.372815][ T1] Key type id_legacy registered
[ 5.373771][ T1] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 5.374910][ T1] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 5.376045][ T1] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[ 5.383700][ T1] Key type cifs.spnego registered
[ 5.384564][ T1] Key type cifs.idmap registered
[ 5.385712][ T1] ntfs: driver 2.1.32 [Flags: R/W].
[ 5.387534][ T1] ntfs3: Max link count 4000
[ 5.388172][ T1] ntfs3: Enabled Linux POSIX ACLs support
[ 5.388984][ T1] ntfs3: Read-only LZX/Xpress compression included
[ 5.391202][ T1] efs: 1.0a - http://aeschi.ch.eu.org/efs/
[ 5.392215][ T1] jffs2: version 2.2. (NAND) (SUMMARY) © 2001-2006 Red Hat, Inc.
[ 5.396546][ T1] romfs: ROMFS MTD (C) 2007 Red Hat, Inc.
[ 5.397834][ T1] QNX4 filesystem 0.2.3 registered.
[ 5.398847][ T1] qnx6: QNX6 filesystem 1.0.0 registered.
[ 5.400490][ T1] fuse: init (API version 7.36)
[ 5.404181][ T1] orangefs_debugfs_init: called with debug mask: :none: :0:
[ 5.405575][ T1] orangefs_init: module version upstream loaded
[ 5.407203][ T1] JFS: nTxBlock = 8192, nTxLock = 65536
[ 5.419901][ T1] SGI XFS with ACLs, security attributes, realtime, quota, fatal assert, debug enabled
[ 5.431399][ T1] 9p: Installing v9fs 9p2000 file system support
[ 5.433445][ T1] NILFS version 2 loaded
[ 5.434036][ T1] befs: version: 0.9.3
[ 5.436837][ T1] ocfs2: Registered cluster interface o2cb
[ 5.437963][ T1] ocfs2: Registered cluster interface user
[ 5.439235][ T1] OCFS2 User DLM kernel interface loaded
[ 5.448869][ T1] gfs2: GFS2 installed
[ 5.460150][ T1] ceph: loaded (mds proto 32)
[ 5.471273][ T1] NET: Registered PF_ALG protocol family
[ 5.472216][ T1] xor: automatically using best checksumming function avx
[ 5.473484][ T1] async_tx: api initialized (async)
[ 5.474262][ T1] Key type asymmetric registered
[ 5.475158][ T1] Asymmetric key parser 'x509' registered
[ 5.475957][ T1] Asymmetric key parser 'pkcs8' registered
[ 5.476750][ T1] Key type pkcs7_test registered
[ 5.480210][ T1] alg: self-tests for CTR-KDF (hmac(sha256)) passed
[ 5.483969][ T1] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 240)
[ 5.484917][ T137] kworker/u4:2 (137) used greatest stack depth: 26816 bytes left
[ 5.486472][ T1] io scheduler mq-deadline registered
[ 5.489234][ T1] io scheduler kyber registered
[ 5.490614][ T1] io scheduler bfq registered
[ 5.503834][ T1] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 5.545233][ T1] ACPI: button: Power Button [PWRF]
[ 5.546867][ T1] input: Sleep Button as /devices/LNXSYSTM:00/LNXSLPBN:00/input/input1
[ 5.548614][ T1] ACPI: button: Sleep Button [SLPF]
[ 5.566119][ T1] ACPI: \_SB_.LNKC: Enabled at IRQ 11
[ 5.566992][ T1] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
[ 5.579637][ T1] ACPI: \_SB_.LNKD: Enabled at IRQ 10
[ 5.580460][ T1] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[ 5.593843][ T1] ACPI: \_SB_.LNKB: Enabled at IRQ 10
[ 5.595120][ T1] virtio-pci 0000:00:06.0: virtio_pci: leaving for legacy driver
[ 5.887643][ T1] N_HDLC line discipline registered with maxframe=4096
[ 5.888706][ T1] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[ 5.890475][ T1] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[ 5.896315][ T1] 00:04: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[ 5.900856][ T1] 00:05: ttyS2 at I/O 0x3e8 (irq = 6, base_baud = 115200) is a 16550A
[ 5.906084][ T1] 00:06: ttyS3 at I/O 0x2e8 (irq = 7, base_baud = 115200) is a 16550A
[ 5.920797][ T1] Non-volatile memory driver v1.3
[ 5.930201][ T1] Linux agpgart interface v0.103
[ 5.933661][ T1] ACPI: bus type drm_connector registered
[ 5.937360][ T1] [drm] Initialized vgem 1.0.0 20120112 for vgem on minor 0
[ 5.941912][ T1] [drm] Initialized vkms 1.0.0 20180514 for vkms on minor 1
[ 5.997414][ T1] Console: switching to colour frame buffer device 128x48
[ 6.015050][ T1] platform vkms: [drm] fb0: vkmsdrmfb frame buffer device
[ 6.016246][ T1] usbcore: registered new interface driver udl
[ 6.025204][ T1] page:ffffea0000736380 refcount:4 mapcount:0 mapping:ffff888140c812f8 index:0x0 pfn:0x1cd8e
[ 6.026731][ T1] memcg:ffff888140150000
[ 6.027762][ T1] aops:def_blk_aops ino:100000
[ 6.029614][ T1] flags: 0xfff00000002004(uptodate|private|node=0|zone=1|lastcpupid=0x7ff)
[ 6.031393][ T1] raw: 00fff00000002004 0000000000000000 dead000000000122 ffff888140c812f8
[ 6.032603][ T1] raw: 0000000000000000 ffff888011fae000 00000004ffffffff ffff888140150000
[ 6.033757][ T1] page dumped because: VM_BUG_ON_FOLIO(!folio_test_locked(folio))
[ 6.035031][ T1] page_owner tracks the page as allocated
[ 6.035852][ T1] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x140cc0(GFP_USER|__GFP_COMP), pid 1, tgid 1 (swapper/0), ts 6025000746, free_ts 5976256083
[ 6.037962][ T1] get_page_from_freelist+0x1290/0x3b70
[ 6.038738][ T1] __alloc_pages+0x1c7/0x510
[ 6.039361][ T1] alloc_page_interleave+0x1e/0x200
[ 6.040066][ T1] alloc_pages+0x2b1/0x310
[ 6.040709][ T1] folio_alloc+0x1c/0x70
[ 6.041292][ T1] do_read_cache_folio+0x3e6/0x800
[ 6.042022][ T1] read_cache_page+0x59/0x2a0
[ 6.042703][ T1] read_part_sector+0xf6/0x920
[ 6.043380][ T1] adfspart_check_ICS+0x9a/0x690
[ 6.044052][ T1] bdev_disk_changed+0x629/0xf60
[ 6.044790][ T1] blkdev_get_whole+0x18a/0x2d0
[ 6.045456][ T1] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 6.046205][ T1] blkdev_get_by_dev+0x6b/0x80
[ 6.046854][ T1] disk_scan_partitions+0x16a/0x200
[ 6.047561][ T1] device_add_disk+0xc3e/0xe20
[ 6.048211][ T1] brd_alloc.part.0+0x4db/0x7a0
[ 6.048884][ T1] page last free stack trace:
[ 6.049552][ T1] free_pcp_prepare+0x549/0xd20
[ 6.050208][ T1] free_unref_page+0x19/0x6a0
[ 6.050881][ T1] __vunmap+0x85d/0xd30
[ 6.051451][ T1] free_work+0x58/0x70
[ 6.052008][ T1] process_one_work+0x996/0x1610
[ 6.052690][ T1] worker_thread+0x665/0x1080
[ 6.053325][ T1] kthread+0x2e9/0x3a0
[ 6.053882][ T1] ret_from_fork+0x1f/0x30
[ 6.054558][ T1] ------------[ cut here ]------------
[ 6.055297][ T1] kernel BUG at mm/filemap.c:1557!
[ 6.055992][ T1] invalid opcode: 0000 [#1] PREEMPT SMP KASAN
[ 6.056802][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
[ 6.058413][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
[ 6.059746][ T1] RIP: 0010:folio_unlock+0xae/0xc0
[ 6.060438][ T1] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 72 69 0f 00 <0f> 0b 48 89 df e8 b8 fd 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 6.063239][ T1] RSP: 0018:ffffc900000678e0 EFLAGS: 00010293
[ 6.064086][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 6.064499][ T1] RDX: ffff888140170000 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 6.064499][ T1] RBP: ffffea0000736380 R08: 0000000000000003 R09: 000000000000ffff
[ 6.064499][ T1] R10: 000000000000ffff R11: 0000000000000001 R12: 0000000000000000
[ 6.064499][ T1] R13: dffffc0000000000 R14: 0000000000000000 R15: ffff88801cdbc180
[ 6.064499][ T1] FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
[ 6.064499][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.064499][ T1] CR2: ffff88823ffff000 CR3: 000000000ba8e000 CR4: 0000000000350ef0
[ 6.064499][ T1] Call Trace:
[ 6.064499][ T1] <TASK>
[ 6.064499][ T1] do_read_cache_folio+0x2f7/0x800
[ 6.064499][ T1] ? blkdev_writepages+0x20/0x20
[ 6.064499][ T1] read_cache_page+0x59/0x2a0
[ 6.064499][ T1] read_part_sector+0xf6/0x920
[ 6.064499][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.064499][ T1] adfspart_check_ICS+0x9a/0x690
[ 6.064499][ T1] ? __alloc_pages_slowpath.constprop.0+0x2160/0x2160
[ 6.064499][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.064499][ T1] ? snprintf+0xbb/0xf0
[ 6.064499][ T1] ? vsprintf+0x30/0x30
[ 6.064499][ T1] ? preempt_count_add+0x74/0x140
[ 6.064499][ T1] ? alloc_page_interleave+0x89/0x200
[ 6.064499][ T1] ? alloc_pages+0x1b2/0x310
[ 6.064499][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.064499][ T1] bdev_disk_changed+0x629/0xf60
[ 6.064499][ T1] ? iput.part.0+0x73/0x820
[ 6.064499][ T1] blkdev_get_whole+0x18a/0x2d0
[ 6.064499][ T1] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 6.064499][ T1] ? devcgroup_check_permission+0x1ab/0x440
[ 6.064499][ T1] blkdev_get_by_dev+0x6b/0x80
[ 6.064499][ T1] disk_scan_partitions+0x16a/0x200
[ 6.064499][ T1] device_add_disk+0xc3e/0xe20
[ 6.064499][ T1] brd_alloc.part.0+0x4db/0x7a0
[ 6.064499][ T1] ? brd_lookup_page+0x1d0/0x1d0
[ 6.064499][ T1] ? up_write+0x148/0x470
[ 6.064499][ T1] ? ramdisk_size+0x23/0x23
[ 6.064499][ T1] brd_init+0x1b8/0x24b
[ 6.064499][ T1] ? ramdisk_size+0x23/0x23
[ 6.064499][ T1] do_one_initcall+0x103/0x650
[ 6.064499][ T1] ? trace_event_raw_event_initcall_level+0x1f0/0x1f0
[ 6.064499][ T1] ? parameq+0xe0/0x170
[ 6.064499][ T1] kernel_init_freeable+0x6b1/0x73a
[ 6.064499][ T1] ? rest_init+0x270/0x270
[ 6.064499][ T1] kernel_init+0x1a/0x1d0
[ 6.064499][ T1] ? rest_init+0x270/0x270
[ 6.064499][ T1] ret_from_fork+0x1f/0x30
[ 6.064499][ T1] </TASK>
[ 6.064499][ T1] Modules linked in:
[ 6.064499][ C0] vkms_vblank_simulate: vblank timer overrun
[ 6.103289][ T1] ---[ end trace 0000000000000000 ]---
[ 6.104053][ T1] RIP: 0010:folio_unlock+0xae/0xc0
[ 6.104844][ T1] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 72 69 0f 00 <0f> 0b 48 89 df e8 b8 fd 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 6.107744][ T1] RSP: 0018:ffffc900000678e0 EFLAGS: 00010293
[ 6.108625][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 6.109722][ T1] RDX: ffff888140170000 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 6.110787][ T1] RBP: ffffea0000736380 R08: 0000000000000003 R09: 000000000000ffff
[ 6.111842][ T1] R10: 000000000000ffff R11: 0000000000000001 R12: 0000000000000000
[ 6.112892][ T1] R13: dffffc0000000000 R14: 0000000000000000 R15: ffff88801cdbc180
[ 6.113946][ T1] FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
[ 6.115160][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.116058][ T1] CR2: ffff88823ffff000 CR3: 000000000ba8e000 CR4: 0000000000350ef0
[ 6.117115][ T1] Kernel panic - not syncing: Fatal exception
[ 6.118428][ T1] Kernel Offset: disabled
[ 6.119019][ T1] Rebooting in 86400 seconds..


syzkaller build log:
go env (err=<nil>)
GO111MODULE="auto"
GOARCH="amd64"
GOBIN=""
GOCACHE="/syzkaller/.cache/go-build"
GOENV="/syzkaller/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/syzkaller/jobs/linux/gopath/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/syzkaller/jobs/linux/gopath"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.17"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/syzkaller/jobs/linux/gopath/src/github.com/google/syzkaller/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build2307476033=/tmp/go-build -gno-record-gcc-switches"

git status (err=<nil>)
HEAD detached at 1434eec0b
nothing to commit, working tree clean


go list -f '{{.Stale}}' ./sys/syz-sysgen | grep -q false || go install ./sys/syz-sysgen
make .descriptions
bin/syz-sysgen
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-fuzzer github.com/google/syzkaller/syz-fuzzer
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-stress github.com/google/syzkaller/tools/syz-stress
mkdir -p ./bin/linux_amd64
gcc -o ./bin/linux_amd64/syz-executor executor/executor.cc \
-m64 -O2 -pthread -Wall -Werror -Wparentheses -Wunused-const-variable -Wframe-larger-than=16384 -Wno-stringop-overflow -Wno-array-bounds -Wno-format-overflow -static-pie -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"1434eec0b84075b7246560cfa89f20cdb3d8077f\"


Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=1523de50080000


Tested on:

commit: 08986606 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=13810a58080000

\
 
 \ /
  Last update: 2022-07-03 08:27    [W:0.518 / U:0.608 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site