Bug: rsync backup fails with ENOENT on unlink when a deleted folder has a sibling like "name-2" (syncer.js compares paths in the wrong order)

[imc67]

On one of my servers I added a second backup site of type filesystem (rsync format, local disk) next to the regular sshfs one. That local site fails now and then with an error like this, always inside a WP Rocket page cache folder:

ENOENT: no such file or directory, unlink '/var/backups/cloudron/snapshot/app_<id>/data/public/wp-content/cache/wp-rocket/<site>/evenement/<post-slug>/index-https.html_gzip'

It failed 2 out of about 11 runs. One of them was the backup before the platform update to 10.1.3 (the site is enabled for updates), so that update attempt was aborted and only went through an hour later. The sshfs site on the same server succeeded 150 out of 150 runs in the same period.

I traced it to src/syncer.js and could reproduce it with Cloudron's own code. Everything below is from 10.1.3; the file is identical in 10.0.5.

What goes wrong

The sync cache is written in traversal order: depth first, with the names in each folder sorted. For a folder romeo-julia with a sibling romeo-julia-2 that order is:

evenement/romeo-julia
evenement/romeo-julia/index-https.html
evenement/romeo-julia/index-https.html_gzip
evenement/romeo-julia-2
evenement/romeo-julia-2/index-https.html

traverse() and advanceCache() then compare cache entries and the current entry with plain string comparison (cache[curCacheIndex].path < entryPath on lines 99 and 124, cachePath > entryPath on line 131). In plain string order - (0x2D) and . (0x2E) sort before / (0x2F), so romeo-julia-2 < romeo-julia/index-https.html. That does not match the cache order.

When romeo-julia disappears (WP Rocket purges the cache of that page) and romeo-julia-2 still exists, the next run produces this delete queue:

removedir evenement/romeo-julia                     (missing)
remove    evenement/romeo-julia/index-https.html    (missing)
remove    evenement/romeo-julia/index-https.html_gzip   (missing)
removedir evenement/romeo-julia-2                   (missing)

and this add queue:

add       evenement/romeo-julia-2/index-https.html  (new)

So there are two problems:

1. The files inside the removed folder are queued again as separate remove operations, because lastRemovedDir is local to each advanceCache() call and the comparison stops halfway. backupformat/rsync.js processes the delete queue with async.eachLimit(…, concurrency). The removedir (rm -rf) therefore runs in parallel with the remove of a file inside that folder. storage/filesystem.js remove() does a statSync followed by an unlinkSync and throws on the error. If rm -rf deletes the file between the two calls, the whole backup fails with ENOENT. On sshfs, removeDir runs rm -rf over a separate ssh connection, which is much slower, so the individual removes almost always finish first. That is presumably why I only see the failure on the local target.
2. The sibling romeo-julia-2, which did not change, is removed from the snapshot and uploaded again as "new". That is not an error, but it is unnecessary work on every backup where this happens, on every target.

With a sibling without a dash (romeo-julia2) the delete queue is a single removedir, as expected.

This is a common pattern on WordPress: posts and events with the same title get the slugs name, name-2, name-3, and every caching plugin writes a folder per slug.

Reproduction

The script uses the real syncer.js, datalayout.js and storage/filesystem.js from /home/yellowtent/box and works only in /tmp/syncer-repro. Run it as yellowtent with the box environment:

sudo -u yellowtent env HOME=/home/yellowtent BOX_ENV=cloudron NODE_ENV=production /usr/local/node-24.19.0/bin/node /tmp/syncer-repro.mjs

import { createRequire } from 'node:module';
import fs from 'node:fs';
import path from 'node:path';

const BOX = '/home/yellowtent/box';
const async = createRequire(BOX + '/package.json')('async');
const { default: syncer } = await import(process.env.SYNCER || (BOX + '/src/syncer.js'));
const { default: DataLayout } = await import(BOX + '/src/datalayout.js');
const { default: storage } = await import(BOX + '/src/storage/filesystem.js');

