On 2019/4/24 下午8:28, Gregory Malloff wrote: > > Hello, > > After 7 days, BTRFS crashed again with the same error: > > [Tue Apr 23 21:59:40 2019] ------------[ cut here ]------------ > [Tue Apr 23 21:59:40 2019] kernel BUG at fs/btrfs/ctree.c:3230! > [Tue Apr 23 21:59:40 2019] invalid opcode: 0000 [#1] SMP PTI > [Tue Apr 23 21:59:40 2019] CPU: 0 PID: 526 Comm: nfsd Not tainted > 4.19.0-4-amd64 #1 Debian 4.19.28-2 > [Tue Apr 23 21:59:40 2019] Hardware name: VMware, Inc. VMware Virtual > Platform/440BX Desktop Reference Platform, BIOS 6.00 09/17/2015 > [Tue Apr 23 21:59:40 2019] RIP: 0010:btrfs_set_item_key_safe+0x116/0x190 > [btrfs] > [Tue Apr 23 21:59:40 2019] Code: 48 8d 7c 24 17 48 89 44 24 20 0f b6 44 24 0e > 88 44 24 1f 48 8b 44 24 06 48 89 44 24 17 e8 c2 f3 ff ff 85 c0 0f 8f 46 ff ff > ff <0f> 0b 8d 43 ff 48 8d 74 24 06 4c 89 e7 b9 11 00 00 00 48 98 48 8d > [Tue Apr 23 21:59:40 2019] RSP: 0018:ffffb23fc082f6a0 EFLAGS: 00010246 > [Tue Apr 23 21:59:40 2019] RAX: 0000000000000000 RBX: 000000000000008d RCX: > 000000000c71b000 > [Tue Apr 23 21:59:40 2019] RDX: 000000000003996e RSI: ffffb23fc082f795 RDI: > ffffb23fc082f6b7 > [Tue Apr 23 21:59:40 2019] RBP: ffff9e9ec6bc95b0 R08: 0000000000001000 R09: > 0000000000004000 > [Tue Apr 23 21:59:40 2019] R10: 0000000000000000 R11: 00000000ffffffff R12: > ffff9e9e90957000 > [Tue Apr 23 21:59:40 2019] R13: ffffb23fc082f795 R14: 0000000000000000 R15: > 000000000d007000 > [Tue Apr 23 21:59:40 2019] FS: 0000000000000000(0000) > GS:ffff9e9efda00000(0000) knlGS:0000000000000000 > [Tue Apr 23 21:59:40 2019] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [Tue Apr 23 21:59:40 2019] CR2: 00007f8bddd7fae4 CR3: 00000000735de000 CR4: > 00000000000406f0 > [Tue Apr 23 21:59:40 2019] Call Trace: > [Tue Apr 23 21:59:40 2019] __btrfs_drop_extents+0x7ae/0xcf0 [btrfs] > [Tue Apr 23 21:59:40 2019] btrfs_log_changed_extents.isra.24+0x391/0x990 > [btrfs] > [Tue Apr 23 21:59:40 2019] btrfs_log_inode+0xb54/0x1240 [btrfs] > [Tue Apr 23 21:59:40 2019] ? __schedule+0x2aa/0x870 > [Tue Apr 23 21:59:40 2019] ? __switch_to_asm+0x34/0x70 > [Tue Apr 23 21:59:40 2019] btrfs_log_inode_parent+0x2a1/0xac0 [btrfs] > [Tue Apr 23 21:59:40 2019] ? wait_current_trans+0x2f/0xf0 [btrfs] > [Tue Apr 23 21:59:40 2019] ? refcount_inc_checked+0x5/0x30 > [Tue Apr 23 21:59:40 2019] ? join_transaction+0xec/0x410 [btrfs] > [Tue Apr 23 21:59:40 2019] btrfs_log_dentry_safe+0x4a/0x70 [btrfs] > [Tue Apr 23 21:59:40 2019] btrfs_sync_file+0x1cb/0x3d0 [btrfs] > [Tue Apr 23 21:59:40 2019] btrfs_file_write_iter+0x495/0x590 [btrfs] > [Tue Apr 23 21:59:40 2019] ? apparmor_cred_prepare+0x4c/0x60 > [Tue Apr 23 21:59:40 2019] do_iter_readv_writev+0x13a/0x1b0 > [Tue Apr 23 21:59:40 2019] do_iter_write+0x80/0x190 > [Tue Apr 23 21:59:40 2019] nfsd_vfs_write+0xe6/0x450 [nfsd] > [Tue Apr 23 21:59:40 2019] ? do_dentry_open+0xd1/0x330 > [Tue Apr 23 21:59:40 2019] nfsd_write+0x88/0x170 [nfsd] > [Tue Apr 23 21:59:40 2019] ? _cond_resched+0x15/0x30 > [Tue Apr 23 21:59:40 2019] nfsd3_proc_write+0xc3/0x170 [nfsd] > [Tue Apr 23 21:59:40 2019] nfsd_dispatch+0x9e/0x210 [nfsd] > [Tue Apr 23 21:59:40 2019] svc_process_common+0x4a5/0x720 [sunrpc] > [Tue Apr 23 21:59:40 2019] ? nfsd_destroy+0x50/0x50 [nfsd] > [Tue Apr 23 21:59:40 2019] svc_process+0xb7/0xf0 [sunrpc] > [Tue Apr 23 21:59:40 2019] nfsd+0xe3/0x140 [nfsd] > [Tue Apr 23 21:59:40 2019] kthread+0x112/0x130 > [Tue Apr 23 21:59:40 2019] ? kthread_bind+0x30/0x30 > [Tue Apr 23 21:59:40 2019] ret_from_fork+0x35/0x40 > [Tue Apr 23 21:59:40 2019] Modules linked in: vmw_vsock_vmci_transport vsock > coretemp crct10dif_pclmul crc32_pclmul vmwgfx ttm ghash_clmulni_intel ppdev > drm_kms_helper vmw_balloon intel_rapl_perf joydev evdev drm pcspkr serio_raw > sg vmw_vmci parport_pc parport button ac nfsd auth_rpcgss nfs_acl lockd grace > sunrpc ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 fscrypto ecb btrfs > xor zstd_decompress zstd_compress xxhash raid6_pq libcrc32c crc32c_generic > sd_mod sr_mod cdrom ata_generic crc32c_intel aesni_intel aes_x86_64 > crypto_simd cryptd glue_helper psmouse ata_piix mptspi mptscsih mptbase > libata vmxnet3 scsi_transport_spi scsi_mod i2c_piix4 floppy > [Tue Apr 23 21:59:40 2019] ---[ end trace 9153b7dc6f042f19 ]--- > [Tue Apr 23 21:59:40 2019] RIP: 0010:btrfs_set_item_key_safe+0x116/0x190 > [btrfs] > [Tue Apr 23 21:59:40 2019] Code: 48 8d 7c 24 17 48 89 44 24 20 0f b6 44 24 0e > 88 44 24 1f 48 8b 44 24 06 48 89 44 24 17 e8 c2 f3 ff ff 85 c0 0f 8f 46 ff ff > ff <0f> 0b 8d 43 ff 48 8d 74 24 06 4c 89 e7 b9 11 00 00 00 48 98 48 8d > [Tue Apr 23 21:59:40 2019] RSP: 0018:ffffb23fc082f6a0 EFLAGS: 00010246 > [Tue Apr 23 21:59:40 2019] RAX: 0000000000000000 RBX: 000000000000008d RCX: > 000000000c71b000 > [Tue Apr 23 21:59:40 2019] RDX: 000000000003996e RSI: ffffb23fc082f795 RDI: > ffffb23fc082f6b7 > [Tue Apr 23 21:59:40 2019] RBP: ffff9e9ec6bc95b0 R08: 0000000000001000 R09: > 0000000000004000 > [Tue Apr 23 21:59:40 2019] R10: 0000000000000000 R11: 00000000ffffffff R12: > ffff9e9e90957000 > [Tue Apr 23 21:59:40 2019] R13: ffffb23fc082f795 R14: 0000000000000000 R15: > 000000000d007000 > [Tue Apr 23 21:59:40 2019] FS: 0000000000000000(0000) > GS:ffff9e9efda00000(0000) knlGS:0000000000000000 > [Tue Apr 23 21:59:40 2019] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [Tue Apr 23 21:59:40 2019] CR2: 00007f8bddd7fae4 CR3: 00000000735de000 CR4: > 00000000000406f0 > [05:24 AM] root@nas-201-b:~> uptime > 05:24:56 up 7 days, 15:05, 1 user, load average: 16.07, 16.03, 15.85 > > Please let me know if you need any other details to help me resolve this > issue.
Not familiar with tree log code, but the following patch could provide extra debug info: https://patchwork.kernel.org/patch/10914687/ And, if your primary objective is to avoid such BUG_ON(), you can simply disable tree log by "notreelog" mount option, if fsync() performance is not your primary concern. Thanks, Qu > > ----- Original Message ----- > > From: "Gregory Malloff" <gregory.mall...@silvernetworks.ca> > To: linux-btrfs@vger.kernel.org > Sent: Tuesday, April 16, 2019 12:53:20 PM > Subject: kernel BUG at fs/btrfs/ctree.c:3230! > > > Hello, > > Problem: On a Debian 9 or 10 system with an NFS share and heavy I/O, about > every 5 days or so, I get the following: > > http://cwillu.com:8080/207.102.58.55 > > 4,1352,538395169676,-;------------[ cut here ]------------ > 2,1353,538395169680,-;kernel BUG at fs/btrfs/ctree.c:3230! > 4,1354,538395169742,-;invalid opcode: 0000 [#1] SMP PTI > 4,1355,538395169767,-;CPU: 0 PID: 859 Comm: nfsd Not tainted 4.19.0-4-amd64 > #1 Debian 4.19.28-2 > 4,1356,538395169802,-;Hardware name: VMware, Inc. VMware Virtual > Platform/440BX Desktop Reference Platform, BIOS 6.00 09/17/2015 > 4,1357,538395169884,-;RIP: 0010:btrfs_set_item_key_safe+0x116/0x190 [btrfs] > 4,1358,538395169921,-;Code: 48 8d 7c 24 17 48 89 44 24 20 0f b6 44 24 0e 88 > 44 24 1f 48 8b 44 24 06 48 89 44 24 17 e8 c2 f3 ff ff 85 c0 0f 8f 46 ff ff ff > <0f> 0b 8d 43 ff 48 8d 74 24 06 4c 89 e7 b9 11 00 00 00 48 98 48 8d > 4,1359,538395170000,-;RSP: 0018:ffffc08a41fbf6a0 EFLAGS: 00010246 > 4,1360,538395171003,-;RAX: 0000000000000000 RBX: 000000000000008f RCX: > 000000005baa2000 > 4,1361,538395171948,-;RDX: 0000000000031b05 RSI: ffffc08a41fbf795 RDI: > ffffc08a41fbf6b7 > 4,1362,538395172882,-;RBP: ffff9d6b33ef3460 R08: 0000000000001000 R09: > 0000000000004000 > 4,1363,538395173774,-;R10: 0000000000000000 R11: 00000000ffffffff R12: > ffff9d6c5a788c08 > 4,1364,538395174713,-;R13: ffffc08a41fbf795 R14: 0000000000000000 R15: > 000000005c01a000 > 4,1365,538395175761,-;FS: 0000000000000000(0000) GS:ffff9d6cb7a00000(0000) > knlGS:0000000000000000 > 4,1366,538395176716,-;CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > 4,1367,538395177582,-;CR2: 00007ffe8161dbe8 CR3: 000000022b3fa000 CR4: > 00000000000406f0 > 4,1368,538395178523,-;Call Trace: > 4,1369,538395179418,-; __btrfs_drop_extents+0x7ae/0xcf0 [btrfs] > 4,1370,538395180296,-; btrfs_log_changed_extents.isra.24+0x391/0x990 [btrfs] > 4,1371,538395181233,-; btrfs_log_inode+0xb54/0x1240 [btrfs] > 4,1372,538395182096,-; ? __kprobes_text_end+0xe5c68/0xe5c68 > 4,1373,538395182930,-; ? __switch_to_asm+0x34/0x70 > 4,1374,538395183747,-; ? __switch_to_asm+0x40/0x70 > 4,1375,538395184542,-; ? __switch_to_asm+0x34/0x70 > 4,1376,538395185320,-; ? __switch_to_asm+0x34/0x70 > 4,1377,538395186078,-; ? __switch_to_asm+0x40/0x70 > 4,1378,538395186859,-; btrfs_log_inode_parent+0x2a1/0xac0 [btrfs] > 4,1379,538395187644,-; ? wait_current_trans+0x2f/0xf0 [btrfs] > 4,1380,538395188379,-; ? refcount_inc_checked+0x5/0x30 > 4,1381,538395189254,-; ? join_transaction+0xec/0x410 [btrfs] > 4,1382,538395190159,-; btrfs_log_dentry_safe+0x4a/0x70 [btrfs] > 4,1383,538395190901,-; btrfs_sync_file+0x1cb/0x3d0 [btrfs] > 4,1384,538395191826,-; btrfs_file_write_iter+0x495/0x590 [btrfs] > 4,1385,538395192631,-; ? apparmor_cred_prepare+0x4c/0x60 > 4,1386,538395193334,-; do_iter_readv_writev+0x13a/0x1b0 > 4,1387,538395195201,-; do_iter_write+0x80/0x190 > 4,1388,538395195877,-; nfsd_vfs_write+0xe6/0x450 [nfsd] > 4,1389,538395196537,-; ? do_dentry_open+0xd1/0x330 > 4,1390,538395197182,-; nfsd_write+0x88/0x170 [nfsd] > 4,1391,538395197785,-; ? _cond_resched+0x15/0x30 > 4,1392,538395198386,-; nfsd3_proc_write+0xc3/0x170 [nfsd] > 4,1393,538395198980,-; nfsd_dispatch+0x9e/0x210 [nfsd] > 4,1394,538395199561,-; svc_process_common+0x4a5/0x720 [sunrpc] > 4,1395,538395200128,-; ? nfsd_destroy+0x50/0x50 [nfsd] > 4,1396,538395200682,-; svc_process+0xb7/0xf0 [sunrpc] > 4,1397,538395201219,-; nfsd+0xe3/0x140 [nfsd] > 4,1398,538395201742,-; kthread+0x112/0x130 > 4,1399,538395202263,-; ? kthread_bind+0x30/0x30 > 4,1400,538395202776,-; ret_from_fork+0x35/0x40 > 4,1401,538395203296,-;Modules linked in: vmw_vsock_vmci_transport vsock > coretemp crct10dif_pclmul crc32_pclmul vmwgfx vmw_balloon ttm > ghash_clmulni_intel ppdev drm_kms_helper intel_rapl_perf joydev pcspkr > serio_raw drm sg vmw_vmci evdev parport_pc parport button ac nfsd auth_rpcgss > nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 > fscrypto ecb btrfs xor zstd_decompress zstd_compress xxhash raid6_pq > libcrc32c crc32c_generic sd_mod sr_mod cdrom ata_generic crc32c_intel > aesni_intel aes_x86_64 crypto_simd cryptd glue_helper psmouse mptspi mptscsih > ata_piix mptbase scsi_transport_spi libata scsi_mod vmxnet3 i2c_piix4 floppy > 4,1402,538395207304,-;---[ end trace 4eda186227cc8ba6 ]--- > > #uname -a > Linux nas-201-b 4.19.0-4-amd64 #1 SMP Debian 4.19.28-2 (2019-03-15) x86_64 > GNU/Linux > > #btrfs --version > btrfs-progs v4.20.1 > > #btrfs fi show > Label: none uuid: 1388dd44-f704-42bd-bdfd-95f2b43af671 > Total devices 1 FS bytes used 2.95TiB > devid 1 size 5.00TiB used 3.35TiB path /dev/sdb > > #btrfs fi df /data > Data, single: total=3.33TiB, used=2.94TiB > System, DUP: total=40.00MiB, used=416.00KiB > Metadata, DUP: total=10.00GiB, used=7.21GiB > GlobalReserve, single: total=512.00MiB, used=0.00B > > #btrfs check --readonly /dev/sdb > Opening filesystem to check... > Checking filesystem on /dev/sdb > UUID: 1388dd44-f704-42bd-bdfd-95f2b43af671 > [1/7] checking root items > [2/7] checking extents > [3/7] checking free space cache > [4/7] checking fs roots > [5/7] checking only csums items (without verifying data) > [6/7] checking root refs > [7/7] checking quota groups skipped (not enabled on this FS) > found 3244857946112 bytes used, no error found > total csum bytes: 3160375372 > total tree bytes: 7738867712 > total fs tree bytes: 2187886592 > total extent tree bytes: 1546764288 > btree space waste bytes: 1368283474 > file data blocks allocated: 6333316149248 > referenced 6330266890240 > > #btrfs scrub start /data > scrub started on /data, fsid 1388dd44-f704-42bd-bdfd-95f2b43af671 (pid=887) > > #btrfs scrub status /data > scrub status for 1388dd44-f704-42bd-bdfd-95f2b43af671 > scrub started at Tue Apr 16 11:06:49 2019 and finished after 01:27:55 > total bytes scrubbed: 2.96TiB with 0 errors > > #btrfs device stats /data > [/dev/sdb].write_io_errs 0 > [/dev/sdb].read_io_errs 0 > [/dev/sdb].flush_io_errs 0 > [/dev/sdb].corruption_errs 0 > [/dev/sdb].generation_errs 0 > > [dmesg.log file attached] > > Cheers, > Greg >
signature.asc
Description: OpenPGP digital signature
