[gelöst] Fehlereinträge während btrfs balance

[jph]

Hallo zusammen,

wenn ich auf meinem Server (RAID1) ein btrfs balance durchführe, hagelt es Meldungen dieser Art:

Code: Alles auswählen

Nov 07 20:12:13 proliant kernel: ------------[ cut here ]------------
Nov 07 20:12:13 proliant kernel: WARNING: CPU: 0 PID: 11841 at fs/btrfs/ctree.h:1682 btrfs_update_device.cold.63+0x10/0x1b [btrfs]                                                                                
Nov 07 20:12:13 proliant kernel: Modules linked in: rpcsec_gss_krb5 veth nf_tables nfnetlink cpuid fuse intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pc
Nov 07 20:12:13 proliant kernel: CPU: 0 PID: 11841 Comm: btrfs Not tainted 5.2.0-0.bpo.3-amd64 #1 Debian 5.2.17-1~bpo10+1                                                                                         
Nov 07 20:12:13 proliant kernel: Hardware name: HP ProLiant MicroServer Gen8, BIOS J06 05/21/2018
Nov 07 20:12:13 proliant kernel: RIP: 0010:btrfs_update_device.cold.63+0x10/0x1b [btrfs]
Nov 07 20:12:13 proliant kernel: Code: ff ff 0f 0b 48 c7 c7 50 32 66 c0 e8 40 b8 29 c5 48 8b 7c 24 20 e9 78 c7 f9 ff 48 c7 c7 90 32 66 c0 48 89 0c 24 e8 26 b8 29 c5 <0f> 0b 48 8b 0c 24 e9 0f cc f9 ff 89 c3 89 da
Nov 07 20:12:13 proliant kernel: RSP: 0018:ffff9e0582c7f9b8 EFLAGS: 00010246
Nov 07 20:12:13 proliant kernel: RAX: 0000000000000024 RBX: ffff8ab101d31c00 RCX: 0000000000000000
Nov 07 20:12:13 proliant kernel: RDX: 0000000000000000 RSI: ffff8ab106817688 RDI: ffff8ab106817688
Nov 07 20:12:13 proliant kernel: RBP: ffff8ab0185878c0 R08: 00000000000003da R09: 0000000000000004
Nov 07 20:12:13 proliant kernel: R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000003f3c
Nov 07 20:12:13 proliant kernel: R13: 0000000000000000 R14: ffff8ab028a9f6a8 R15: 0000000000000000
Nov 07 20:12:13 proliant kernel: FS:  00007f0ce76938c0(0000) GS:ffff8ab106800000(0000) knlGS:0000000000000000                                                                                                     
Nov 07 20:12:13 proliant kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Nov 07 20:12:13 proliant kernel: CR2: 000055a38ffd1ed0 CR3: 0000000015bf0005 CR4: 00000000001606f0
Nov 07 20:12:13 proliant kernel: Call Trace:
Nov 07 20:12:13 proliant kernel:  btrfs_finish_chunk_alloc+0x115/0x4e0 [btrfs]
Nov 07 20:12:13 proliant kernel:  ? set_extent_buffer_dirty+0x13/0x90 [btrfs]
Nov 07 20:12:13 proliant kernel:  ? btrfs_insert_item+0x7e/0xf0 [btrfs]
Nov 07 20:12:13 proliant kernel:  btrfs_create_pending_block_groups+0xee/0x240 [btrfs]
Nov 07 20:12:13 proliant kernel:  __btrfs_end_transaction+0x40/0x1b0 [btrfs]
Nov 07 20:12:13 proliant kernel:  btrfs_inc_block_group_ro+0xd4/0x150 [btrfs]
Nov 07 20:12:13 proliant kernel:  btrfs_relocate_block_group+0x5d/0x2c0 [btrfs]
Nov 07 20:12:13 proliant kernel:  btrfs_relocate_chunk+0x31/0xa0 [btrfs]
Nov 07 20:12:13 proliant kernel:  btrfs_balance+0x799/0xea0 [btrfs]
Nov 07 20:12:13 proliant kernel:  ? _cond_resched+0x15/0x30
Nov 07 20:12:13 proliant kernel:  btrfs_ioctl_balance+0x2b8/0x370 [btrfs]
Nov 07 20:12:13 proliant kernel:  btrfs_ioctl+0x1627/0x2e00 [btrfs]
Nov 07 20:12:13 proliant kernel:  ? do_vfs_ioctl+0xa4/0x630
Nov 07 20:12:13 proliant kernel:  do_vfs_ioctl+0xa4/0x630
Nov 07 20:12:13 proliant kernel:  ksys_ioctl+0x60/0x90
Nov 07 20:12:13 proliant kernel:  __x64_sys_ioctl+0x16/0x20
Nov 07 20:12:13 proliant kernel:  do_syscall_64+0x53/0x130
Nov 07 20:12:13 proliant kernel:  entry_SYSCALL_64_after_hwframe+0x44/0xa9
Nov 07 20:12:13 proliant kernel: RIP: 0033:0x7f0ce7786427
Nov 07 20:12:13 proliant kernel: Code: 00 00 90 48 8b 05 69 aa 0c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 39 aa 0c
Nov 07 20:12:13 proliant kernel: RSP: 002b:00007ffc74b96588 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
Nov 07 20:12:13 proliant kernel: RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f0ce7786427
Nov 07 20:12:13 proliant kernel: RDX: 00007ffc74b96628 RSI: 00000000c4009420 RDI: 0000000000000003
Nov 07 20:12:13 proliant kernel: RBP: 00007ffc74b96628 R08: 0000000000000003 R09: 0000000000000078
Nov 07 20:12:13 proliant kernel: R10: fffffffffffffb66 R11: 0000000000000206 R12: 0000000000000003
Nov 07 20:12:13 proliant kernel: R13: 00007ffc74b97f61 R14: 0000000000000001 R15: 0000000000000001
Nov 07 20:12:13 proliant kernel: ---[ end trace 920de44b81e37854 ]---

