Re: Readynas 3312 BTRFS error (device md127) in __btrfs_free_extent:6998: errno=-28 No space left

defcon84 · ‎2020-01-23

Hi,

I have another issue with BTRFS.

All the sudden, I couldn't write to the share.

It gave the exception 'Permission denied'.

I also could reset the shares permissions.

So i tried to reset the server but it didnt come back up.

After a power cycle, it was back.

It all started with exception in the journal:


Jan 23 00:28:15 SKNAS05 kernel: ------------[ cut here ]------------
Jan 23 00:28:19 SKNAS05 kernel: WARNING: CPU: 3 PID: 3751 at fs/btrfs/extent-tree.c:6998 __btrfs_free_extent.isra.71+0x28b/0xd70()
Jan 23 00:28:27 SKNAS05 kernel: BTRFS: Transaction aborted (error -28)
Jan 23 00:28:27 SKNAS05 kernel: Modules linked in: vpd(PO)
Jan 23 00:28:27 SKNAS05 kernel: CPU: 3 PID: 3751 Comm: btrfs-transacti Tainted: P O 4.4.116.x86_64.1 #1
Jan 23 00:28:27 SKNAS05 kernel: Hardware name: NETGEAR ReadyNAS 3312/ReadyNAS RR3312, BIOS RR3312v112 07/25/2016
Jan 23 00:28:27 SKNAS05 kernel: 0000000000000000 ffff88024bb03ae8 ffffffff883ec5a8 ffff88024bb03b30
Jan 23 00:28:27 SKNAS05 kernel: ffffffff88d1aab1 ffff88024bb03b20 ffffffff8806f3ac 00000000ffffffe4
Jan 23 00:28:27 SKNAS05 kernel: 0000294acccc8000 ffff8802664fea00 ffff8800182a5f50 0000000000000002
Jan 23 00:28:27 SKNAS05 kernel: Call Trace:
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff883ec5a8>] dump_stack+0x4d/0x65
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff8806f3ac>] warn_slowpath_common+0x7c/0xb0
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff8806f427>] warn_slowpath_fmt+0x47/0x50
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff882e520b>] __btrfs_free_extent.isra.71+0x28b/0xd70
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff882e8d26>] __btrfs_run_delayed_refs+0x626/0x10f0
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff882ec75d>] btrfs_run_delayed_refs+0x7d/0x2e0
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff8830177f>] btrfs_commit_transaction.part.25+0x5f/0xa80
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff882ec8e9>] ? btrfs_run_delayed_refs+0x209/0x2e0
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff883021d5>] btrfs_commit_transaction+0x35/0x60
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff882fcd36>] transaction_kthread+0x216/0x230
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff882fcb20>] ? btrfs_cleanup_transaction+0x4a0/0x4a0
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff88089356>] kthread+0xe6/0x100
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff88a6f972>] ? __schedule+0x1b2/0x600
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff88089270>] ? kthread_create_on_node+0x170/0x170
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff88a731c5>] ret_from_fork+0x55/0x80
Jan 23 00:28:27 SKNAS05 kernel: [<ffffffff88089270>] ? kthread_create_on_node+0x170/0x170
Jan 23 00:28:27 SKNAS05 kernel: ---[ end trace 7029bcdeed995522 ]---
Jan 23 00:28:27 SKNAS05 kernel: BTRFS: error (device md127) in __btrfs_free_extent:6998: errno=-28 No space left
Jan 23 00:28:27 SKNAS05 kernel: BTRFS info (device md127): forced readonly
Jan 23 00:28:32 SKNAS05 kernel: BTRFS: error (device md127) in btrfs_run_delayed_refs:2993: errno=-28 No space left

Some more info:

root@SKNAS05:~# btrfs filesystem show
Label: '2fe72d70:root'  uuid: 8444e252-7714-4ce8-a75c-daff364d1c2c
        Total devices 1 FS bytes used 644.34MiB
        devid    1 size 4.00GiB used 1.64GiB path /dev/md0

