BTRFS unreliable on TL-WR842ND

[Just4pLeisure]

I hope raising a ticket here is the right thing to, I apologise if not :-(

I have been using my router as a simple NFS NAS for around 2 years with an ext3 formatted Western Digital 2.5" USB Passport disk. I have also been slowly moving to BTRFS and thought it about time to convert this disk too but unfortunately BTRFS is unreliable on my router :-(. It doesn't take much for an error to happen causing a 'ro' remount. However the disk is unreadable after the remount, both over NFS and locally. Rebooting the router seems to be the only way to access the disk again.

My TP-Link router has been upgraded to have 64 MB RAM and I have a 1 GB swap partition on the disk (btrfs doesn't support swap files). No problems are found when I use my laptop to check and scrub the disk (i.e. with the disk connected directly to my laptop).

This is a snippet of from the system log (Chaos Calmer r44555):

[11156.330000] usb 1-1: new high-speed USB device number 2 using ehci-platform
[11156.490000] usb-storage 1-1:1.0: USB Mass Storage device detected
[11156.490000] scsi0 : usb-storage 1-1:1.0
[11157.500000] scsi 0:0:0:0: Direct-Access WD My Passport 0748 1015 PQ: 0 ANSI: 6
[11157.510000] scsi 0:0:0:1: Enclosure WD SES Device 1015 PQ: 0 ANSI: 6
[11157.520000] sd 0:0:0:0: [sda] Spinning up disk...
[11158.540000] ......ready
[11163.590000] sd 0:0:0:0: [sda] 3906963456 512-byte logical blocks: (2.00 TB/1.81 TiB)
[11163.600000] sd 0:0:0:0: [sda] Write Protect is off
[11163.600000] sd 0:0:0:0: [sda] Mode Sense: 47 00 10 08
[11163.610000] sd 0:0:0:0: [sda] No Caching mode page found
[11163.610000] sd 0:0:0:0: [sda] Assuming drive cache: write through
[11163.620000] sd 0:0:0:0: [sda] No Caching mode page found
[11163.630000] sd 0:0:0:0: [sda] Assuming drive cache: write through
[11163.650000] sda: sda1 sda2
[11163.660000] sd 0:0:0:0: [sda] No Caching mode page found
[11163.670000] sd 0:0:0:0: [sda] Assuming drive cache: write through
[11163.670000] sd 0:0:0:0: [sda] Attached SCSI disk
[11210.890000] Adding 1047548k swap on /dev/sda2. Priority:-1 extents:1 across:1047548k
[11234.190000] BTRFS: device label Media Share devid 1 transid 13976 /dev/sda1
[11234.200000] BTRFS info (device sda1): disk space caching is enabled
[11409.700000] nfsd: last server has exited, flushing export cache
[11409.860000] svc: failed to register lockdv1 RPC service (errno 124).
[11563.240000] ------------[ cut here ]------------
[11563.250000] WARNING: CPU: 0 PID: 5648 at fs/btrfs/super.c:257 btrfs_abort_transaction+0x74/0x150 [btrfs]()
[11563.260000] BTRFS: Transaction aborted (error -17)
[11563.260000] Modules linked in: ath9k ath9k_common pppoe ppp_async iptable_nat ath9k_hw ath pppox ppp_generic nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 mac80211 ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_id xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_CT slhc nf_nat_irc nf_nat_ftp nf_nat nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack_irc nf_conntrack_ftp nf_conntrack libcrc32c iptable_raw iptable_mangle iptable_filter ipt_REJECT ip_tables crc_ccitt compat ledtrig_usbdev ip6t_REJECT ip6table_raw ip6table_mangle ip6table_filter ip6_tables x_tables nfsd nfsv3 nfs lockd sunrpc dns_resolver ipv6 arc4 crypto_blkcipher usb_storage sd_mod scsi_mod ext4 crc16 jbd2 mbcache btrfs zlib_inflate zlib_deflate xor raid6_pq lzo_decompress lzo_compress exportfs crc32c crypto_hash ohci_platform ohci_hcd ehci_platform ehci_hcd gpio_button_hotplug usbcore nls_base usb_common
[11563.350000] CPU: 0 PID: 5648 Comm: btrfs-transacti Not tainted 3.14.32 #1
[11563.360000] Stack : 00000006 00000000 00000000 00000000 00000000 00000000 803dd8fe 0000003d
[11563.360000] 82107ba0 83623000 8031ff74 8036be03 00001610 803d3b60 82107ba0 83623000
[11563.360000] 832aeb44 8035f790 832b0000 802b5ea4 00000003 80215c18 00000101 83623000
[11563.360000] 8032314c 81861d34 00000000 00000000 00000000 00000000 00000000 00000000
[11563.360000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[11563.360000] ...
[11563.390000] Call Trace:
[11563.390000] [<802596dc>] show_stack+0x48/0x70
[11563.400000] [<802c68dc>] warn_slowpath_common+0x84/0xb4
[11563.400000] [<802c6938>] warn_slowpath_fmt+0x2c/0x38
[11563.410000] [<83201ad4>] btrfs_abort_transaction+0x74/0x150 [btrfs]
[11563.420000] [<8321f704>] btrfs_run_delayed_refs+0xac/0x258 [btrfs]
[11563.420000] [<83230148>] btrfs_commit_transaction+0x390/0xe30 [btrfs]
[11563.430000] [<8322c984>] btrfs_cleanup_one_transaction+0xae8/0xb98 [btrfs]
[11563.440000] [<80244610>] schedule_tail+0x1c/0x60
[11563.440000] [<80060878>] ret_from_kernel_thread+0x14/0x1c
[11563.450000]
[11563.450000] ---[ end trace 26f362792e02ead6 ]---
[11563.450000] BTRFS: error (device sda1) in btrfs_run_delayed_refs:2714: errno=-17 Object already exists
[11563.460000] BTRFS info (device sda1): forced readonly
[11563.470000] BTRFS warning (device sda1): Skipping commit of aborted transaction.
[11563.470000] BTRFS: error (device sda1) in cleanup_transaction:1545: errno=-17 Object already exists

Thanks in advance,
Sophie x

[bittorf@…]

please switch to trunk with kernel 3.18.9 - there are several fixes regarding btrfs since your version and report again.

[Just4pLeisure]

Thank you bittorf, I've been using the daily snapshot downloads which are built with kernel 3.14. Do I need to get the sources, change LINUX_VERSION in one of the makefiles somewhere and compile or are there other snapshots with different kernel builds that I haven't found yet?

Sorry if that's a noob question,
Sophie x

[bittorf@…]

Replying to Just4pLeisure:

Thank you bittorf, I've been using the daily snapshot downloads which are built with kernel 3.14. Do I need to get the sources, change LINUX_VERSION in one of the makefiles somewhere and compile or are there other snapshots with different kernel builds that I haven't found yet?

you have to wait some days for the builtbots or compile yourself for kernel 3.18.9+
(if you checkout trunk, it automatically builts with this kernel)

[Just4pLeisure]

This is a (moot) correction to my original defect report:
I had r44455 on my router, not r44555.
Ironically kernel 3.18 was made the default in r44482.

[Just4pLeisure]

Oh dear, the same happens with most recent snapshot and 3.18.9 kernel :-(

CHAOS CALMER (Bleeding Edge, r44879)

[ 265.110000] ------------[ cut here ]------------
[ 265.110000] WARNING: CPU: 0 PID: 831 at fs/btrfs/super.c:260 btrfs_abort_transaction+0x74/0x150 [btrfs]()
[ 265.120000] BTRFS: Transaction aborted (error -17)
[ 265.130000] Modules linked in: ath9k ath9k_common pppoe ppp_async iptable_nat ath9k_hw ath pppox ppp_generic nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 mac80211 ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_id xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_CT slhc nf_reject_ipv4 nf_nat_masquerade_ipv4 nf_nat_irc nf_nat_ftp nf_nat nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack_irc nf_conntrack_ftp nf_conntrack libcrc32c iptable_raw iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbdev ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_raw ip6table_mangle ip6table_filter ip6_tables x_tables nfsd nfsv3 nfs lockd sunrpc grace dns_resolver ipv6 arc4 crypto_blkcipher usb_storage sd_mod scsi_mod ext4 crc16 jbd2 mbcache btrfs zlib_inflate zlib_deflate xor raid6_pq lzo_decompress lzo_compress exportfs crc32c_generic crypto_hash ohci_platform ohci_hcd ehci_platform ehci_hcd gpio_button_hotplug usbcore nls_base usb_common
[ 265.220000] CPU: 0 PID: 831 Comm: btrfs-transacti Not tainted 3.18.9 #1
[ 265.230000] Stack : 00000000 00000000 00000000 00000000 803fe10a 0000003b 00000000 832012e0
[ 265.230000] 00000001 8359fed8 8033fd38 8038df63 0000033f 803f3b80 83a195a8 8359fed8
[ 265.230000] 832b6dfc 00000000 832c0000 802cf89c 00000003 8022ae14 00000104 8359fed8
[ 265.230000] 80342e54 825bdc6c 00000000 00000000 00000000 00000000 00000000 00000000
[ 265.230000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 265.230000] ...
[ 265.260000] Call Trace:
[ 265.270000] [<802718d8>] show_stack+0x48/0x70
[ 265.270000] [<802e0c48>] warn_slowpath_common+0x84/0xb4
[ 265.280000] [<802e0ca4>] warn_slowpath_fmt+0x2c/0x38
[ 265.280000] [<832012e0>] btrfs_abort_transaction+0x74/0x150 [btrfs]
[ 265.290000] [<832206e4>] btrfs_run_delayed_refs+0xa0/0x318 [btrfs]
[ 265.290000] [<83220bb8>] btrfs_write_dirty_block_groups+0x25c/0x650 [btrfs]
[ 265.300000] [<832b3df4>] btrfs_crc32c+0x514/0x1418 [btrfs]
[ 265.310000]
[ 265.310000] ---[ end trace e1e1a04204a7499b ]---
[ 265.310000] BTRFS: error (device sda1) in btrfs_run_delayed_refs:2792: errno=-17 Object already exists
[ 265.320000] BTRFS info (device sda1): forced readonly
[ 265.350000] BTRFS warning (device sda1): Skipping commit of aborted transaction.
[ 265.360000] BTRFS: error (device sda1) in cleanup_transaction:1607: errno=-17 Object already exists

[bittorf@…]

how large is the disc?
can you show the output of 'cat /proc/meminfo' after the error?

[Just4pLeisure]

Replying to bittorf@…:

how large is the disc?
can you show the output of 'cat /proc/meminfo' after the error?

I have a 2TB WD My Passport disk which had been ext3 formatted. I used my laptop to convert the fs to btrfs, not my router. My laptop has Fedora 21 with 3.18 kernel and tools.

Thank you :-)
Sophie x

# btrfs fi show
Label: '###########'  uuid: ########-####-####-####-############
        Total devices 1 FS bytes used 1.15TiB
        devid    1 size 1.82TiB used 1.15TiB path /dev/sda1

Btrfs v3.17.3

and meminfo:

# cat /proc/meminfo
MemTotal:          61020 kB
MemFree:            2784 kB
MemAvailable:      40044 kB
Buffers:            1736 kB
Cached:            35768 kB
SwapCached:            0 kB
Active:            20292 kB
Inactive:          19244 kB
Active(anon):       2952 kB
Inactive(anon):       32 kB
Active(file):      17340 kB
Inactive(file):    19212 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:             0 kB
SwapFree:              0 kB
Dirty:                 0 kB
Writeback:             0 kB
AnonPages:          2064 kB
Mapped:             1428 kB
Shmem:               920 kB
Slab:              11460 kB
SReclaimable:       4392 kB
SUnreclaim:         7068 kB
KernelStack:         592 kB
PageTables:          284 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:       30508 kB
Committed_AS:       5848 kB
VmallocTotal:    1048372 kB
VmallocUsed:        1612 kB
VmallocChunk:    1026496 kB

[bittorf@…]

can you please report this upstream?
​https://btrfs.wiki.kernel.org/index.php/Btrfs_mailing_list

just provide them with the needed information, e.g. everything from this ticket and

uname -a
btrfs --version
btrfs fi show
btrfs fi df /home # Replace /home with the mount point of your btrfs-filesystem 
dmesg > dmesg.log

please link the send mail here, when it arrived in the mailinglist archiv

[Just4pLeisure]

Replying to bittorf@…:

can you please report this upstream?
​https://btrfs.wiki.kernel.org/index.php/Btrfs_mailing_list

just provide them with the needed information, e.g. everything from this ticket and

uname -a
btrfs --version
btrfs fi show
btrfs fi df /home # Replace /home with the mount point of your btrfs-filesystem 
dmesg > dmesg.log

please link the send mail here, when it arrived in the mailinglist archiv

Yes :-)
​http://article.gmane.org/gmane.comp.file-systems.btrfs/43771

[Just4pLeisure]

One of the BTRFS devs has reproduced the problem and hopes to make progress with a fix soon :-)

I have an image that can reproduce this bug, and I'm trying to figure out
where we've gone wrong.  Hopefully end of day tomorrow I'll have more ideas,
but its a run time error related to extent management. Since the FS check is
clean, the FS itself isn't corrupt.

-chris