Merge pull request #10466 from nextcloud/i2h3/fix/on2-enumeration-problem

Eliminate O(N²) Realm work in large-folder enumeration

Author: i2h3

shell_integration/MacOSX/NextcloudFileProviderKit/Sources/NextcloudFileProviderKit/Database/FilesDatabaseManager.swift

@@ -31,7 +31,7 @@ public final class FilesDatabaseManager: Sendable {
         )
     }
 
-    private static let schemaVersion = SchemaVersion.addedCanonicalPathKeysToRealmItemMetadata
+    private static let schemaVersion = SchemaVersion.addedNormalizedFileNameIndexToRealmItemMetadata
     let logger: FileProviderLogger
     let account: Account
 
@@ -269,14 +269,18 @@ public final class FilesDatabaseManager: Sendable {
         existingMetadatas: Results<RealmItemMetadata>,
         updatedMetadatas: [SendableItemMetadata]
     ) -> [RealmItemMetadata] {
+        // O(1) membership test instead of a per-existing linear scan of `updatedMetadatas`. The previous
+        // `updatedMetadatas.contains(where:)` made this loop O(existing × updated) — with the linear scan
+        // in `processItemMetadatasToUpdate` it was the dominant cost of a large non-paginated depth-1
+        // write (measured ≈19 min, never completing, for a 6982-item flat folder; no index can fix an
+        // in-memory scan). `existingMetadata` is already the managed row from the caller's `database`
+        // handle and is value-copied before the write, so it is used directly — this also removes the
+        // per-item `itemMetadatas` (`ncDatabase()`) re-open the old `.where{}.first` fetch incurred.
+        let updatedOcIds = Set(updatedMetadatas.map(\.ocId))
         var deletedMetadatas: [RealmItemMetadata] = []
 
-        for existingMetadata in existingMetadatas {
-            guard !updatedMetadatas.contains(where: { $0.ocId == existingMetadata.ocId }),
-                  let metadataToDelete = itemMetadatas.where({ $0.ocId == existingMetadata.ocId }).first
-            else { continue }
-
-            deletedMetadatas.append(metadataToDelete)
+        for existingMetadata in existingMetadatas where !updatedOcIds.contains(existingMetadata.ocId) {
+            deletedMetadatas.append(existingMetadata)
 
             logger.debug("Deleting item metadata during update.", [.item: existingMetadata.ocId])
         }
@@ -289,8 +293,22 @@ public final class FilesDatabaseManager: Sendable {
         var returningUpdatedMetadatas: [SendableItemMetadata] = []
         var directoriesNeedingRename: [SendableItemMetadata] = []
 
+        // O(1) ocId lookup instead of `existingMetadatas.first(where:)` — the old per-item linear scan of
+        // a Realm `Results` was O(updated × existing), the other half of the measured O(N²) large-folder
+        // write. Keyed once up front (first occurrence wins, matching `.first(where:)`).
+        var existingByOcId: [String: RealmItemMetadata] = [:]
+        existingByOcId.reserveCapacity(existingMetadatas.count)
+        for existingMetadata in existingMetadatas where existingByOcId[existingMetadata.ocId] == nil {
+            existingByOcId[existingMetadata.ocId] = existingMetadata
+        }
+
+        // `inheritedKeepDownloaded` depends on the item only through (account, parent serverUrl); every
+        // child of a folder shares one serverUrl, so cache per serverUrl to collapse N parent lookups
+        // (each a DB query) to one per distinct parent.
+        var inheritedKeepDownloadedByServerUrl: [String: Bool] = [:]
+
         for var updatedMetadata in updatedMetadatas {
-            if let existingMetadata = existingMetadatas.first(where: { $0.ocId == updatedMetadata.ocId }) {
+            if let existingMetadata = existingByOcId[updatedMetadata.ocId] {
                 if existingMetadata.status == Status.normal.rawValue, !existingMetadata.isInSameDatabaseStoreableRemoteState(updatedMetadata) {
                     let pathChanged = !updatedMetadata.hasSameLocation(as: existingMetadata)
 
@@ -325,7 +343,13 @@ public final class FilesDatabaseManager: Sendable {
 
             } else { // This is a new metadata
                 // Inherit the parent's "Always keep downloaded" flag so a file surfacing here via remote enumeration acquires the same pin as its already-pinned siblings (#10054).
-                updatedMetadata.keepDownloaded = inheritedKeepDownloaded(for: updatedMetadata)
+                if let cached = inheritedKeepDownloadedByServerUrl[updatedMetadata.serverUrl] {
+                    updatedMetadata.keepDownloaded = cached
+                } else {
+                    let inherited = inheritedKeepDownloaded(for: updatedMetadata)
+                    inheritedKeepDownloadedByServerUrl[updatedMetadata.serverUrl] = inherited
+                    updatedMetadata.keepDownloaded = inherited
+                }
 
                 returningNewMetadatas.append(updatedMetadata)
 

shell_integration/MacOSX/NextcloudFileProviderKit/Sources/NextcloudFileProviderKit/Database/SchemaVersion.swift

@@ -10,4 +10,5 @@ enum SchemaVersion: UInt64 {
     case addedLockTokenPropertyToRealmItemMetadata = 201
     case addedIsLockFileOfLocalOriginToRealmItemMetadata = 202
     case addedCanonicalPathKeysToRealmItemMetadata = 203
+    case addedNormalizedFileNameIndexToRealmItemMetadata = 204
 }

shell_integration/MacOSX/NextcloudFileProviderKit/Sources/NextcloudFileProviderKit/Enumeration/Enumerator+ItemEnumeration.swift

@@ -67,6 +67,21 @@ extension Enumerator {
         logger.debug("Enumerating page: \(String(data: page.rawValue, encoding: .utf8) ?? "")", [.account: account.ncKitAccount, .url: serverUrl])
 
         Task {
+            // Bound the synchronous page work (cursor decode + capabilities + network + convert +
+            // persist) for a trace, and record its wall-clock for the JSONL fallback. The `defer` ends
+            // the interval on every exit — including the error returns below — so no interval dangles.
+            // The trailing observer conversion/report runs in a detached Task and is captured by the
+            // separate `ToFileProviderItems` / `ObserverReport` signposts.
+            let signposter = EnumerationSignposter.signposter
+            let pageWorkState = signposter.beginInterval(
+                "EnumeratePageWork",
+                id: signposter.makeSignpostID(),
+                "serverUrl=\(self.serverUrl, privacy: .public)"
+            )
+            defer { signposter.endInterval("EnumeratePageWork", pageWorkState) }
+            let pageWorkClock = ContinuousClock()
+            let pageWorkStart = pageWorkClock.now
+
             let cursor = paginationCursor(from: page)
 
             // Check server version to determine if pagination should be enabled.
@@ -149,6 +164,12 @@ extension Enumerator {
                 rawNextPage = nil
             }
 
+            let pageWorkElapsed = pageWorkClock.now - pageWorkStart
+            logger.performance(
+                "PERF EnumeratePageWork items=\(items.count) page_work_s=\(pageWorkElapsed.fpSeconds) hasNextPage=\(rawNextPage != nil)",
+                [.url: self.serverUrl]
+            )
+
             completeEnumerationObserver(observer, nextPage: rawNextPage, itemMetadatas: items)
         }
     }

shell_integration/MacOSX/NextcloudFileProviderKit/Sources/NextcloudFileProviderKit/Enumeration/Enumerator+ObserverReporting.swift

@@ -24,17 +24,30 @@ extension Enumerator {
         handleInvalidParent: Bool = true
     ) {
         Task {
+            let signposter = EnumerationSignposter.signposter
+            let toItemsState = signposter.beginInterval(
+                "ToFileProviderItems",
+                id: signposter.makeSignpostID(),
+                "count=\(itemMetadatas.count)"
+            )
             do {
                 let items = try await itemMetadatas.toFileProviderItems(
                     account: account, remoteInterface: remoteInterface, dbManager: dbManager, log: self.logger.log
                 )
+                signposter.endInterval("ToFileProviderItems", toItemsState)
 
                 Task { @MainActor in
+                    // Begin/end stay in this MainActor scope; both observer calls are synchronous.
+                    let reportState = signposter.beginInterval(
+                        "ObserverReport", id: signposter.makeSignpostID(), "items=\(items.count)"
+                    )
                     observer.didEnumerate(items)
                     logger.info("Did enumerate \(items.count) items. Next page is nil: \(nextPage == nil)")
                     observer.finishEnumerating(upTo: nextPage)
+                    signposter.endInterval("ObserverReport", reportState)
                 }
             } catch let error as NSError { // This error can only mean a missing parent item identifier
+                signposter.endInterval("ToFileProviderItems", toItemsState)
                 guard handleInvalidParent else {
                     logger.info("Not handling invalid parent in enumeration.")
                     observer.finishEnumeratingWithError(error)

shell_integration/MacOSX/NextcloudFileProviderKit/Sources/NextcloudFileProviderKit/Enumeration/Enumerator+SyncEngine.swift

@@ -6,7 +6,7 @@ import NextcloudKit
 
 extension Enumerator {
     static func handlePagedReadResults(
-        files: [NKFile], pageIndex: Int, dbManager: FilesDatabaseManager
+        files: [NKFile], pageIndex: Int, dbManager: FilesDatabaseManager, log: any FileProviderLogging
     ) -> (metadatas: [SendableItemMetadata]?, error: NKError?) {
         // First PROPFIND contains the target item, but we do not want to report this in the
         // retrieved metadatas (the enumeration observers don't expect you to enumerate the
@@ -40,10 +40,44 @@ extension Enumerator {
         // `keepDownloaded == false` for items that are pinned in the
         // database, leaving the OS view (`isKeepDownloaded`, `contentPolicy`)
         // out of sync with the local truth.
-        let metadatas = files[startIndex...].map { file -> SendableItemMetadata in
-            dbManager.addItemMetadataPreservingLocalState(file.toItemMetadata())
+        //
+        // Conversion and persistence are timed separately (convAccum / dbAccum) so the JSONL PERF
+        // line splits CPU spent building metadata from CPU spent in Realm. Today each item opens its
+        // own write transaction inside `addItemMetadataPreservingLocalState`; `db_items_per_s` is the
+        // throughput number to watch, and the enclosing `ConvertAndPersistPage` signpost bounds the
+        // whole page for Instruments. (Phase 2 batches these into one transaction per page.)
+        let signposter = EnumerationSignposter.signposter
+        let convAndPersistState = signposter.beginInterval(
+            "ConvertAndPersistPage",
+            id: signposter.makeSignpostID(),
+            "pageIndex=\(pageIndex) files=\(files.count)"
+        )
+
+        let clock = ContinuousClock()
+        var convAccum: Duration = .zero
+        var dbAccum: Duration = .zero
+        var metadatas: [SendableItemMetadata] = []
+        metadatas.reserveCapacity(max(0, files.count - startIndex))
+
+        for file in files[startIndex...] {
+            let convStart = clock.now
+            let itemMetadata = file.toItemMetadata()
+            convAccum += clock.now - convStart
+
+            let dbStart = clock.now
+            metadatas.append(dbManager.addItemMetadataPreservingLocalState(itemMetadata))
+            dbAccum += clock.now - dbStart
         }
 
+        signposter.endInterval("ConvertAndPersistPage", convAndPersistState, "items=\(metadatas.count)")
+
+        let itemCount = metadatas.count
+        let dbSeconds = dbAccum.fpSeconds
+        let dbRate = dbSeconds > 0 ? Double(itemCount) / dbSeconds : 0
+        FileProviderLogger(category: "Enumerator", log: log).performance(
+            "PERF ConvertAndPersistPage pageIndex=\(pageIndex) items=\(itemCount) conv_s=\(convAccum.fpSeconds) db_s=\(dbSeconds) db_items_per_s=\(dbRate)"
+        )
+
         return (metadatas, nil)
     }
 
@@ -68,11 +102,23 @@ extension Enumerator {
 
         if let pageIndex {
             let (metadatas, error) =
-                handlePagedReadResults(files: files, pageIndex: pageIndex, dbManager: dbManager)
+                handlePagedReadResults(files: files, pageIndex: pageIndex, dbManager: dbManager, log: log)
             return (metadatas, nil, error)
         }
 
-        guard var (directory, _, files) = await files.toSendableDirectoryMetadata(account: account, directoryToRead: serverUrl) else {
+        // Non-paginated path (older servers / change enumeration): conversion is parallelized and the
+        // persist is a single batched transaction. Signpost each so its cost is comparable, in a trace,
+        // against the paginated path's per-item behavior.
+        let signposter = EnumerationSignposter.signposter
+        let convDirState = signposter.beginInterval(
+            "ConvertDirectoryMetadata",
+            id: signposter.makeSignpostID(),
+            "serverUrl=\(serverUrl, privacy: .public) files=\(files.count)"
+        )
+        let convertedDirectory = await files.toSendableDirectoryMetadata(account: account, directoryToRead: serverUrl)
+        signposter.endInterval("ConvertDirectoryMetadata", convDirState)
+
+        guard var (directory, _, files) = convertedDirectory else {
             logger.error("Failed to convert array of NKFile to directory and files metadata objects!")
             return (nil, nil, .invalidData)
         }
@@ -92,12 +138,31 @@ extension Enumerator {
 
         files.insert(directory, at: 0)
 
+        let batchClock = ContinuousClock()
+        let batchStart = batchClock.now
+        let batchWriteState = signposter.beginInterval(
+            "Depth1BatchWrite",
+            id: signposter.makeSignpostID(),
+            "serverUrl=\(serverUrl, privacy: .public) items=\(files.count)"
+        )
         let changes = dbManager.depth1ReadUpdateItemMetadatas(
             account: account.ncKitAccount,
             serverUrl: serverUrl,
             updatedMetadatas: files,
             keepExistingDownloadState: true
         )
+        signposter.endInterval("Depth1BatchWrite", batchWriteState)
+
+        // The non-paginated depth-1 write (change / working-set full-folder re-read) is the measured
+        // enumeration bottleneck: its per-item logical-dedup scans are O(N²) over a flat folder. Log its
+        // wall-clock + items/sec so the effect of the normalizedFileName index is visible in the JSONL
+        // (the `Depth1BatchWrite` signpost shows the same in Instruments).
+        let batchElapsed = batchClock.now - batchStart
+        let batchRate = batchElapsed.fpSeconds > 0 ? Double(files.count) / batchElapsed.fpSeconds : 0
+        logger.performance(
+            "PERF Depth1BatchWrite items=\(files.count) write_s=\(batchElapsed.fpSeconds) items_per_s=\(batchRate)",
+            [.url: serverUrl]
+        )
 
         return (files, changes, nil)
     }
@@ -140,6 +205,21 @@ extension Enumerator {
             .init()
         }
 
+        // Signpost + wall-clock the network read in isolation so a trace (or the JSONL PERF line) can
+        // attribute enumeration latency to the paginated PROPFIND (server-bound) versus the local
+        // conversion + Realm persistence (CPU-bound). begin/end stay in this one function scope so the
+        // non-Sendable interval state never crosses the `await`'s potential thread hop.
+        let pageIndexForLog = pageSettings?.index ?? 0
+        let signposter = EnumerationSignposter.signposter
+        let propfindSignpostID = signposter.makeSignpostID()
+        let propfindState = signposter.beginInterval(
+            "PROPFIND",
+            id: propfindSignpostID,
+            "serverUrl=\(serverUrl, privacy: .public) index=\(pageIndexForLog) depth=\(depth.rawValue, privacy: .public)"
+        )
+        let networkClock = ContinuousClock()
+        let networkStart = networkClock.now
+
         let (_, files, data, error) = await remoteInterface.enumerate(
             remotePath: serverUrl,
             depth: depth,
@@ -159,6 +239,13 @@ extension Enumerator {
             }
         )
 
+        let networkElapsed = networkClock.now - networkStart
+        signposter.endInterval("PROPFIND", propfindState, "files=\(files.count)")
+        logger.performance(
+            "PERF PROPFIND index=\(pageIndexForLog) net_s=\(networkElapsed.fpSeconds) files=\(files.count) depth=\(depth.rawValue)",
+            [.url: serverUrl]
+        )
+
         guard error == .success else {
             logger.error("Read of URL did fail.", [.error: error, .url: serverUrl])
             return RemoteReadResult(error: error)
@@ -259,7 +346,7 @@ extension Enumerator {
             )
         } else if let pageIndex = pageSettings?.index {
             let (metadatas, error) = handlePagedReadResults(
-                files: files, pageIndex: pageIndex, dbManager: dbManager
+                files: files, pageIndex: pageIndex, dbManager: dbManager, log: log
             )
             return RemoteReadResult(metadatas: metadatas, nextPage: nextPage, error: error)
         } else {

shell_integration/MacOSX/NextcloudFileProviderKit/Sources/NextcloudFileProviderKit/Log/EnumerationSignposter.swift

@@ -0,0 +1,43 @@
+//  SPDX-FileCopyrightText: 2026 Nextcloud GmbH and Nextcloud contributors
+//  SPDX-License-Identifier: LGPL-3.0-or-later
+
+import Foundation
+import os
+
+///
+/// Process-global `OSSignposter` for the enumeration hot path.
+///
+/// The enumeration + persistence work runs across `static func`s that receive no `self`, so a
+/// shared signposter is the least invasive way to instrument them without threading a handle
+/// through every signature. `OSSignposter` (and the `OSSignpostID`s it vends) are `Sendable`, so a
+/// global `let` is safe under Swift 6 strict concurrency and usable from any isolation domain.
+///
+/// The subsystem mirrors ``FileProviderLogger`` (the extension bundle identifier) so signposts and
+/// log messages share the same subsystem in Instruments and `log stream`. The `"PointsOfInterest"`
+/// category makes intervals appear in the built-in *Points of Interest* instrument with no extra
+/// configuration.
+///
+/// Signposts are near-zero cost when no Instruments trace (or `log stream --signpost`) is attached:
+/// `signposter.signpostsEnabled` is `false` and the interval calls become cheap branches, and the
+/// message interpolations are only evaluated when a consumer is present. They are therefore safe to
+/// ship enabled — no `#if DEBUG` gate.
+///
+enum EnumerationSignposter {
+    static let signposter = OSSignposter(
+        subsystem: Bundle.main.bundleIdentifier ?? "",
+        category: "PointsOfInterest"
+    )
+}
+
+extension Duration {
+    ///
+    /// This duration expressed as fractional seconds, for human-readable performance logging.
+    ///
+    /// `components` yields whole seconds plus attoseconds; recombine them into a `Double`. Precision
+    /// loss at the attosecond scale is irrelevant for wall-clock timings measured in milliseconds.
+    ///
+    var fpSeconds: Double {
+        let parts = components
+        return Double(parts.seconds) + Double(parts.attoseconds) / 1e18
+    }
+}

shell_integration/MacOSX/NextcloudFileProviderKit/Sources/NextcloudFileProviderKit/Log/FileProviderLog.swift

@@ -100,6 +100,18 @@ public actor FileProviderLog: FileProviderLogging {
     ///
     nonisolated(unsafe) var debugLoggingObservation: NSKeyValueObservation?
 
+    ///
+    /// Whether performance-timing messages are written; see ``FileProviderLogging/performanceLoggingEnabled``.
+    ///
+    /// Read live from `UserDefaults.standard` (key `"performanceLoggingEnabled"`) on each access rather than cached
+    /// via KVO like ``debugLoggingEnabled``: performance lines are emitted at most a couple of times per enumerated
+    /// page, so a live read is cheap and picks up `defaults write` immediately without any observation machinery.
+    /// Defaults to `false` when the key is unset or not a boolean, in both DEBUG and release builds.
+    ///
+    public var performanceLoggingEnabled: Bool {
+        (UserDefaults.standard.object(forKey: "performanceLoggingEnabled") as? NSNumber)?.boolValue ?? false
+    }
+
     ///
     /// Initialize a new log file abstraction.
     ///