At 10:01 UTC on September 1, 2023, Aiursoft experienced a major incident.

All services were interrupted, and some data was lost. Availability was severely degraded on that day.

It took us approximately 4 hours to figure out what happened. Below is the detailed process.

Background

Aiursoft's infrastructure runs on a vSphere data center using a storage-compute separation design. Compute is handled by multiple ESXi hosts, while storage is provided by a single NFS server.

This NFS server is equipped with 12 Toshiba 2TB low-cost mechanical hard drives and two 6TB Dell enterprise-grade NVMe solid-state drives.

Previously, the NFS server was configured by assembling the 12 2TB mechanical drives into a ZFS Pool, using the two enterprise-grade SSDs as ZFS cache. This approach allowed leveraging both the capacity of the mechanical drives and the performance of the SSDs.

file

However, we quickly discovered that this configuration still resulted in slightly lower performance compared to a pure SSD setup.

Changes

As a result, we realized that using mechanical hard drives (HDDs) with solid-state caching in ZFS would create a performance bottleneck 😐. Therefore, we decided to stop using mechanical hard drives for serving business workloads. Instead, we repurposed the HDDs exclusively for backups and moved all data to NVMe solid-state drives (SSDs).

Testing confirmed that this change significantly improved read and write speeds across all services, especially random read/write performance.

Consequently, on August 30, 2023, we abandoned the approach of using SSDs as a cache. Instead, we combined two NVMe SSDs into a RAID 0 ZFS pool and created a dataset named NVME, which was mounted at /mnt/nvme to provide NFS storage services.

Soon, we began reaping the performance benefits of a pure NVMe setup. The improvement in performance from using pure NVMe SSDs was indeed very significant. Boot times, system updates, and system installation speeds all saw substantial gains.

file

Of course, at this point, we had not yet configured backups. This made it a very dangerous phase: all user data was stored in RAID 0! If any single drive failed, we would lose all data, and recovery would be impossible.

Crisis

Of course, we understand the risks involved at this stage. Therefore, immediately designing a backup strategy for the NVME SSD data is a critical task.

We initially attempted to use rsync for backups. However, considering that the files to be backed up are being read from and written to at high speeds, the efficiency of rsync is very low, and it is even difficult to completely copy a file that is currently being read from or written to.

sudo rsync -avh --inplace --partial --delete --progress /mnt/nvme/ /mnt/pool/backup/

Since we are using ZFS, we decided to leverage ZFS's snapshot feature for backups. ZFS snapshots are highly robust, allowing you to capture a snapshot of the file system without interrupting services, and then send the snapshot to another location.

Therefore, we developed the following backup script:

#sudo rsync -avh --inplace --partial --delete --progress /mnt/nvme/ /mnt/pool/backup/
echo "Installing prerequisites..."
sudo apt install -y pv

echo "Deleting existing backups..."
sudo zfs destroy pool/backup@backup
sudo zfs destroy nvme/data@backup

echo "Creating snapshot..."
sudo zfs snapshot -r nvme/data@backup

echo "Sending snapshot from nvme/data to pool/backup..."
sudo zfs send -vR nvme/data@backup | pv | sudo zfs receive -vF pool/backup

echo "Deleting data backup"
sudo zfs destroy nvme/data@backup

The purpose of the above script is to create a snapshot of /mnt/nvme/data and then send the snapshot to /mnt/pool/backup.

Theoretically, it is very safe because it does not modify production environment data, and it deletes the snapshot on the NVMe drive after sending is complete to free up space. The target for sending the snapshot is a separate ZFS Pool, so even if the send fails, it will not affect the production environment.

Considering its safety, after the script was completed, we did not test it in any experimental environment but ran it directly in the production environment. Of course, practice has proven that this decision was very wrong.

Incident

On September 1, 2023, at 10:01 UTC, we received an alert indicating that business operations had stopped.

I was checking performance information on NFS at that exact moment, so I immediately began the investigation.

As part of the troubleshooting process for the Vsphere data center, I immediately checked the status of Vsphere. At that time, I discovered that all VMs had stopped and were in an error state, specifically marked as Orphan.