const ROOT = '/tmp/syncer-repro', SRC = ROOT + '/src', DEST = ROOT + '/dest', CACHE = ROOT + '/test.sync.cache';
const reset = () => { fs.rmSync(ROOT, { recursive: true, force: true }); fs.mkdirSync(SRC, { recursive: true }); fs.mkdirSync(DEST, { recursive: true }); };
const write = (rel) => { for (const base of [ SRC, DEST ]) { const p = path.join(base, rel); fs.mkdirSync(path.dirname(p), { recursive: true }); fs.writeFileSync(p, 'x'); } };
const sync = () => syncer.sync(new DataLayout(SRC, []), CACHE);
async function syncAndFinalize() {
    const r = await sync();
    for (const a of r.addQueue) r.integrityMap.set(a.path, { size: 1, sha256: 'x' });
    await syncer.finalize(r.integrityMap, CACHE);
}

// 1. the queues
reset();
write('evenement/romeo-julia/index-https.html');
write('evenement/romeo-julia/index-https.html_gzip');
write('evenement/romeo-julia-2/index-https.html');
await syncAndFinalize();
fs.rmSync(path.join(SRC, 'evenement/romeo-julia'), { recursive: true });
const { delQueue, addQueue } = await sync();
console.log(delQueue, addQueue);

// 2. the failure: process the delete queue like backupformat/rsync.js does
const config = { _provider: 'filesystem', backupDir: DEST, prefix: '' };
let failed = 0;
for (let run = 0; run < 50; run++) {
    reset();
    for (let i = 0; i < 200; i++) { write(`e/p${i}/index-https.html`); write(`e/p${i}/index-https.html_gzip`); write(`e/p${i}-2/index-https.html`); }
    await syncAndFinalize();
    for (let i = 0; i < 200; i++) fs.rmSync(path.join(SRC, `e/p${i}`), { recursive: true });
    const { delQueue } = await sync();
    await async.eachLimit(delQueue, 10, async (c) => {
        if (c.operation === 'removedir') await storage.removeDir(config, {}, c.path, () => {});
        else if (c.operation === 'remove') await storage.remove(config, c.path);
    }).catch((e) => { failed++; if (failed === 1) console.log(e.message); });
}
console.log(`failed runs: ${failed}/50`);
fs.rmSync(ROOT, { recursive: true, force: true });

Result on 10.1.3: part 1 prints exactly the queues shown above. Part 2 failed in 46, 47 and 50 of the 50 runs (three attempts), with errors like ENOENT: no such file or directory, unlink '/tmp/syncer-repro/dest/e/p72/index-https.html'. With p${i}2 instead of p${i}-2 as the sibling name it fails 0 out of 50 times.

Suggested fix

Compare paths per component, so that the comparison follows the same order as the traversal:

// compare paths per component, so that the order matches the depth-first traversal order
// ("a" < "a/x" < "a-2"), instead of plain string order ("a" < "a-2" < "a/x")
function comparePaths(a, b) {
    const x = a.split('/'), y = b.split('/');
    for (let i = 0; i < Math.min(x.length, y.length); i++) {
        if (x[i] !== y[i]) return x[i] < y[i] ? -1 : 1;
    }
    return x.length - y.length;
}

and use it in the three places:

-        for (; curCacheIndex !== cache.length && (entryPath === '' || cache[curCacheIndex].path < entryPath); ++curCacheIndex) {
+        for (; curCacheIndex !== cache.length && (entryPath === '' || comparePaths(cache[curCacheIndex].path, entryPath) < 0); ++curCacheIndex) {
-            if (curCacheIndex !== cache.length && cache[curCacheIndex].path < entryPath) { // files disappeared. first advance cache as needed
+            if (curCacheIndex !== cache.length && comparePaths(cache[curCacheIndex].path, entryPath) < 0) { // files disappeared. first advance cache as needed
-            if (cachePath === null || cachePath > entryPath) { // new files appeared
+            if (cachePath === null || comparePaths(cachePath, entryPath) > 0) { // new files appeared

With this change, on a copy of syncer.js, part 1 gives a single removedir evenement/romeo-julia and an empty add queue, and part 2 fails 0 out of 50 times (both with and without the dash). Existing cache files are already in traversal order, so they don't need to change.

As extra hardening it might also make sense to treat ENOENT from unlinkSync in filesystem.js remove() as success, since the file being gone is the desired end state.

[girish]

Good catch. Was easy to create a test and fix.