Label: '2fe72d70:data'  uuid: 7638dba2-0e72-4c52-b071-987b1395d91e
        Total devices 1 FS bytes used 42.54TiB
        devid    1 size 54.55TiB used 44.25TiB path /dev/md127

Enough space free.

Running on firmware 6.9.3

Any idea what this is and how to prevent it?

defcon84 · ‎2020-01-23

some more information:

root@SKNAS05:~# btrfsck /dev/md127 --force
WARNING: filesystem mounted, continuing because of --force
parent transid verify failed on 45403858534400 wanted 1820270 found 1820360
parent transid verify failed on 45403858534400 wanted 1820270 found 1820360
parent transid verify failed on 45403858534400 wanted 1820270 found 1820360
leaf parent key incorrect 45403858534400
ERROR: cannot open file system

Sandshark · ‎2020-01-23

Yes, when there is an unrecoverable BTRFS error, one thing the OS tries is to make the volume read-only so you can make sure your backup is in order before something more happens (which likely would if writes were allowed). The only solution to this is normally a factory default and restoration of data from backup. It's a good idea to first check the SMART data for your drives just to be sure a hardware issue isn't the driving factor.

defcon84 · ‎2020-01-24

Thanks for the information.

Shouldn't a balance fix / prevent this?

smartctl doesn't show anything weird.

Anything else I can check?

For now, i'll copy the whole 80TB somewhere else and reset the NAS.

But this shouldn't be happening in a NAS, we buy them to use the RAID5, to prevent downtime.

StephenB · ‎2020-01-24

@defcon84 wrote:

Anything else I can check?

This might resolve the error:

# btrfs-zero-log /dev/md127

But there could be some missing or damaged files. The wanted 1820270 found 1820360 bit in the log means that there are 90 transactions in the journal that somehow didn't get written to the file system.

That could be due to disk errors, a system crash, or an unexpected power cut. So perhaps check the log zip for that stuff.

defcon84 · ‎2020-01-24

I have destroyed the Volume and recreated it, that seemed to get rid of the btrfs check errors (and the data offcourse).

Now it's rebuilding and than i'll get the data back. But i think it'll be fine for now.

defcon84 · ‎2020-01-27

It allready happened again:

...
parent transid verify failed on 8611392847872 wanted 8249 found 8252
parent transid verify failed on 8611392847872 wanted 8249 found 8252
ERROR: child eb corrupted: parent bytenr=8611405791232 item=335 parent level=1 child level=2
ERROR: failed to repair root items: Input/output error

if i try do the fix you proposed, it offcourse gives the mount exception:

root@SKNAS05:~# btrfs rescue zero-log /dev/md127
ERROR: /dev/md127 is currently mounted

What is the safest way to unmount fix and remount the volume?

Or do you think i'm better off with a factory reset (until now i only deleted and recreated the volume).

SMART gives me no errors, there was no system crash and no power loss.

StephenB · ‎2020-01-27

@defcon84 wrote:
root@SKNAS05:~# btrfs rescue zero-log /dev/md127
ERROR: /dev/md127 is currently mounted
What is the safest way to unmount fix and remount the volume?

You could try unmounting it with umount, and then restarting - not sure if the umount will work, but it is safe to try.

The other option would be to boot into tech support mode.

But something is really wrong here - you shouldn't be seeing these problems over and over if you have healthy disks. I don't know what is going on, but I am wondering if you should pursue a warranty replacement.

Sandshark · ‎2020-01-27

I believe you should be able to unmount the main volume as long as you have no apps that are running that reside on it.

One thing to verify if you just delete and re-create the volume is that the home and apps shares are created properly. I ran some experiments, and had them not be a couple times. Netgear could not duplicate the problem, so there is no fix. I happen to know how to create them myself, and so I did.