Fix file provider issues with directory handling and performance - #10728
Fix file provider issues with directory handling and performance#10728juliusvaart wants to merge 13 commits into
Conversation
A folder created on the Mac is, from the framework's point of view, already fully enumerated: it knows the empty listing it just created and will not ask for the contents again. The refresh subscription a browsed folder gets must therefore be granted here too — `visitedDirectory` is what puts a directory into the materialised set the working-set scan reads, and `downloaded` is ignored for directories there. Without it a locally created folder is never PROPFINDed by the scan, so items added to it on the server (web UI, public upload link, another user) never surface, and no later `enumerateItems` exists to repair that. Resolves: nextcloud#9688 Signed-off-by: Julius van der Vaart <julius@vanderva.art>
Covers the path a notify_push or root-ETag signal actually drives: `enumerateChanges(.workingSet)` -> `scanMaterialisedItemsForRemoteChanges()` -> `pendingWorkingSetChanges(since:)` -> the change observer. Each test mutates the mock server and asserts the change reaches `MockChangeObserver`. Three reproduced real silent drops in the enumerator and database change derivation, and now guard them: the scan returning the changes it discovers rather than relying on the lossy syncTime reconstruction, recursion into changed subdirectories, and `size` participating in the change-detection predicate. Signed-off-by: Julius van der Vaart <julius@vanderva.art>
…writes `FileProviderLog.write` ran `attributesOfItem` and `handle.synchronize()` for every line, inside a single actor that `info`/`error`/`fault` always hop to. A burst of tens of thousands of lines therefore became that many serialized fsyncs, in front of every hot path in the extension. `write(contentsOf:)` is an unbuffered `write(2)`, so a line is in the file and readable without the fsync; it only added durability against power loss, which a diagnostic log does not need. Rotation still flushes, and a byte counter replaces the per-line stat. Batched `addItemMetadatas` / `removeItemMetadatas` are added alongside, and the delivered-deletion cleanup switched to the latter: it opened one write transaction per item, on the main actor. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
A pinned tree drove a self-sustaining storm of container updates that never converged. Four causes, all reachable from one investigation: - The materialized-set reconciliation marked *directories* dataless. A directory qualifies as materialized through `visitedDirectory`, which the reconciliation deliberately preserves, so clearing `downloaded` never removed it from the candidate set and it was re-evicted on every pass, forever. Measured on a font library: 630 directories, 30,117 transitions and 28,334 log lines in seven minutes, the per-pass count climbing as browsing marked more directories visited. Only files carry materialized content, so only files are reconciled. - `Item.rootContainer` synthesised its metadata on every call, taking `creationDate` and `date` from `Date()`. Every read of the root therefore returned new timestamps, the framework saw `diffs:lastUsedDate|btime|mtime` and re-queued the container's update-item job, which could never converge. Persisted values are merged instead, with a constant fallback. - `childItemCount` counted descendants rather than direct children, so a root with 14 children reported 17372, and Finder showed that number. It also counted tombstones, other accounts, and — for the root only — its own row. - `fetchContents` writes `downloaded = true` before the system adds the file to its materialized set, so the reconciliation flipped every fresh download back to dataless and the framework re-requested it. A short-lived registry holds each download until the system confirms it. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
Every completed download nudged each of its ancestors up to the root immediately. Files share ancestors, so materialising a pinned tree issued one `requestModification` per file per level, all landing on the same few containers: the root's update-item job was re-queued before it could finish, and macOS flagged the call rate as a harmful notification flood, climbing from 421 to 863 notifications per second over 90 seconds. Accumulating a short window's worth and draining one deduplicated ancestor set costs a few hundred milliseconds on the menu item and removes the amplification. Observed after: no notification-rate faults at all. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
Trashing rewrites an item's `serverUrl` to the trashbin but leaves `deleted` false, and a folder keeps `visitedDirectory`, so a trashed folder stayed in the materialised set and the scan PROPFINDed it through the ordinary DAV path. That 404s, and the scan reads a 404 as "the item is gone": it reported the item deleted and hard-removed the very row the trash reconciliation derives permanent deletions from. Trash has its own enumeration path via `listingTrashAsync`. The regression test fails on both counts without the fix — it observes the PROPFIND to /remote.php/dav/trashbin/... and the row's destruction. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
…stion The non-paginated ingestion path guards its writes with `isInSameDatabaseStoreableRemoteState`; the paginated one, which every enumeration takes on servers from Nextcloud 31, wrote every row of every listing unconditionally — one transaction and one `evictLogicalDuplicates` query each. One working-set scan rewrote 1,998 rows to surface 7 actual changes, against 5,858 evaluations that found no difference. Applying the same guard suppressed 99.7% of writes on the next run: 11 written, 3,655 skipped. `visitedDirectory` is compared explicitly because it is local-only and so absent from the remote-state comparison: a caller passing `preserveVisitedDirectory: false` is recording a visit and must always be written, or folders would fall out of the working set. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
…tree Pinning walks every descendant and asks the framework to download each one, but those calls address the framework's own item store, which only knows what enumeration has handed it. Every descendant the user has never browsed answers `noSuchItem`: 15,229 of 15,849 on one pinned tree, each logged as an error and together about half the log volume. Nothing is lost by skipping them — the database flag is written first, so `contentPolicy` reports `.downloadEagerlyAndKeepDownloaded` and the framework acts on it the moment it first enumerates the item. The signal only brings that forward for descendants already being tracked. Genuine failures still log as errors. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
The walk issued its PROPFINDs strictly sequentially — 669 reads of roughly 100ms each, 76 seconds of almost pure network waiting, to surface zero changes. Reads now go out six at a time, in waves grouped by remote-path depth. One measured scan went from 76s to 51s with the read count essentially unchanged (669 to 652), which is the check that matters: coverage held on live data. Depth is what makes concurrency safe. The only ordering the walk depends on is that a directory is read before the items it covers — a depth-1 read records its unchanged direct children in `scannedItemIds`, and those children are always exactly one level deeper. Processing shallowest-first preserves every coverage decision, while items within one depth can never cover one another. Results are reordered before merging, and the merge stays single-threaded, so the accumulators and deletion reconciliation evolve exactly as before. The added test pins the coverage rule, which the suite did not previously check: collapsing the waves makes it read three paths instead of one. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
A `notify_push` already identifies what changed within a second, but `processFileIdsChanged` used the ids only to ask whether *any* of them were locally known, threw them away, and signalled the whole working set. That turned a one-file change into a walk of every materialised item: one measured pass spent 305 seconds to surface a 31-byte file the push had named 1.5 seconds after it was created. The ids are now resolved to the containers worth re-reading — a changed directory to itself, a changed file to its parent, since a depth-1 read of the parent reveals a created, modified or removed child alike — and the working-set derivation reads just those. Measured after: 5 containers instead of 2566, a 17-second scan instead of 305, and a web-UI change visible in Finder in about six seconds. Only the seed of the walk narrows. The full materialised set still backs the descendant and coverage checks, and deletion reconciliation operates over what was actually read, so an item under a container this pass did not look at is never claimed as deleted. The periodic full scan is retained deliberately. Push drops messages across reconnects and only ever reports what did change, so targeting is an accelerator layered over the full walk, never a replacement: a full reconciliation runs whenever nothing is targeted, and is forced every ten minutes regardless. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
A full walk grows with the materialised set and used to report nothing until it finished: one document was discovered 15 seconds into a scan and reported 4m34s later, when the scan ended. The scan now hands each depth wave to the change buffer as it completes, and the first batch goes out while the walk continues. Measured after: first batch 1.3 seconds into a 160-second scan. Only scan-discovered creations and updates stream. Deletions cannot — an item absent from one directory may have moved into another the walk has not reached, which is only decidable once it has — so they and the database-derived half are appended at the end. Waves run shallowest-depth-first, so the streamed portion is already ordered parents-before-children without a global sort. A first attempt at this was reverted for silently dropping remote changes. The framework served an intermediate batch from a second `Enumerator` — the reason the session is persisted at all — and that instance, holding producer state in memory, saw no producer, reported `moreComing: false`, and both ended the sequence and deleted the session out from under the live scan. Since `moreComing: false` states that the client is synced, nothing was reported again. Producer liveness is therefore process-wide rather than per-buffer: the framework replaces enumerators, not the extension process. It is deliberately not persisted, so a new process correctly treats any earlier producer as gone — the session is drained and finished on its incoming anchor, and the next signal re-derives. A deadline covers a producer that hangs rather than exits; expiring one early costs a redundant re-derivation, never a lost change. The two-enumerator test was written before the implementation, because the original suite drove a single buffer instance — the one topology in which that bug cannot appear. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
…equests The system starts the extension process and begins asking it for work before the main app has handed the account across. `fetchContents` and `item(for:)` answered `notAuthenticated` outright, and the framework treated those downloads as failed: on one relaunch 17 fetches arrived in the first 0.6 seconds, 1.7 seconds before the account landed, and most were never re-requested. Both now wait for the account, which turns the race into a short delay because it almost always arrives moments later. A genuinely account-less domain still fails, just after the timeout. `createItem` / `modifyItem` / `deleteItem` are left alone — they are user-initiated, and nobody is editing files before the app has loaded — and `enumerator(for:)` self-heals through `signalEnumeratorAfterAccountSetup`. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
claucambra
left a comment
There was a problem hiding this comment.
Hi, thanks for the contribution! I glanced through the change set but did not see any performance tests or benchmarks included in the diffs, could you add the benchmarks that you ran for these changes so we can try to reproduce and verify the results? Thanks!
…estion work The figures quoted for these changes were taken from the extension's logs on one live account, which nobody else can reproduce. The mechanisms behind them are reproducible from a checkout, because they are counts rather than durations: how many PROPFINDs a working-set walk issues, how many rows a paginated enumeration rewrites, and how many reads overlap. `PerformanceBenchmarkTests` asserts each of those exactly, so a regression fails the suite instead of merely reading slower. Measured on an Apple silicon Mac against 34.0.3 and against this branch, same machine and invocation: | Benchmark | 34.0.3 | Branch | | -------------------------------------------------- | ------ | ------ | | Reads per full walk (30 directories, 180 files) | 30 | 30 | | Rows rewritten, unchanged 200-file enumeration | 201 | 0 | | Rows rewritten when one of those 200 files changed | 201 | 1 | | Peak overlapping reads during a full walk | 1 | 6 | | Full walk wall clock, 30 reads x 50 ms | 1.80 s | 0.31 s | | Reads to answer a push naming one container | n/a | 1 | The read-volume row is deliberately unchanged: the walk already read one directory at a time, and the benchmark exists to keep it that way. The push-targeted benchmark has no 34.0.3 counterpart because the code path does not exist there. Only one timing assertion is made, and it is a ceiling rather than a threshold: the walk must beat the time its reads would take issued one after another, which a sequential scan cannot do by construction. The durations it prints are for comparing revisions on one machine, not for asserting. `MockRemoteInterface` gains `enumerateLatency`, so a mocked read has a duration at all, and `maxConcurrentEnumerations`, so overlap is observable. Its operation counters move behind a lock at the same time: the working-set scan now issues its reads concurrently, so incrementing a shared `Int` was a race that under-counted exactly the tests that care about request volume. The write-volume benchmarks drive `readServerUrl` with explicit page settings rather than going through `enumerateItems`, whose pagination is gated on the server advertising major version 31 or later; the mock advertises 28. <doc:PerformanceBenchmarks> documents how to run these, how to compare two revisions, and how the live-account figures were gathered from the extension's own log lines. Signed-off-by: Julius van der Vaart <julius@vanderva.art> Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Assisted-by: Claude Code:claude-opus-5
|
I ran the tests based on the logs when using our server. Claude added tests, hope these are good enough. |
There was a problem hiding this comment.
@juliusvaart thanks for the contribution. As is, I don't think this PR is mergeable for us. Here are some changes we'd need to see:
- This PR is very big and does multiple different things. There are various different types of optimisations and changes that are unrelated to each other. Each class of change should ideally be self-contained and be benchmarked on its own. This way we can more easily verify what the impact of each change is
- The benchmark test is superficial. It only proves that a synthetic mock’s six artificial reads overlap, rather than reproducibly measuring the claimed end-to-end performance improvement against the unmodified baseline
- The before/after live-account figures are not reproducible from the branch. We need to have a consistent environment through which we can check that the improvements are as claimed, but in your case, this requires a specific account/machine
If you can look into these we would be happy to re-review. Thanks for spending the time on this!
|
Hi @claucambra, Thanks for the fast responses. I can split it in 8 requests:
Note 8 depends on 6. Should i keep this pull request open as a tracker for the new pull requests? |
If the changes overlap, I think it's best if this PR is closed. You can always mention this PR in the new ones or vice-versa |
Resolves
Resolved
#9688
Very likely resolved:
#10558
#9854
Possibly resolved:
#10334
#10560
Summary
Note: my first pull request here, was frustrated with the performance and bugs of the File Provider implementation. Created with a lotn of help from Claude Opus 5. Tested on our production Nextcloud with over 6TB data (Hetzner Storage Share NC 34.0.8, single server, macOS only).
Targeting stable-34.0 (created on tag 34.0.3).
Making the Virtual Files on MacOS (File Provider) workable. Upgrading performance/speed and fixing Nextcloud Push to start enumeration.
Streaming was implemented, shipped, found to drop remote changes, reverted, and redone with the test written.
Performance stats
Checklist
AI (if applicable)