Diese Fehler treten sowohl mit Kernel und btrfs-progs aus buster als auch mit denen aus buster-backports auf.

Das Neubalancieren (wie nennt man das eigentlich im Deutschen?) läuft klaglos durch, Exitcode 0. Was passiert da?

Gruß

Jan

[smutbert]

Gibt es davor möglicherweise I/O-Fehler oder ähnliches bei den Kernelmeldungen.
(So ähnlich sieht es beispielsweise aus, wenn aufgrund von Fehlern zu einem USB-Reset kommt, das Gerät infolgedessen verschwindet und danach wieder auftaucht.)

[jph]

Ja, es gibt I/O-Fehler, aber auf einem anderen SATA-Port. Kurz ein paar weitere Hardwareinfos:

• ata1.00: dort hängt eine SSD dran, /dev/sda, btrfs, /
• ata2.00: Festplatte, /dev/sdb, btrfs-RAID1, separates Dateisystem
• ata3.00: Festplatte, /dev/sdc, zweite Platte des btrfs-RAID1

Im Syslog finden sich sporadisch Einträge wie

Code: Alles auswählen

Nov 08 17:56:37 proliant kernel: print_req_error: I/O error, dev sda, sector 161402192 flags 80700
Nov 08 17:56:37 proliant kernel: ata1: EH complete
Nov 08 17:56:37 proliant kernel: ata1.00: exception Emask 0x0 SAct 0x400 SErr 0x0 action 0x6 frozen
Nov 08 17:56:37 proliant kernel: ata1.00: failed command: READ FPDMA QUEUED
Nov 08 17:56:37 proliant kernel: ata1.00: cmd 60/20:50:20:e8:59/00:00:0f:00:00/40 tag 10 ncq dma 16384 in                                                                                                         
                                          res 40/00:01:00:4f:c2/00:00:00:00:00/00 Emask 0x4 (timeout)
