From 099d73dde8ae4b08c582189e0c169a581117da9e Mon Sep 17 00:00:00 2001 From: Alan Wizemann Date: Tue, 5 May 2026 11:50:51 +0200 Subject: [PATCH] feat(scarfmon): instrument Nous model catalog + subscription path (beach-ball investigation) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit User reported a remote-context beach-ball when opening the model picker with Nous as the active provider. Existing measure points showed loadProviders + loadModels at ~315ms each (fast). The beach-ball must be in the uninstrumented Nous-overlay branch the picker fires when nous is selected. Adds four measure points covering every blocking call in that path: - nous.subscription.loadState (interval, .diskIO) — auth.json read via NousSubscriptionService.loadState. Already known to do an SSH read; now precisely measurable. - nous.readCache (interval, .diskIO) — nous_models cache read, TWO sequential SSH ops (fileExists + readFile). - nous.bearerToken (interval, .diskIO) — auth.json read AGAIN inside fetchModels. **This is a duplicate read** — loadState already parsed the same file moments earlier. Comment-flagged as a caching candidate. - nous.fetchModels (interval, .transport) + .bytes (event) — HTTP GET against the Nous /v1/models endpoint with the body byte count attached. The most likely beach-ball culprit if the endpoint is slow or hung. After the next capture we'll know which of the four owns the user's wall-clock; if `nous.bearerToken` shows up alongside `nous.subscription.loadState` with similar duration, the duplicate read is also a real cost worth fixing. Co-Authored-By: Claude Opus 4.7 (1M context) --- .../Services/NousModelCatalogService.swift | 90 +++++++++++-------- .../Services/NousSubscriptionService.swift | 50 ++++++----- 2 files changed, 77 insertions(+), 63 deletions(-) diff --git a/scarf/Packages/ScarfCore/Sources/ScarfCore/Services/NousModelCatalogService.swift b/scarf/Packages/ScarfCore/Sources/ScarfCore/Services/NousModelCatalogService.swift index fe42959..2913bc0 100644 --- a/scarf/Packages/ScarfCore/Sources/ScarfCore/Services/NousModelCatalogService.swift +++ b/scarf/Packages/ScarfCore/Sources/ScarfCore/Services/NousModelCatalogService.swift @@ -96,21 +96,23 @@ public struct NousModelCatalogService: Sendable { /// malformed cache → nil; the loader treats that as "no cache" and /// kicks off a fresh fetch. public func readCache() -> NousModelsCache? { - let transport = context.makeTransport() - guard transport.fileExists(cachePath) else { return nil } - do { - let data = try transport.readFile(cachePath) - let decoder = JSONDecoder() - decoder.dateDecodingStrategy = .iso8601 - let cache = try decoder.decode(NousModelsCache.self, from: data) - guard cache.version == NousModelsCache.currentVersion else { - Self.logger.info("nous models cache schema mismatch (got v\(cache.version), expected v\(NousModelsCache.currentVersion)); ignoring") + ScarfMon.measure(.diskIO, "nous.readCache") { + let transport = context.makeTransport() + guard transport.fileExists(cachePath) else { return nil } + do { + let data = try transport.readFile(cachePath) + let decoder = JSONDecoder() + decoder.dateDecodingStrategy = .iso8601 + let cache = try decoder.decode(NousModelsCache.self, from: data) + guard cache.version == NousModelsCache.currentVersion else { + Self.logger.info("nous models cache schema mismatch (got v\(cache.version), expected v\(NousModelsCache.currentVersion)); ignoring") + return nil + } + return cache + } catch { + Self.logger.warning("couldn't decode nous models cache: \(error.localizedDescription, privacy: .public)") return nil } - return cache - } catch { - Self.logger.warning("couldn't decode nous models cache: \(error.localizedDescription, privacy: .public)") - return nil } } @@ -148,15 +150,22 @@ public struct NousModelCatalogService: Sendable { // The subscription service already checks for `present`; we // re-read the raw token here because we need the actual string, // not just a Bool. Mirrors the SubscriptionService parse path. - let transport = context.makeTransport() - guard transport.fileExists(context.paths.authJSON) else { return nil } - guard let data = try? transport.readFile(context.paths.authJSON) else { return nil } - guard let root = try? JSONSerialization.jsonObject(with: data) as? [String: Any] else { return nil } - let providers = root["providers"] as? [String: Any] ?? [:] - let nous = providers["nous"] as? [String: Any] - let token = nous?["access_token"] as? String - guard let token, !token.isEmpty else { return nil } - return token + // ScarfMon: separate `nous.bearerToken` measure point because + // this is the second auth.json read of the picker's open + // sequence (subscriptionService.loadState() did the first). + // Together with `nous.subscription.loadState`, total two SSH + // round-trips of the same file — candidate for caching. + ScarfMon.measure(.diskIO, "nous.bearerToken") { + let transport = context.makeTransport() + guard transport.fileExists(context.paths.authJSON) else { return nil } + guard let data = try? transport.readFile(context.paths.authJSON) else { return nil } + guard let root = try? JSONSerialization.jsonObject(with: data) as? [String: Any] else { return nil } + let providers = root["providers"] as? [String: Any] ?? [:] + let nous = providers["nous"] as? [String: Any] + let token = nous?["access_token"] as? String + guard let token, !token.isEmpty else { return nil } + return token + } } /// Make the API call. Times out after `requestTimeout` so a hung @@ -164,25 +173,28 @@ public struct NousModelCatalogService: Sendable { /// `[NousModel]` on success, throws on any HTTP / decode error so /// the caller can log + fall back. public func fetchModels() async throws -> [NousModel] { - guard let token = bearerToken() else { - throw NousModelCatalogError.notAuthenticated - } - var request = URLRequest(url: Self.baseURL) - request.httpMethod = "GET" - request.timeoutInterval = Self.requestTimeout - request.setValue("Bearer \(token)", forHTTPHeaderField: "Authorization") - request.setValue("application/json", forHTTPHeaderField: "Accept") + try await ScarfMon.measureAsync(.transport, "nous.fetchModels") { + guard let token = bearerToken() else { + throw NousModelCatalogError.notAuthenticated + } + var request = URLRequest(url: Self.baseURL) + request.httpMethod = "GET" + request.timeoutInterval = Self.requestTimeout + request.setValue("Bearer \(token)", forHTTPHeaderField: "Authorization") + request.setValue("application/json", forHTTPHeaderField: "Accept") - let (data, response) = try await session.data(for: request) - guard let http = response as? HTTPURLResponse else { - throw NousModelCatalogError.transport("non-HTTP response") + let (data, response) = try await session.data(for: request) + guard let http = response as? HTTPURLResponse else { + throw NousModelCatalogError.transport("non-HTTP response") + } + guard (200..<300).contains(http.statusCode) else { + throw NousModelCatalogError.http(status: http.statusCode) + } + struct Envelope: Decodable { let data: [NousModel] } + let envelope = try JSONDecoder().decode(Envelope.self, from: data) + ScarfMon.event(.transport, "nous.fetchModels.bytes", count: envelope.data.count, bytes: data.count) + return envelope.data } - guard (200..<300).contains(http.statusCode) else { - throw NousModelCatalogError.http(status: http.statusCode) - } - struct Envelope: Decodable { let data: [NousModel] } - let envelope = try JSONDecoder().decode(Envelope.self, from: data) - return envelope.data } // MARK: - Public entry diff --git a/scarf/scarf/Core/Services/NousSubscriptionService.swift b/scarf/scarf/Core/Services/NousSubscriptionService.swift index e7812a3..8666b1f 100644 --- a/scarf/scarf/Core/Services/NousSubscriptionService.swift +++ b/scarf/scarf/Core/Services/NousSubscriptionService.swift @@ -82,30 +82,32 @@ struct NousSubscriptionService: Sendable { /// on any read or parse failure — callers treat "absent" and "can't /// read" the same in UI (show a "not subscribed" CTA). nonisolated func loadState() -> NousSubscriptionState { - guard let data = try? transport.readFile(authJSONPath) else { - return .absent + ScarfMon.measure(.diskIO, "nous.subscription.loadState") { + guard let data = try? transport.readFile(authJSONPath) else { + return .absent + } + guard let root = try? JSONSerialization.jsonObject(with: data) as? [String: Any] else { + logger.warning("auth.json is not a JSON object; assuming no Nous subscription") + return .absent + } + let providers = root["providers"] as? [String: Any] ?? [:] + let nous = providers["nous"] as? [String: Any] + let token = nous?["access_token"] as? String + let present = (token?.isEmpty == false) + + let activeProvider = root["active_provider"] as? String + let providerIsNous = (activeProvider == "nous") + + let updatedAt: Date? = { + guard let raw = root["updated_at"] as? String else { return nil } + return ISO8601DateFormatter().date(from: raw) + }() + + return NousSubscriptionState( + present: present, + providerIsNous: providerIsNous, + updatedAt: updatedAt + ) } - guard let root = try? JSONSerialization.jsonObject(with: data) as? [String: Any] else { - logger.warning("auth.json is not a JSON object; assuming no Nous subscription") - return .absent - } - let providers = root["providers"] as? [String: Any] ?? [:] - let nous = providers["nous"] as? [String: Any] - let token = nous?["access_token"] as? String - let present = (token?.isEmpty == false) - - let activeProvider = root["active_provider"] as? String - let providerIsNous = (activeProvider == "nous") - - let updatedAt: Date? = { - guard let raw = root["updated_at"] as? String else { return nil } - return ISO8601DateFormatter().date(from: raw) - }() - - return NousSubscriptionState( - present: present, - providerIsNous: providerIsNous, - updatedAt: updatedAt - ) } }