I attempted to restart all VMs via VCenter, but found that none of them could start because their disks could not be found.

I then tried to access NFS on ESXi and found that NFS was inaccessible. At this point, it was determined that the NFS server had stopped.

I immediately logged into the NFS server and executed the following commands on it:

(This section contains the archived source commands actually executed after the incident occurred)

anduin@NFS:~$ zpool list
NAME   SIZE  ALLOC   FREE  CKPOINT  EXPANDSZ   FRAG    CAP  DEDUP    HEALTH  ALTROOT
nvme  11.6T  4.28T  7.35T        -         -     3%    36%  1.00x    ONLINE  -
pool  21.8T  5.02T  16.8T        -         -     2%    23%  1.00x    ONLINE  -

anduin@NFS:~$ zpool status
  pool: nvme
 state: ONLINE
  scan: scrub repaired 0B in 00:22:16 with 0 errors on Fri Sep  1 08:55:55 2023
config:

	NAME                                                        STATE     READ WRITE CKSUM
	nvme                                                        ONLINE       0     0     0
	  nvme-Dell_Express_Flash_PM1725b_6.4TB_AIC_S5C112  ONLINE       0     0     0
	  nvme-Dell_Express_Flash_PM1725b_6.4TB_AIC_S5C111  ONLINE       0     0     0

errors: No known data errors

  pool: pool
 state: ONLINE
  scan: scrub in progress since Fri Sep  1 08:35:37 2023
	3.41T scanned at 1.22G/s, 110G issued at 39.4M/s, 4.05T total
	0B repaired, 2.66% done, 1 days 05:09:52 to go
config:

	NAME                               STATE     READ WRITE CKSUM
	pool                               ONLINE       0     0     0
	  raidz2-0                         ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_33GU8WUAS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_33GV7R9AS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_33GVJ01GS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_33UW1T0AS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_52QPEN1AS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_52VPEEUAS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_62BPNH6AS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_62DPLXKAS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_62DPLY6AS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_62DPS2ZAS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_821NVTHAS  ONLINE       0     0     0
	    ata-TOSHIBA_HDWD120_821P90RAS  ONLINE       0     0     0

errors: No known data errors

anduin@NFS:~$ zfs list -t snapshot
NAME               USED  AVAIL     REFER  MOUNTPOINT
nvme/data@backup  11.0G      -     4.27T  -

anduin@NFS:~$ tmux ls
no server running on /tmp/tmux-1000/default

anduin@NFS:~$ tmux a
no sessions

anduin@NFS:~$ zfs list -t snapshot
NAME                 USED  AVAIL     REFER  MOUNTPOINT
pool/backup@backup     0B      -     4.32T  -

The information above indicates that both NVMe SSDs on the NFS server are online, and the mechanical hard drives are also online. My backup script is run using tmux, so I tried checking the status of tmux with tmux ls, but found that the tmux service had stopped.

However, a strange thing happened: two consecutive runs of zfs list -t snapshot produced different results! The first run showed a snapshot named nvme/data@backup, but the second run showed that snapshot was gone! Instead, a new snapshot appeared: pool/backup@backup.

At this point, I decided I should immediately check whether the data was still intact. This is a critical situation: I have only one copy of my data, and it is stored on a RAID 0 array. Any data loss would be catastrophic.

So I immediately tried to access the data on the NFS:

anduin@NFS:~$ cd /mnt/backup/
anduin@NFS:/mnt/backup$ ls
anduin@NFS:/mnt/backup$ cd /mnt/nvme/
anduin@NFS:/mnt/nvme$ cd /mnt/nvme/
anduin@NFS:/mnt/nvme$ ls
 Aiursoft     Books      Dvorak     Gbiner   GPT        Jimmoen   Live        Monitoring   NugetNinja   Rdf        Runner1      Shubuzuo

Fortunately: the data is still there.

At this point, I also noticed: although /mnt/nvme, which is the production NFS path, contains data, /mnt/backup does not. However, this is not surprising, as the backup script's purpose is only to send a snapshot, not to copy the data to another location.

Since the data is still there, why did the NFS server stop?

