Bug#941712: hfs partitions corrupted when removing lots of files over network
Package: hfsutils
Version: 3.2.6-14
Severity: grave
#### Output from uname -a
Linux raspberrypi 4.19.66-v7l+ #1253 SMP Thu Aug 15 12:02:08 BST 2019 armv7l GNU/Linux
#### Output from apt show libc6 2>&1 | grep ^Version
Version: 2.28-10+rpi1
#### Hardware;
RaspberryPi model 2b and RaspberryPi model 4b
#### What led up to the situation?
I set up a new RaspberryPi to be a Samba network file server for an HFS partition (see setup section at end of this email for details). I then deleted about 300 files from the HFS partition from a client machine. This caused an "Internal error: Oops: 206 [#1] SMP ARM". See kern.log below for Oops details.
After the error, the filesytem was corrputed and could not be repaired using fsck. See fsck output below.
To reproduce the problem, I run the following from a client machine;
for i in {1..300}; do touch /Volumes/TimeMachineBackup/$i; done ; rm /Volumes/TimeMachineBackup/*
Every time I re-run this test on a freshly formatted drive, the same error occurs and the filesystem is always corrupted and cannot be repaired (i.e. total data loss).
#### What exactly did you do (or not do) that was effective (or ineffective)?
I tried all of the following;
- Replaced Samba network sharing with Netatalk
- Re-installed Raspbian from scratch
- Different mkfs.hfs formatting options to add journal files and alter the b-node sizes
- Various samba configurations to change sync / async options, threading options, permissions, etc
- 3 different disk drives (USB flash drive, USB powered HDD, Separately powered HDD)
- 2 different RaspberryPi models (2b and 4b)
- Different network connections speeds (WiFi at 200Mbs, Ethernet at 100Mbs, Ethernet at 1000Mbs)
- Deleted 300 files locally on the RaspberryPi file server (i.e. not over network)
- Replaced HFS+ format with EXT4
#### What was the outcome of this action?
None the the things I tried above had any impact on the problem except;
- The problem did not occur at all when deleting locally on the RaspberryPi file server.
- The problem did not occur at all when HFS+ was replaced with EXT4
#### What outcome did you expect instead?
Given the problem did not occur locally on the file server, but did over Sambaa, I expected the problem to go away when I replaced Samba with Netatalk. It did not.
I wonder if the problem relates to how all file-networking protocols interact with local filesystems?
#############################################################
# LOGS AND OUTPUT #
#############################################################
##### kern.log;
Sep 26 16:09:25 raspberrypi kernel: [ 222.906719] hfsplus: trying to free free bnode 0(1)
Sep 26 16:09:25 raspberrypi kernel: [ 222.906844] hfsplus: trying to free free bnode 0(1)
Sep 26 16:09:25 raspberrypi kernel: [ 222.906893] Unable to handle kernel NULL pointer dereference at virtual address 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.906906] pgd = bc442823
Sep 26 16:09:25 raspberrypi kernel: [ 222.906914] [00000000] *pgd=11d05003, *pmd=00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.906933] Internal error: Oops: 206 [#1] SMP ARM
Sep 26 16:09:25 raspberrypi kernel: [ 222.906942] Modules linked in: nls_utf8 hfsplus bnep hci_uart btbcm serdev bluetooth ecdh_generic 8021q garp stp llc vc4 v3d drm_kms_helper brcmfmac gpu_sched brcmutil drm drm_panel_orientation_quirks snd_bcm2835(C) snd_soc_core sha256_generic snd_compress snd_pcm_dmaengine snd_pcm sg snd_timer syscopyarea sysfillrect sysimgblt fb_sys_fops cfg80211 rfkill snd raspberrypi_hwmon hwmon bcm2835_codec(C) bcm2835_v4l2(C) v4l2_mem2mem v4l2_common videobuf2_vmalloc bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common videodev media vc_sm_cma(C) rpivid_mem uio_pdrv_genirq uio fixed ip_tables x_tables ipv6
Sep 26 16:09:25 raspberrypi kernel: [ 222.907150] CPU: 3 PID: 634 Comm: smbd Tainted: G C 4.19.66-v7l+ #1253
Sep 26 16:09:25 raspberrypi kernel: [ 222.907160] Hardware name: BCM2835
Sep 26 16:09:25 raspberrypi kernel: [ 222.907177] PC is at kmap+0x1c/0x44
Sep 26 16:09:25 raspberrypi kernel: [ 222.907188] LR is at _cond_resched+0x30/0x50
Sep 26 16:09:25 raspberrypi kernel: [ 222.907196] pc : [<c021bfe4>] lr : [<c0997394>] psr: 60000013
Sep 26 16:09:25 raspberrypi kernel: [ 222.907205] sp : dc0e3cc0 ip : dc0e3cb0 fp : dc0e3cd4
Sep 26 16:09:25 raspberrypi kernel: [ 222.907214] r10: 0000002e r9 : dcdf9c48 r8 : 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907222] r7 : dc0e3d02 r6 : dcdf9c7c r5 : 00000002 r4 : 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907231] r3 : 00000000 r2 : c0e953fc r1 : 00000000 r0 : 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907241] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user
Sep 26 16:09:25 raspberrypi kernel: [ 222.907250] Control: 30c5383d Table: 1e71cfc0 DAC: 55555555
Sep 26 16:09:25 raspberrypi kernel: [ 222.907259] Process smbd (pid: 634, stack limit = 0xf933c1ef)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907268] Stack: (0xdc0e3cc0 to 0xdc0e4000)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907278] 3cc0: 00000002 00000002 dc0e3cfc dc0e3cd8 bfa23a44 c021bfd4 c1004d88 00002000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907290] 3ce0: 0000000e 00001ff8 00001ffc 0000002e dc0e3d1c dc0e3d00 bfa23af0 bfa23a08
Sep 26 16:09:25 raspberrypi kernel: [ 222.907302] 3d00: e0ff3d80 889206f5 dcdf9c40 dc0e3d80 dc0e3d4c dc0e3d20 bfa25d54 bfa23ab8
Sep 26 16:09:25 raspberrypi kernel: [ 222.907314] 3d20: 00000010 c1004d88 dc0e3d80 dc988ae8 000001a3 000001a3 00000002 dc0e3dc8
Sep 26 16:09:25 raspberrypi kernel: [ 222.907325] 3d40: dc0e3d7c dc0e3d50 bfa283c0 bfa25c38 00000002 a3010000 10000000 889206f5
Sep 26 16:09:25 raspberrypi kernel: [ 222.907337] 3d60: 00000000 dc988ae8 000001a3 c1004d88 dc0e3dc4 dc0e3d80 bfa289d4 bfa28308
Sep 26 16:09:25 raspberrypi kernel: [ 222.907349] 3d80: dca03800 dca0390c dd44f000 dcdf9c40 ffffffff 0000000e 0000002a 00000038
Sep 26 16:09:25 raspberrypi kernel: [ 222.907361] 3da0: 00000004 889206f5 00000000 c1004d88 dc988ae8 dc975c00 dc0e3e7c dc0e3dc8
Sep 26 16:09:25 raspberrypi kernel: [ 222.907372] 3dc0: bfa21848 bfa28978 5d8c5615 00000000 00000000 bfa240ec d7e2d000 d7e2d206
Sep 26 16:09:25 raspberrypi kernel: [ 222.907384] 3de0: de66d000 dcdf9600 00000001 00000032 00000008 0000003a 00000010 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907395] 3e00: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907407] 3e20: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907418] 3e40: 00000000 00000000 00000000 889206f5 c0997394 d7eefce8 c1004d88 cf03a330
Sep 26 16:09:25 raspberrypi kernel: [ 222.907430] 3e60: dd67e100 000001a3 dc988ae8 dd67e17c dc0e3efc dc0e3e80 bfa220c4 bfa21640
Sep 26 16:09:25 raspberrypi kernel: [ 222.907442] 3e80: de190010 cf03a338 2c4d3c3b dd33e6e8 dc0e3f50 c03bc790 0000000b dc988ae8
Sep 26 16:09:25 raspberrypi kernel: [ 222.907453] 3ea0: 00000003 00000001 00000000 d7eefce8 dc0e3edc dc0e3ec0 c03bc790 c0997394
Sep 26 16:09:25 raspberrypi kernel: [ 222.907465] 3ec0: 00000000 d7eefd68 dc0e3ee4 889206f5 c0997394 00000000 cf03a330 d7eefce8
Sep 26 16:09:25 raspberrypi kernel: [ 222.907477] 3ee0: dc988ae8 d7eefd68 dc0e3f44 dc0e3f40 dc0e3f2c dc0e3f00 c03bd64c bfa2205c
Sep 26 16:09:25 raspberrypi kernel: [ 222.907488] 3f00: dc0e3f2c dc0e3f10 00000000 de190000 00000000 dc0e3f50 d7eefce8 cf03a330
Sep 26 16:09:25 raspberrypi kernel: [ 222.907500] 3f20: dc0e3f94 dc0e3f30 c03c1dac c03bd590 dc0e3f50 dc0e3f40 c1004d88 ffffff9c
Sep 26 16:09:25 raspberrypi kernel: [ 222.907512] 3f40: 00000000 00000000 dcc6f210 dd33e6e8 2c4d3c3b 00000003 de190010 dc4a7910
Sep 26 16:09:25 raspberrypi kernel: [ 222.907524] 3f60: b6f2e968 889206f5 0000000a 01a1fd98 b6f2e968 019f22c8 0000000a c02011c4
Sep 26 16:09:25 raspberrypi kernel: [ 222.907535] 3f80: dc0e2000 0000000a dc0e3fa4 dc0e3f98 c03c1e60 c03c1b78 00000000 dc0e3fa8
Sep 26 16:09:25 raspberrypi kernel: [ 222.907547] 3fa0: c0201000 c03c1e48 01a1fd98 b6f2e968 01a1e988 01a1fd98 00000000 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907559] 3fc0: 01a1fd98 b6f2e968 019f22c8 0000000a 01a25b08 b6a68090 b6e23bb8 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907570] 3fe0: b6e254f8 bed343fc b4007710 b6290b9c 60000010 01a1e988 00000000 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907603] [<c021bfe4>] (kmap) from [<bfa23a44>] (hfsplus_bnode_write+0x48/0xb0 [hfsplus])
Sep 26 16:09:25 raspberrypi kernel: [ 222.907654] [<bfa23a44>] (hfsplus_bnode_write [hfsplus]) from [<bfa23af0>] (hfsplus_bnode_write_u16+0x44/0x60 [hfsplus])
Sep 26 16:09:25 raspberrypi kernel: [ 222.907687] [<bfa23af0>] (hfsplus_bnode_write_u16 [hfsplus]) from [<bfa25d54>] (hfsplus_brec_remove+0x128/0x178 [hfsplus])
Sep 26 16:09:25 raspberrypi kernel: [ 222.907720] [<bfa25d54>] (hfsplus_brec_remove [hfsplus]) from [<bfa283c0>] (__hfsplus_delete_attr+0xc4/0x108 [hfsplus])
Sep 26 16:09:25 raspberrypi kernel: [ 222.907751] [<bfa283c0>] (__hfsplus_delete_attr [hfsplus]) from [<bfa289d4>] (hfsplus_delete_all_attrs+0x68/0xe0 [hfsplus])
Sep 26 16:09:25 raspberrypi kernel: [ 222.907782] [<bfa289d4>] (hfsplus_delete_all_attrs [hfsplus]) from [<bfa21848>] (hfsplus_delete_cat+0x214/0x330 [hfsplus])
Sep 26 16:09:25 raspberrypi kernel: [ 222.907813] [<bfa21848>] (hfsplus_delete_cat [hfsplus]) from [<bfa220c4>] (hfsplus_unlink+0x74/0x1ec [hfsplus])
Sep 26 16:09:25 raspberrypi kernel: [ 222.907837] [<bfa220c4>] (hfsplus_unlink [hfsplus]) from [<c03bd64c>] (vfs_unlink+0xc8/0x1b0)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907853] [<c03bd64c>] (vfs_unlink) from [<c03c1dac>] (do_unlinkat+0x240/0x280)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907867] [<c03c1dac>] (do_unlinkat) from [<c03c1e60>] (sys_unlink+0x24/0x28)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907881] [<c03c1e60>] (sys_unlink) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907892] Exception stack(0xdc0e3fa8 to 0xdc0e3ff0)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907901] 3fa0: 01a1fd98 b6f2e968 01a1e988 01a1fd98 00000000 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907913] 3fc0: 01a1fd98 b6f2e968 019f22c8 0000000a 01a25b08 b6a68090 b6e23bb8 00000000
Sep 26 16:09:25 raspberrypi kernel: [ 222.907924] 3fe0: b6e254f8 bed343fc b4007710 b6290b9c
Sep 26 16:09:25 raspberrypi kernel: [ 222.907934] Code: e52de004 e8bd4000 e1a04000 eb1decdf (e5943000)
Sep 26 16:09:25 raspberrypi kernel: [ 222.907946] ---[ end trace 6cfde67f15cd72ed ]---
#### fsck output;
fsck from util-linux 2.33.1
** /dev/sda2
** Checking HFS Plus volume.
** Checking Extents Overflow file.
** Checking Catalog file.
Invalid leaf record count
(It should be 176 instead of 340)
Invalid B-tree Header
** Checking Catalog hierarchy.
Invalid directory item count
(It should be 85 instead of 167)
** Checking Extended Attributes file.
Invalid sibling link
(8, 4)
** Volume check failed.
#############################################################
# SET UP SECTION #
#############################################################
Below are my notes for setting up my RaspberryPi from scratch and reproducing the error.
#### New install of Rasbian on Mac;
# If new device or ip address, add pi to ssh config;
cat << EOF >> ~/.ssh/config
Host pi
HostName 192.168.1.120
User pi
EOF
# Flash pi's microSD card;
diskutil list | grep -C2 Linux # Find /dev/disk_ for rpi boot SD card
diskutil unmountDisk /dev/disk_ # ...with number identified above
sudo dd bs=1m if=/Users/grahamcoster/Reference/IT/RasberryPi\ projects/Rasbian\ TimeMachine\ server/2019-07-10-raspbian-buster-lite.img of=/dev/rdisk_ conv=sync # NB: Takes 2-3 miuntes. Press crtl+T (i.e. send SIGINFO) to see progress
touch /Volumes/boot/ssh # Allow first ssh into pi so can be headless
diskutil unmountDisk /dev/disk_ # Then eject SD card and boot pi with it
vi ~/.ssh/known_hosts # Remove any previous entry for pi (?192.168.1.120)
# After pi boots and is connected via ethernet, set up mac ssh config;
ssh-copy-id pi@192.168.1.120 # NB: Default p/w is raspberry
ssh pi # NB: Can use this instead; ssh -l pi 192.168.1.120 # Default p/w is raspberry
# On pi
ethtool eth0 | less # Check pi ethernet speed is as expected
##### Raspian OS update on pi
sudo raspi-config
- interfacing options -> SSH on
- localisation -> timezone = Australia
sudo apt-get update
sudo apt-get upgrade --assume-yes --auto-remove
sudo reboot
##### HFS+ package installation
sudo apt-get install --assume-yes --auto-remove hfsplus hfsutils hfsprogs
sudo reboot
# NB: Can try the following if HFS+ partitions go wrong;
sudo fsck.hfsplus /dev/sda_ # Use to check filesystem (should umount first)
sudo fsck.hfsplus -fryd /dev/sda_ # Could try this to force repairs if needed
sudo apt-get install testdisk # Could also try this to force repairs if needed
##### SAMBA package installation;
sudo apt-get install --assume-yes --auto-remove samba samba-common-bin # NB: Said NO to setting up DHCP WINS config
sudo reboot
sudo cp /etc/samba/smb.conf /etc/samba/smb.conf.bak
#### SAMBA configutation;
sudo bash # Become root so can append HERE-DOC
cat << EOF >> /etc/samba/smb.conf
[global]
min protocol = SMB2
ea support = yes
vfs objects = catia fruit streams_xattr
fruit:aapl = yes
readdir_attr:aapl_rsize = yes
readdir_attr:aapl_finder_info = yes
readdir_attr:aapl_max_access = yes
fruit:nfs_aces = yes
fruit:copyfile= yes
fruit:metadata = netatalk
fruit:resource = file
fruit:locking = none
fruit:encoding = private
unix extensions = yes
fruit:model = MacSamba
spotlight = no
smb2 max read = 8388608
smb2 max write = 8388608
smb2 max trans = 8388608
smb2 leases = yes
aio read size = 1
aio write size = 1
kernel oplocks = no
use sendfile = yes
strict sync = yes
sync always = no
delete veto files = true
fruit:posix_rename = yes
fruit:veto_appledouble = yes
fruit:zero_file_id = yes
fruit:wipe_intentionally_left_blank_rfork = yes
fruit:delete_empty_adfiles = yes
disable netbios = yes
dns proxy = no
smb ports = 445
name resolve order = host bcast
[TimeMachineBackup]
comment = Time Machine
path = /media/tm/tm_backups
browseable = yes
writeable = yes
create mask = 0600
directory mask = 0700
fruit:aapl = yes
vfs objects = catia fruit streams_xattr
fruit:time machine = yes
# fruit:time machine max size = SIZE <<<<<
strict sync = yes
spotlight = no
EOF
exit # Stop being root
sudo samba restart # Restart samba service and check it doesn't complain about updated configuration
sudo useradd tm -m -G users # Create tm user for samba sharing
sudo smbpasswd -a tm # Set password the same as default pi p/w ; raspberry
#### Format drive
ls /dev/sda_ # Work out drive device number
sudo mkfs.hfsplus /dev/sda2 -v timemachine # FOR HFS+
sudo mkfs.ext4 /dev/sda2 # FOR EXT4
#### Mount drive
[ ! -d /media/tm ] && sudo mkdir -m 1777 /media/tm # Create drive mount point
sudo chown tm /media/tm # Set tm user as owner of mount point
sudo su tm # Become tm user
[ ! -d /media/tm/tm_backups ] && mkdir /media/tm/tm_backups # Get tm user to create samba share point
exit # Go back to being pi user
sudo mount /dev/sda2 /media/tm # Mount with defaults
df -h # And check /media/tm has mounted correctly
# Now check on mac that samba share is available and can create files
#### Set up auto-mount of drive on boot
ls -lha /dev/disk/by-uuid # Note UUID of USB drive (e.g. sda2)
sudo vi /etc/fstab # And append one of the following;
UUID=<uuid noted above> /media/tm hfsplus rw,exec,auto,nosuid,nodev,user 0 0 # FOR HFS+
UUID=<uuid noted above> /media/tm ext4 rw,exec,auto,nosuid,nodev,user 0 0 # FOR EXT4
sudo crontab -e # And append the following to delay mounting until HDD spun-up;
@reboot sleep 30 && mount /media/tm
#### Ensure samba service and drive mounting is all good on reboot
sudo reboot
df -h # And check /media/tm has mounted correctly
#### To reproduce error;
# On pi;
sudo mkdir /media/tm
sudo chown tm /media/tm
sudo umount /media/tm
sudo mkfs.hfsplus /dev/sda2
sudo mount -t hfsplus -o force,rw /dev/sda2 /media/tm
[ ! -d /media/tm ] && sudo mkdir -m 1777 /media/tm
sudo chown tm /media/tm
sudo su tm
[ ! -d /media/tm/tm_backups ] && mkdir /media/tm/tm_backups
exit
# Passing test on pi;
sudo su tm
for i in {1..300}; do touch /media/tm/tm_backups/$i; done ; rm /media/tm/tm_backups/*
exit
# Failing test on mac;
for i in {1..300}; do touch /Volumes/TimeMachineBackup/$i; done ; rm /Volumes/TimeMachineBackup/*
Reply to: