The two-hour stat: why VM disk images don't belong on CephFS

A few months ago, we received a support request from one of our customers. They were in the middle of migrating, on their own, some large virtual machines from VMware to Proxmox. As one of the steps, they decided to move virtual machine disks (as VMDK files) to storage supported both by VMware and Proxmox. And that storage was an NFS share configured via croit and backed by CephFS. All OSDs in this cluster were NVMe-based.

The migration went almost smoothly: the only unexpected thing was the default 1TB file size limit on CephFS, which the customer increased (ceph fs set cephfs max_file_size $(( 10 ** 14 ))), and then they were able to run their workload from the NFS share while still on VMware. That was until the cluster was affected by a temporary network outage.

Then, VMware lost access to the disk image. No amount of restarting VMware, NFS server, or failing over the MDS helped. Access was timing out: on the VMware side, the error was “Mount failed: Unable to complete Sysinfo operation”, and at that point the customer raised a ticket.

The first thing that we did was to localize the problem. Without further information, it could plausibly be in the MDS, in the NFS server, or even in VMware. According to the customer, they could mount the CephFS filesystem on a Linux host, but the ls command in the directory containing the virtual machine disk images was hanging. Other folders could be listed without any issues. This fact alone narrowed the problem down to the MDS.

An attempt to list the problematic directory also raised the MDS_SLOW_OP warning. We inspected (ceph tell mds.0 ops) what the MDS was doing and found two “lookup” operations for *-flat.vmdk files. They could be cleared by evicting the client, but any attempt to list the files using the ls command resulted in these “slow” operations reappearing, and the client saw no response and appeared to be stuck waiting.

Actually, ls hanging was a red herring. By default, ls is aliased to ls --color=auto, and the difference is crucial. To colorize its output, ls needs to know the type of each file, and this requires a stat operation. This stat operation returns a structure containing the file type (i.e., is it a regular file, a directory, a symlink, or something else), its size, permissions, and some other fields. And it’s the stat operation that was not returning. ls (expanded to ls --color=auto) never completed. /bin/ls worked just fine.

The directory containing the disk image allowed listing its contents, showing the *.vmdk file with the metadata and the *-flat.vmdk file, which stored the actual disk contents. However, any attempt to “stat” the flat.vmdk file just hung and, after some time, led to the MDS_SLOW_OPS warning. Not surprisingly, it pointed to the client that attempted the stat, and there was a steady 1000-IOPS extra load on the data pool that ceased when we evicted the client.

There seemed to be no way to clear this roadblock: VMware needed to know the disk image size, and to achieve that, it needed to stat the flat disk image, which, from VMware perspective, was timing out.

To debug what the MDS was doing, we used the debug_objecter configuration parameter:

ceph config set mds debug_objecter 10

This logs every object that the daemon accesses on OSDs.

We found that the MDS attempted to access sequentially, from the highest-numbered ones to the lowest, all objects that could, in theory, correspond to the problematic file. That’s slow. For a 32-terabyte file, the MDS would ask OSDs about all 8388608 possible objects that make the file, no matter whether they exist or not. A direct test using the rados get command with a couple of objects confirmed that they were readable. At that point, one of the support engineers suggested writing a script that would read all the objects and reconstruct the disk image from them.

But why did the MDS try to enumerate all possible objects in the file? During normal operation, it gets the size and other inode metadata fields such as the modification time (mtime) directly from the inode object stored in RADOS. But there is one situation where the MDS cannot trust the stored fields and must rederive them. It’s when a client was evicted while holding a capability covering a range of bytes it is permitted to write without consulting anyone else. This matched the customer-reported history of the problem: network outage triggering the client auto-eviction timeout.

During the attribute recovery, the size is taken from the highest-numbered object that exists, unless the size already recorded in the inode is higher. The modification time is similarly rederived as the maximum RADOS-level modification time of all objects that could possibly make the file. At approximately 8 million possible objects and 1000 objects probed per second, that would have taken approximately two hours – far more than VMware’s patience, far more than Ceph’s own patience, and more than the usual human patience would allow.

Two hours. That’s more than a human can wait for a computer system to react when unprepared, but still less than it would take one to produce a script that reconstructs the file from objects (including corner cases like intentionally-missing objects in the middle of a sparse file) and to convince colleagues that it is correct.

In the end, we decided not to try to outwit the problem with low-level data recovery approaches, parameter tuning, or custom scripts. All we needed was to outwait one exceptionally slow operation and let everything else happen naturally. So we mounted the CephFS and started an “rbd import” process. Initially, it appeared to do nothing, and the MDS_SLOW_OPS warning appeared, as expected. We did nothing more. In two hours, as predicted, the progress indicator started moving, and the warning disappeared. After some more hours, the customer got an RBD image with their data intact.

Actually, Ceph documentation already contains a warning against increasing the maximum file size on CephFS:

When users create a file of an enormous size (without necessarily writing any data to it), some operations (such as deletes) cause the MDS to have to do a large number of operations to check if any of the RADOS objects within the range that could exist (according to the file size) really existed.

The max_file_size setting prevents users from creating files that appear to be e.g. exabytes in size, causing load on the MDS as it tries to enumerate the objects during operations like stats or deletes.

That’s precisely the problem that the customer faced and we resolved. Our recommendation is to avoid triggering it. Do not store terabyte-sized files on CephFS. Use RBD, not CephFS, for disk images, and export them via iSCSI or NVMe-oF if required for compatibility with software that cannot talk to Ceph directly. And please note that croit offers consultancy arrangements for workload migrations from VMware hypervisors to Proxmox.