So I tried to investigate further for more clues:

anduin@NFS:~$ zfs list
NAME          USED  AVAIL     REFER  MOUNTPOINT
nvme         4.27T  6.99T       96K  none
nvme/data    4.27T  6.99T     4.27T  /mnt/nvme
pool         4.36T  11.7T      219K  none
pool/backup  4.32T  11.7T     4.32T  /mnt/nvme
pool/data    48.1G  11.7T     48.1G  /mnt/pool

In the output above, I was surprised to find that the MOUNTPOINTs of two zfs datasets were actually the same directory! This is impossible, because ZFS does not allow two datasets to be mounted to the same directory.

This situation is far beyond my understanding, so I tried changing the MOUNTPOINTs of the two datasets to different directories:

anduin@NFS:/mnt/nvme$ sudo zfs set mountpoint=/mnt/backup pool/backup
cannot unmount '/mnt/nvme': unmount failed

anduin@NFS:/mnt/nvme$ sudo zfs set mountpoint=/mnt/backup pool/backup
cannot unmount '/mnt/nvme': unmount failed

I spent a considerable amount of time here trying to change the MOUNTPOINT of two datasets to different directories, but all attempts failed. The error message was: unable to unmount /mnt/nvme because it is a busy directory. I believe this error is reasonable, as /mnt/nvme is the mount point for NFS, and NFS does not automatically unmount.

So I tried restarting the NFS service:

anduin@NFS:/mnt/nvme$ sudo systemctl stop nfs-kernel-server

Then tried modifying MOUNTPOINT again:

anduin@NFS:/mnt$ sudo zfs set mountpoint=/mnt/backup pool/backup
anduin@NFS:/mnt$ zfs list
NAME          USED  AVAIL     REFER  MOUNTPOINT
nvme         4.27T  6.99T       96K  none
nvme/data    4.27T  6.99T     4.27T  /mnt/nvme
pool         4.36T  11.7T      219K  none
pool/backup  4.32T  11.7T     4.32T  /mnt/backup
pool/data    48.1G  11.7T     48.1G  /mnt/pool

So I restarted the NFS service:

anduin@NFS:/mnt$ sudo systemctl start nfs-kernel-server

Then I tried to access the NFS server, and the issue had already been resolved.

In reality, restoring the vSphere data center took a very long time. This was because VMs in an Orphan state could not be managed through vCenter, so I had to manage them manually on ESXi. Additionally, since the data on the NFS server was corrupted, I needed to manually delete all VMs and then remount the storage.

Furthermore, because DPM and DRS were enabled in the data center, and HA was configured to use NFS, the HA system considered the system corrupted during the incident and continuously attempted to migrate VMs. Meanwhile, DPM even shut down the ESXi hosts to save power. All of these factors caused significant issues when I was restoring the data center.

The subsequent repair work took approximately three hours. Finally, at 13:00 UTC, our data center returned to normal operation.

Cause

Although our data center has returned to normal, we still need to figure out what happened.

In particular, the most bizarre phenomenon: why did two snapshot listings produce different results? And why did the MOUNTPOINT for two datasets end up being the same directory?

file

The first question was answered after carefully reading the backup script:

The backup script creates a snapshot on nvme, then copies the snapshot to another pool, and finally deletes the snapshot. At that point, tmux indicated that the backup had finished. Therefore, it is highly likely that when zfs list -t snapshot was first run, the script had not yet completed and was still executing sudo zfs send -vR nvme/data@backup | pv | sudo zfs receive -vF pool/backup.

#sudo rsync -avh --inplace --partial --delete --progress /mnt/nvme/ /mnt/pool/backup/
echo "Installing prerequisites..."
sudo apt install -y pv

echo "Deleting existing backups..."
sudo zfs destroy pool/backup@backup
sudo zfs destroy nvme/data@backup

echo "Creating snapshot..."
sudo zfs snapshot -r nvme/data@backup

echo "Sending snapshot from nvme/data to pool/backup..."
sudo zfs send -vR nvme/data@backup | pv | sudo zfs receive -vF pool/backup

echo "Deleting data backup"
sudo zfs destroy nvme/data@backup