Nov 08 17:56:37 proliant kernel: ata1.00: status: { DRDY }
Nov 08 17:56:37 proliant kernel: ata1: hard resetting link
Nov 08 17:56:37 proliant kernel: ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Nov 08 17:56:37 proliant kernel: ata1.00: configured for UDMA/133
Nov 08 17:56:37 proliant kernel: ata1: EH complete
Nov 08 17:56:37 proliant kernel: ata1.00: Enabling discard_zeroes_data
Nov 08 17:56:37 proliant kernel: ata1.00: Enabling discard_zeroes_data

Da muss ich auch ran; ich habe den Adapter in Verdacht, mit dem ich die 2,5"-SSD in einem 3,5"-Schacht verwende.

Das ist aber / und nicht das RAID1. Die eingangs erwähnten Fehler treten aber, wie ich mittlerweile herausgefunden habe, nur auf, wenn ich ein balance auf dem RAID1 ausführe. Ein balance auf / funktioniert ohne Fehler.

balance für das RAID1 wirft auf der Konsole nicht mal einen Fehler, es wird nur das syslog zugetextet.

Scrubbing und btrfsck laufen auf beiden Dateisystemen ohne Auffälligkeiten durch.

P.S. Ja, ich habe ein Backup

[habakug]

Hallo,

welchen Kernel verwendest du?
Es gibt aktuell einen Faden in linux-btrfs [1] mit einem identischen Fehlerbild. Du könntest einen "älteren" Kernel verwenden und prüfen. Oder du wartest ab, ob daraus ein Bug-Report wird der Klarheit bringt.

Gruss, habakug

[1] https://www.spinics.net/lists/linux-btrfs/msg94184.html
oder all-in-one
https://lore.kernel.org/linux-btrfs/959 ... x.com/T/#t

[jph]

Danke für den Link, ich werde den Thread beobachten.

Der Fehler trat erstmals Anfang Oktober (ich lasse das balance monatlich per systemd-Timer durchführen) mit Kernel 4.19 auf. Ich habe jetzt probehalber auf Kernel 5.2 inkl. btrfs-progs aus buster-backports aktualisiert (neuester Kernel ist bei btrfs ohnehin keine schlechte Idee) und der Fehler tritt genau so auf.

Gab es zwischen September und Oktober ein Upgrade für den 4.19-Kernel in Debian?

Nachtrag: im Thread wird auf btrfs rescue fix-device-size hingewiesen, und in der zugehörigen Manpage darauf, dass sich mit Kernel 4.11 die Ermittlung der Gerätegröße geändert hat, was diesen Fehler verursachen kann. Das Dateisystem wurde unter Stretch mit Kernel 4.9 erzeugt. Könnte ein Fingerzeig sein…

[habakug]

Hallo,

yep, das ist ein Hinweis; Siehe auch hier [1].

This is a known bug for older created btrfs with unaligned device size.

You could resize the fs by -4K and it should make the warning disappear.

Or you can use offline tool, "btrfs rescue fix-device-size" to fix it
offline.

Gruss, habakug

[1] https://www.mail-archive.com/linux-btrf ... 84995.html

[jph]

Code: Alles auswählen

root@proliant:~# btrfs rescue fix-device-size /dev/sdb1
Fixed device size for devid 2, old size: 4000785964544 new size: 4000785960960
Fixed super total bytes, old size: 8001571925504 new size: 8001571921920
Fixed unaligned/mismatched total_bytes for super block and device items

Für sdc1 gab es nichts zu fixen; das passt zur Ausgabe im syslog, die den Fehler nur für sdb1 ausgab. Ein balance läuft jetzt ohne Fehlerhinweise durch. Zur Sicherheit lasse ich gerade ein btrfsck --readonly drüberlaufen.

Edit: devid 2 ist sdc1; offenbar werden beim Angeben eines Device eines RAID1 alle darin enthaltenen Devices geprüft und gefixt.

Danke für deine Unterstützung, habakug!