feat(zero-swift): inspector, query metrics, and slowMaterializeThreshold

.changeset/zero-swift-inspector.md

@@ -0,0 +1,5 @@
+---
+'zero-swift': patch
+---
+
+Add JS's inspector and query metrics. `zero.inspector` lists the client's and its group's queries on the server, with their client and server timings and ZQL, reads the clients the local store knows and their local data, reports the client's query metrics merged with the server's, shows zero-cache's version, and analyzes a query, a server AST, or a named query on the server. Where JS asks for zero-cache's admin password in a dialog, a request throws `InspectorError.authenticationRequired`: call `zero.inspector.authenticate(password:)` first, and the password it accepts is presented again after a reconnect. The client records JS's query metrics (`query-materialization-client`, `query-materialization-end-to-end`, `query-update-client`) in a `TDigest` that gives the same quantiles as JS's, and `ZeroOptions.slowMaterializeThreshold` (5 seconds by default) logs a warning for a query that takes longer to materialize, server and network included.

swift/Sources/Zero/AST/ASTToZQL.swift

@@ -0,0 +1,219 @@
+/// The query builder code of an AST after its table, such as
+/// `.where('id', '=', 123)` (`astToZQL` in `packages/ast-to-zql/src/ast-to-zql.ts`,
+/// without `redactLiterals`). The code is JS's, as the JS inspector shows it.
+func astToZQL(_ ast: AST) -> String {
+  var code = ""
+  if let condition = ast.where {
+    var args = Set<String>()
+    code += zqlCondition(condition, where: true, &args)
+  }
+  for related in ast.related ?? [] {
+    if related.hidden == true {
+      if let nested = related.subquery.related?.first { code += zqlRelated(nested) }
+    } else {
+      code += zqlRelated(related)
+    }
+  }
+  // distinct and groupBy go before orderBy, which then orders their rows.
+  if let groupBy = ast.groupBy {
+    let columns = groupBy.map(jsStringLiteral).joined(separator: ", ")
+    if let aggregate = ast.aggregate {
+      code += ".groupBy(\(columns)).\(aggregate.fn.rawValue)(\(zqlAggregateArg(aggregate)))"
+    } else {
+      code += ".distinct(\(columns))"
+    }
+  } else if let distinct = ast.aggregate?.distinct {
+    code += ".distinct(\(distinct.map(jsStringLiteral).joined(separator: ", ")))"
+  }
+  if let orderBy = ast.orderBy, !orderBy.isEmpty {
+    for part in orderBy { code += ".orderBy('\(part.field)', '\(part.direction.rawValue)')" }
+  }
+  if let limit = ast.limit { code += ".limit(\(JSNumber.format(limit)))" }
+  if let start = ast.start {
+    code +=
+      ".start(\(JSONSerializer.stringify(.object(start.row)))"
+      + (start.exclusive ? "" : ", { inclusive: true }") + ")"
+  }
+  // A count of the distinct values ends the chain.
+  if ast.aggregate?.distinct != nil { code += ".count()" }
+  return code
+}
+
+/// Whether a subquery has more than a table: JS tests these properties'
+/// truthiness, so an empty ordering counts and a limit of 0 doesn't.
+private func hasSubqueryProps(_ ast: AST) -> Bool {
+  ast.where != nil || !(ast.related ?? []).isEmpty || ast.orderBy != nil
+    || (ast.limit.map { $0 != 0 && !$0.isNaN } ?? false)
+}
+
+/// `wrap`: `code`, a builder-callback expression, at the top level of a
+/// `.where` (a callback of its own) or inside a callback (its names join the
+/// enclosing callback's).
+private func zqlWrap(
+  _ isWhere: Bool, _ args: inout Set<String>, _ needed: [String], _ code: String
+) -> String {
+  if isWhere {
+    let names = Set(needed).sorted(by: StringCompare.utf16Less).joined(separator: ", ")
+    return ".where(({\(names)}) => \(code))"
+  }
+  args.formUnion(needed)
+  return code
+}
+
+private func zqlCondition(
+  _ condition: AST.Condition, where isWhere: Bool, _ args: inout Set<String>
+) -> String {
+  let prefix = isWhere ? ".where" : "cmp"
+  switch condition {
+  case .simple(let op, let left, let right):
+    let leftCode = zqlValue(left)
+    let rightCode = zqlValue(right)
+    let argsCode =
+      op == .eq ? "\(leftCode), \(rightCode)" : "\(leftCode), '\(op.rawValue)', \(rightCode)"
+    if case .json = left {
+      // A JSON path operand only exists through the expression builder's `json()`.
+      return zqlWrap(isWhere, &args, ["cmp", "json"], "cmp(\(argsCode))")
+    }
+    return "\(prefix)(\(argsCode))"
+  case .and(let conditions), .or(let conditions):
+    let type = condition.isAnd ? "and" : "or"
+    if conditions.count == 1 { return zqlCondition(conditions[0], where: isWhere, &args) }
+    if condition.isAnd {
+      let parts = conditions.map { zqlCondition($0, where: isWhere, &args) }
+      if isWhere { return parts.joined() }
+      args.insert("and")
+      return "and(" + parts.joined(separator: ", ") + ")"
+    }
+    // An OR gets a callback: of its own at the top level, the enclosing one
+    // inside a callback.
+    var own = Set<String>()
+    let code: String
+    if isWhere {
+      code = conditions.map { zqlCondition($0, where: false, &own) }.joined(separator: ", ")
+    } else {
+      code = conditions.map { zqlCondition($0, where: false, &args) }.joined(separator: ", ")
+      own = args
+    }
+    return zqlWrap(isWhere, &args, Array(own) + ["cmp", type], "\(type)(\(code))")
+  case .correlatedSubquery(let related, let op, let flip, let scalar):
+    let relationship = zqlRelationshipName(related)
+    let next = nextExistsSubquery(related)
+    let props = hasSubqueryProps(next)
+    var options: [String] = []
+    if let flip { options.append("flip: \(flip)") }
+    if let scalar { options.append("scalar: \(scalar)") }
+    let optionsCode = options.isEmpty ? "" : ", {\(options.joined(separator: ", "))}"
+    let subquery = props ? ", q => q\(astToZQL(next))" : ""
+    switch op {
+    case .exists:
+      if isWhere { return ".whereExists('\(relationship)'\(subquery)\(optionsCode))" }
+      args.insert("exists")
+      return "exists('\(relationship)'\(subquery)\(optionsCode))"
+    case .notExists:
+      return zqlWrap(
+        isWhere, &args, ["exists", "not"],
+        "not(exists('\(relationship)'\(subquery)\(optionsCode)))")
+    }
+  }
+}
+
+extension AST.Condition {
+  fileprivate var isAnd: Bool {
+    if case .and = self { return true }
+    return false
+  }
+}
+
+/// `getNextExistsSubquery`: an `exists` over a junction edge has both hops
+/// as exists conditions with the same alias; the code names the far one.
+private func nextExistsSubquery(_ related: AST.CorrelatedSubquery) -> AST {
+  if case .correlatedSubquery(let inner, _, _, _)? = related.subquery.where,
+    inner.subquery.alias?.contains(subqueryAliasPrefix + "zhidden_") == true
+  {
+    return nextExistsSubquery(inner)
+  }
+  return related.subquery
+}
+
+private func zqlRelationshipName(_ related: AST.CorrelatedSubquery) -> String {
+  let alias = related.subquery.alias ?? ""
+  return alias.hasPrefix(subqueryAliasPrefix)
+    ? String(alias.dropFirst(subqueryAliasPrefix.count)) : alias
+}
+
+private func zqlRelated(_ related: AST.CorrelatedSubquery) -> String {
+  guard let alias = related.subquery.alias else { return "" }
+  var code = ".related('\(alias)'"
+  if hasSubqueryProps(related.subquery) { code += ", q => q" + astToZQL(related.subquery) }
+  return code + ")"
+}
+
+private func zqlValue(_ value: AST.ValuePosition) -> String {
+  switch value {
+  case .literal(let v): return zqlLiteral(v)
+  case .column(let name): return "'\(name)'"
+  case .json(let column, let path):
+    return "json('\(column)', \(zqlPath(path)))"
+  case .static(_, let field):
+    switch field {
+    case .single(let f): return "authParam('\(f)')"
+    case .path(let fields):
+      return "authParam([\(fields.map { "'\($0)'" }.joined(separator: ", "))])"
+    }
+  }
+}
+
+private func zqlPath(_ path: [AST.JSONPathSegment]) -> String {
+  path.map { segment in
+    switch segment {
+    case .key(let k): jsStringLiteral(k)
+    case .index(let i): String(i)
+    }
+  }.joined(separator: ", ")
+}
+
+/// `transformLiteral`: what `String()` prints, with strings quoted.
+private func zqlLiteral(_ value: JSONValue) -> String {
+  switch value {
+  case .null: "null"
+  case .array: JSONSerializer.stringify(value)
+  case .string(let s): jsStringLiteral(s)
+  case .number(let n): JSNumber.format(n)
+  case .bool(let b): b ? "true" : "false"
+  case .object: "[object Object]"
+  }
+}
+
+/// `transformAggregateArg`: nothing for a count, a column, or a callback
+/// that picks a leaf of a `json()` column.
+private func zqlAggregateArg(_ aggregate: AST.Aggregate) -> String {
+  guard let field = aggregate.field else { return "" }
+  let name = jsStringLiteral(field)
+  guard let path = aggregate.path else { return name }
+  return "({json}) => json(\(name), \(zqlPath(path)))"
+}
+
+/// A single-quoted JS string literal of `s`, escaped as `JSON.stringify`
+/// escapes it (`jsStringLiteral`).
+private func jsStringLiteral(_ s: String) -> String {
+  let quoted = Array(JSONSerializer.stringify(.string(s)).unicodeScalars)
+  var out = String.UnicodeScalarView()
+  var i = 1
+  let end = quoted.count - 1
+  while i < end {
+    let c = quoted[i]
+    if c == "\\", i + 1 < end, quoted[i + 1] == "\"" {
+      out.append("\"")
+      i += 2
+      continue
+    }
+    if c == "'" {
+      out.append("\\")
+      out.append("'")
+    } else {
+      out.append(c)
+    }
+    i += 1
+  }
+  return "'" + String(out) + "'"
+}