Almost simultaneously, the script finished executing at the question mark, so when zfs list -t snapshot was run for the second time, the snapshot on the nvme device had already been deleted, while the snapshot on the pool had already been created.

As for the second issue, we quickly ran the aforementioned script in the lab and reached the exact same conclusion:

file

Running the aforementioned script will inevitably result in the MOUNTPOINT of both datasets being the same directory. Under normal operation, ZFS does not allow two datasets to be mounted to the same directory.

This might be because we did not correctly understand the purpose of zfs send and receive. In our understanding, zfs send and receive are used to copy a snapshot to another dataset. However, in reality, it is highly likely that they maintain the consistency of the MOUNTPOINT. Therefore, zfs send and receive will also copy the MOUNTPOINT, leading to data overlap between the two datasets.

Additionally, we have re-evaluated our understanding of zfs list: the MOUNTPOINT it displays is merely metadata of a dataset and is unrelated to whether the dataset is actually mounted. Therefore, determining whether a directory is a ZFS Dataset should not be based on zfs list, but rather on df -Th. It was precisely this critical misunderstanding that caused obstacles during our investigation.

Lessons Learned

This incident has taught us a very valuable lesson. First, we should test scripts in a test environment rather than running them directly in the production environment. Production execution should only occur when we are highly confident in the operations and the scripts have been thoroughly tested.

Second, we should implement more rigorous checks and monitoring of script execution results. We plan to build additional Prometheus-based monitoring and alerting systems for crontab and tmux.

Finally, we have decided to refactor the legacy backup scripts. The new scripts will be repeatedly validated in the test environment before being executed line by line on the production servers.

Improvements

In the new script, we revisited our approach to backups:

Our actual goal is not simply to send snapshots over; rather, we need the files to remain accessible even after disk failure. Therefore, we decided to combine the use of snapshot send and rollback.

After performing the rollback, we can directly mount the ZFS dataset to access the files from the transferred snapshot. At this point, the snapshot is no longer important and can be safely deleted. (This does not affect security, as the transferred files are archival files that will not be modified and will not differ from the snapshot.)

Of course, to avoid the issues mentioned above, we simply unmount the entire dataset during the backup process. Whether a directory is mounted is not a ZFS issue, but rather a design philosophy of Linux itself: devices are mounted as directories, which makes it more difficult to determine whether a directory belongs to a specific device compared to Windows. On Windows, a failing or disconnected disk is directly and bluntly reported as an error like "Drive D not found." In the Linux world, however, extreme caution is required. Naturally, unmounting the dataset before sending the snapshot naturally avoids these issues.

The final backup script is:

#sudo rsync -avh --exclude "*.vswp" --inplace --partial --delete --progress /mnt/nvme/ /mnt/pool/backup/

echo "Deleting exising backups..."
sudo zfs destroy pool/backup@backup
sudo zfs destroy nvme/data@backup

echo "Creating snapshot..."
sudo touch /mnt/nvme/$(date +"%Y-%m-%d-%H-%M-%S")
sudo zfs snapshot nvme/data@backup

echo "Unmounting backup..."
sudo zfs unmount pool/backup

echo "Sending snapshot from nvme/data to pool/backup..."
sudo bash -c 'zfs send -v nvme/data@backup | zfs receive -vF pool/backup'

echo "Reseting workspace to snapshot..."
sudo zfs rollback pool/backup@backup
sudo zfs mount pool/backup

echo "Deleting snapshots..."
sudo zfs destroy nvme/data@backup
sudo zfs destroy pool/backup@backup

The script above deletes all snapshots (this is safe because the backed-up files are located under /mnt/backup), then tags the data, creates a snapshot, sends the entire snapshot to the backup pool, immediately rolls back, and then mounts it so that the files within the snapshot appear as a directory. Finally, it deletes the snapshot (this is also safe because the backed-up files are already under /mnt/backup).

We have tested this multiple times in the lab and performed several backups in production environments. It works well, and in any scenario, the data has at least two copies:

file

As shown in the image, the green line represents the production pool, and the yellow line represents the backup pool.