Re: 2.6.37 BUG at inode.c:1616 (was Re: 2.6.37: Bug on btrfs while umount)

[Andy Isaacson]

On Mon, Jan 10, 2011 at 12:08:15AM -0800, Andy Isaacson wrote:
> On Thu, Jan 06, 2011 at 08:29:12PM -0500, Chris Mason wrote:
> > > [50010.838804] [ cut here ]
> > > [50010.838931] kernel BUG at fs/btrfs/inode.c:1616!
> > > [50010.839053] invalid opcode:  [#1] PREEMPT SMP
> [snip]
> > > [50010.839653] Pid: 1681, comm: btrfs-endio-wri Not tainted 2.6.37 #1
> > 
> > Could you please pull from the master branch of the btrfs unstable tree.
> > We had a late fix that is related to this.
> 
> I saw BUG at inode.c:1616 while running 2.6.37-rc6-11882-g55ec86f, I saw

Just got this again, same BUG and same stack trace.  This machine +
fs ran great for several months under approximately the same workload,
but the FS is slowly filling up; is this a regression in .37 or is the
bug a function of the FS load?

-andy
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

2.6.37 BUG at inode.c:1616 (was Re: 2.6.37: Bug on btrfs while umount)

[Andy Isaacson]

On Thu, Jan 06, 2011 at 08:29:12PM -0500, Chris Mason wrote:
> > [50010.838804] [ cut here ]
> > [50010.838931] kernel BUG at fs/btrfs/inode.c:1616!
> > [50010.839053] invalid opcode:  [#1] PREEMPT SMP
[snip]
> > [50010.839653] Pid: 1681, comm: btrfs-endio-wri Not tainted 2.6.37 #1
> 
> Could you please pull from the master branch of the btrfs unstable tree.
> We had a late fix that is related to this.

I saw BUG at inode.c:1616 while running 2.6.37-rc6-11882-g55ec86f, I saw
your message and upgraded to Linus tip (0c21e3a) + btrfs-unstable tip
(65e5341), and I just saw it again.  Including both BUG traces below.

The machine is a Core i7 with 12GB, with btrfs spanning three volumes:

Label: btr  uuid: 1271de53-b3d2-4d68-9d48-b19487e1c982
Total devices 3 FS bytes used 735.97GB
devid1 size 18.65GB used 18.64GB path /dev/sda2
devid2 size 512.00GB used 511.88GB path /dev/sdb1
devid3 size 512.00GB used 225.26GB path /dev/sdc1

The primary writer to the filesystem is rtorrent; normally I have ffmpeg
writing to the filesystem at about 100 kbyte/sec as well, but it wasn't
running in this latest crash.

[ 9275.240027] [ cut here ]
[ 9275.249991] kernel BUG at fs/btrfs/inode.c:1616!
[ 9275.259914] invalid opcode:  [#1] SMP 
[ 9275.269794] last sysfs file: 
/sys/devices/pci:00/:00:1a.7/usb1/1-4/1-4:1.0/host8/target8:0:0/8:0:0:0/block/sdd/stat
[ 9275.280066] CPU 0 
[ 9275.280127] Modules linked in: tun ebtable_nat ebtables ipt_MASQUERADE 
iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack 
ipt_REJECT xt_tcpudp iptable_filter ip_tables x_tables bridge stp llc kvm_intel 
kvm xfs exportfs loop snd_hda_codec_hdmi snd_hda_codec_realtek radeon ttm 
drm_kms_helper drm snd_hda_intel snd_hda_codec i2c_algo_bit snd_usb_audio 
uvcvideo snd_hwdep i2c_i801 snd_usbmidi_lib snd_pcm snd_rawmidi snd_timer 
videodev snd_seq_device snd v4l2_compat_ioctl32 pcspkr i2c_core serio_raw 
soundcore snd_page_alloc processor tpm_tis tpm tpm_bios evdev shpchp button 
thermal_sys ext3 jbd mbcache dm_mod btrfs zlib_deflate crc32c libcrc32c 
usb_storage uas sd_mod crc_t10dif ehci_hcd usbcore ahci libahci libata r8169 
scsi_mod mii nls_base [last unloaded: scsi_wait_scan]
[ 9275.358450] 
[ 9275.369821] Pid: 3654, comm: btrfs-endio-wri Not tainted 
2.6.37-03739-gccda756 #73 MSI X58 Pro-E (MS-7522)/MS-7522
[ 9275.381570] RIP: 0010:[]  [] 
T.1234+0x76/0x201 [btrfs]
[ 9275.393380] RSP: 0018:88025f275c30  EFLAGS: 00010286
[ 9275.405100] RAX: ffe4 RBX: 88032b596b40 RCX: 88032b596c60
[ 9275.416865] RDX:  RSI: ea000b17b8d0 RDI: fff4
[ 9275.428666] RBP: 88025f275cc0 R08: 0005 R09: 88025f2759a0
[ 9275.440522] R10: 88025f275970 R11: dead00100100 R12: 880083a7e888
[ 9275.452374] R13: 06e0c000 R14: 880331d7c800 R15: 8800bb38d880
[ 9275.464146] FS:  () GS:8800bf40() 
knlGS:
[ 9275.475923] CS:  0010 DS:  ES:  CR0: 8005003b
[ 9275.487673] CR2: 7f3eada57000 CR3: 01603000 CR4: 26e0
[ 9275.499547] DR0:  DR1:  DR2: 
[ 9275.511395] DR3:  DR6: 0ff0 DR7: 0400
[ 9275.523192] Process btrfs-endio-wri (pid: 3654, threadinfo 88025f274000, 
task 88032554b020)
[ 9275.535168] Stack:
[ 9275.546852]  06e0c000 1000 00b8c1376000 
1000
[ 9275.558616]  880331d7c800 0001 8800bb38d880 
880331d7c800
[ 9275.570416]  88025f275cb0 a014b53f 88025f275ce0 
8802e21ad7f0
[ 9275.582149] Call Trace:
[ 9275.593731]  [] ? start_transaction+0x1a9/0x1d8 [btrfs]
[ 9275.605513]  [] btrfs_finish_ordered_io+0x1e6/0x2c2 [btrfs]
[ 9275.617426]  [] btrfs_writepage_end_io_hook+0x1a/0x1c 
[btrfs]
[ 9275.629403]  [] end_bio_extent_writepage+0xae/0x159 [btrfs]
[ 9275.641463]  [] bio_endio+0x2d/0x2f
[ 9275.653462]  [] end_workqueue_fn+0x111/0x120 [btrfs]
[ 9275.665484]  [] worker_loop+0x195/0x4c4 [btrfs]
[ 9275.677451]  [] ? worker_loop+0x0/0x4c4 [btrfs]
[ 9275.689317]  [] ? worker_loop+0x0/0x4c4 [btrfs]
[ 9275.701079]  [] kthread+0x82/0x8a
[ 9275.712839]  [] kernel_thread_helper+0x4/0x10
[ 9275.724455]  [] ? kthread+0x0/0x8a
[ 9275.735873]  [] ? kernel_thread_helper+0x0/0x10
[ 9275.747329] Code: 0f 0b eb fe 80 88 88 00 00 00 08 45 31 c9 48 8b 4d 88 4c 
8d 45 c0 4c 01 e9 4c 89 ea 4c 89 e6 4c 89 ff e8 7c 4c 00 00 85 c0 74 04 <0f> 0b 
eb fe 49 8b 84 24 a8 00 00 00 4c 89 6d a9 48 89 45 a0 c6 
[ 9275.771177] RIP  [] T.1234+0x76/0x201 [btrfs]
[ 9275.782973]  RSP 
[ 9276.049117] ---[ end trace 39a68c45b2f4ff68 ]---

The previous BUG also happened at runtime (not umount or anything), with
rtorrent running and ffmpeg writing a video stream from /dev/video0 to
btrfs.

[1719001.040399] [ cut here ]
[1719001.0415