swift/Sources/Zero/Client/Engine.swift

@@ -75,6 +75,10 @@ public struct ZeroOptions: Sendable {
   /// hydration), with its listener calls. It must call the function it is
   /// given, once, before it returns.
   public var batchViewUpdates: (@MainActor @Sendable (() -> Void) -> Void)?
+  /// How long, in milliseconds, a query may take to materialize, until the
+  /// server has sent its rows, before a warning is logged
+  /// (`slowMaterializeThreshold`). Faster ones are logged at debug level.
+  public var slowMaterializeThreshold: Double = 5_000
 
   public init(
     cacheURL: String? = nil, userID: String? = nil, auth: String? = nil,
@@ -145,6 +149,8 @@ final class Engine {
   private(set) var mutationTracker: MutationTracker!
   private(set) var queryManager: QueryManager!
   private var pokeHandler: PokeHandler!
+  /// The inspector's requests (`zero.inspector`).
+  let inspectRPCs = InspectRPCs()
 
   /// The current token: `options.auth`, then the last one `connect(auth:)` set.
   private(set) var auth: String?
@@ -302,12 +308,17 @@ final class Engine {
       closedReason: { [weak self] in
         guard case .closed(let reason) = self?.connectionManager.state else { return nil }
         return reason
-      })
+      },
+      addMetric: { [weak self] metric, value, queryID, ast in
+        self?.queryManager.addMetric(metric, value, queryID: queryID, ast: ast)
+      },
+      monotonicNow: { [scheduler] in scheduler.monotonicNow })
     _ = connectionManager.subscribe { [weak self] state in self?.onConnectionStateChange(state) }
     onConnectionStateChange(connectionManager.state)
     queryManager = QueryManager(
       clientID: clientID, schema: schema, mutationTracker: mutationTracker, scheduler: scheduler,
       queryChangeThrottleMs: options.queryChangeThrottleMs, recentQueriesMaxSize: 0,
+      slowMaterializeThreshold: options.slowMaterializeThreshold, log: log,
       send: { [weak self] body in
         guard let self else { return }
         var body = body
@@ -806,7 +817,8 @@ final class Engine {
       userID: userID,
       baseCookie: connectCookie.stringValue ?? connectCookie.numberValue.map(JSNumber.format),
       timestamp: scheduler.monotonicNow, lastMutationID: lastMutationIDReceived, wsid: wsid,
-      profileID: profileID, additionalParams: additionalConnectParams ?? [])
+      profileID: profileID, debugPerf: log.level == .debug,
+      additionalParams: additionalConnectParams ?? [])
     addConnectEvent(attempt, "reading deleted clients")
     var deleted = deletedClientsBody()
     addConnectEvent(attempt, "reading desired queries")
@@ -915,6 +927,7 @@ final class Engine {
     connectedAt = nil
     socket?.close(code: closeCode)
     socket = nil
+    inspectRPCs.connectionLost(reason)
     lastMutationIDsSent.removeAll()
     pokeHandler.handleDisconnect()
     queryManager.clearGotQueriesAuthoritative()
@@ -1047,8 +1060,8 @@ final class Engine {
         try mutationTracker.processPushResponse(body)
       case .transformError(let errors):
         queryManager.handleTransformErrors(errors)
-      case .inspect:
-        break
+      case .inspect(let body):
+        inspectRPCs.receive(body)
       }
     } catch {
       disconnect(.client(.internal, message: errorMessage(error)))
@@ -1265,6 +1278,44 @@ final class Engine {
     database.release()
     database.removeWriteFailureListener(clientID)
     connectionManager.closed()
+    inspectRPCs.clientClosed()
+  }
+
+  /// The socket of the connection, once the current attempt has made it
+  /// (the inspector's `getSocket`).
+  func inspectorSocket(_ done: @escaping (Result<SocketHandle, InspectorError>) -> Void) {
+    if repClosed { return done(.failure(.clientClosed)) }
+    // Swift only: JS waits for a connection that never comes.
+    if socketOrigin == nil {
+      return done(.failure(.connectionLost("No server socket origin provided")))
+    }
+    let waiter = inspectRPCs.addSocketWaiter(done)
+    connectionReady.onSettle(loop) { [weak self] connected in
+      guard let self, let done = self.inspectRPCs.takeSocketWaiter(waiter) else { return }
+      if connected, let socket = self.socket {
+        done(.success(socket))
+      } else {
+        let reason =
+          Self.connectionError(self.connectionManager.state)
+          ?? self.connectionManager.state.reason
+        done(.failure(.connectionLost(reason?.message ?? "Not connected")))
+      }
+    }
+  }
+
+  /// Sends an inspector request on `socket`, which must still be the
+  /// connection's, and calls `done` with its response.
+  func sendInspect(
+    _ socket: SocketHandle, _ body: InspectUpBody,
+    _ done: @escaping (Result<InspectDownBody, InspectorError>) -> Void
+  ) {
+    if repClosed { return done(.failure(.clientClosed)) }
+    guard socket === self.socket else {
+      return done(
+        .failure(.connectionLost(connectionManager.state.reason?.message ?? "Disconnected")))
+    }
+    inspectRPCs.expect(body.id, done)
+    socket.send(Upstream.inspect(body).text)
   }
 
   // MARK: - Storage and the client lifecycle