Skip to content

chore: add logging to help investigate hang - WPB-22986 #4271

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
samwyndham merged 8 commits into from
Feb 6, 2026
+55 −20
Merged

chore: add logging to help investigate hang - WPB-22986 #4271

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
8aba259
Add non async version of `WireLogger.measureTime(label:attributes:blo…
samwyndham Feb 5, 2026
3592727
Log duration making client strategies
samwyndham Feb 5, 2026
9aa6869
Refactor `WireLogger.measureTime`
samwyndham Feb 5, 2026
20bd15d
Merge branch 'release/cycle-4.15' into chore/add-logging-for-hang-WPB…
samwyndham Feb 5, 2026
f98a46d
Merge branch 'release/cycle-4.15' into chore/add-logging-for-hang-WPB…
samwyndham Feb 6, 2026
6f6a210
Fix missing attributes when logging
samwyndham Feb 6, 2026
50cf2f6
Log whether it is a new client
samwyndham Feb 6, 2026
79bd151
Merge branch 'release/cycle-4.15' into chore/add-logging-for-hang-WPB…
samwyndham Feb 6, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions WireLogging/Sources/WireLogging/LogAttributes.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,7 @@ public enum LogAttributesKey: String, Comparable, Sendable {
case syncType = "sync_type"
case syncVersion = "sync_version"
case workItemID = "work_item_id"
case isNewClient = "is_new_client"

public static func < (lhs: LogAttributesKey, rhs: LogAttributesKey) -> Bool {
lhs.rawValue < rhs.rawValue
Expand Down
42 changes: 36 additions & 6 deletions WireLogging/Sources/WireLogging/WireLogger+MessageTime.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,17 +25,47 @@ public extension WireLogger {
attributes: LogAttributes = [:],
block: () async throws -> T
) async throws -> T {
let context = measureTimeStart(label: label, attributes: attributes)
let result = try await block()
measureTimeEnd(context: context)
return result
}

func measureTime<T, E: Error>(
label: String,
attributes: LogAttributes = [:],
block: () throws(E) -> T
) throws(E) -> T {
let context = measureTimeStart(label: label, attributes: attributes)
let result = try block()
measureTimeEnd(context: context)
return result
}

// MARK: - Helpers

private struct Context {
let start: Date
let label: String
let attributes: LogAttributes
}

private func measureTimeStart(
label: String,
attributes: LogAttributes
) -> Context {
let startMessage = "starting \(label)"
info(startMessage, attributes: attributes)
let start = Date.now
let result = try await block()
let durationInSeconds = start.timeIntervalSinceNow.magnitude
var updatedAttributes = attributes
return Context(start: Date.now, label: label, attributes: attributes)
}

private func measureTimeEnd(context: Context) {
let durationInSeconds = context.start.timeIntervalSinceNow.magnitude
var updatedAttributes = context.attributes
let formattedDuration = String(format: "%.2f", durationInSeconds)
updatedAttributes[.duration] = formattedDuration
let completedMessage = "completed \(label)"
let completedMessage = "completed \(context.label)"
info(completedMessage, attributes: updatedAttributes)
return result
}

}
2 changes: 1 addition & 1 deletion wire-ios-sync-engine/Source/Synchronization/StrategyDirectory.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -310,7 +310,7 @@ public class StrategyDirectory: NSObject, StrategyDirectoryProtocol {
]
}

func makeClientRelatedStategies(
func makeClientRelatedStrategies(
applicationStatusDirectory: ApplicationStatusDirectory,
syncContext: NSManagedObjectContext,
transportSession: TransportSessionType,
Expand Down
28 changes: 16 additions & 12 deletions wire-ios-sync-engine/Source/UserSession/ZMUserSession/ZMUserSession.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -612,12 +612,12 @@ public final class ZMUserSession: NSObject {

// Create and perform sync if there is a self client.
if let selfClientID = selfUserClient.remoteIdentifier {
setUpSyncAgent(clientID: selfClientID)
setUpSyncAgent(clientID: selfClientID, isNewClient: false)
}
}
}

func setUpSyncAgent(clientID: String) {
func setUpSyncAgent(clientID: String, isNewClient: Bool) {
let clientSessionComponent = userSessionComponent.clientSessionComponent(
clientID: clientID,
completionHandlers: .init(
Expand Down Expand Up @@ -659,15 +659,19 @@ public final class ZMUserSession: NSObject {
syncAgent: syncAgent,
notificationContext: notificationContext
)
strategyDirectory.makeClientRelatedStategies(
applicationStatusDirectory: applicationStatusDirectory,
syncContext: syncContext,
transportSession: transportSession,
pushMessageHandler: localNotificationDispatcher,
flowManager: flowManager,
incrementalSyncObserver: incrementalSyncObserver,
metadata: resolvedBackendMetadata
)

// TODO: [WPB-22986] Remove logging - added this logging temporarily to investigate a hang.
WireLogger.session.measureTime(label: "make client strategies", attributes: [.isNewClient: isNewClient]) {
strategyDirectory.makeClientRelatedStrategies(
applicationStatusDirectory: applicationStatusDirectory,
syncContext: syncContext,
transportSession: transportSession,
pushMessageHandler: localNotificationDispatcher,
flowManager: flowManager,
incrementalSyncObserver: incrementalSyncObserver,
metadata: resolvedBackendMetadata
)
}
syncStrategy?.updateClientContextChangeTrackers()
}
Task {
Expand Down Expand Up @@ -1389,7 +1393,7 @@ extension ZMUserSession: ZMClientRegistrationStatusDelegate {
// The client was just registered and still needs to perform the
// initial sync.
if let selfClientID = userClient.remoteIdentifier {
setUpSyncAgent(clientID: selfClientID)
setUpSyncAgent(clientID: selfClientID, isNewClient: true)
// no migration needed from last sync system as it's a new client
if userClient.isConsumableNotificationsCapable {
// activate new sync with consumable notifications
Expand Down
2 changes: 1 addition & 1 deletion wire-ios-sync-engine/Tests/Source/UserSession/ZMUserSessionTests.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -419,7 +419,7 @@ final class ZMUserSessionTests: ZMUserSessionTestsBase {
sut.didRegisterSelfUserClient(selfUserClient)
syncMOC.saveOrRollback()

sut.setUpSyncAgent(clientID: selfUserClient.remoteIdentifier!)
sut.setUpSyncAgent(clientID: selfUserClient.remoteIdentifier!, isNewClient: false)

// WHEN
sut.didFinishIncrementalSync(isRecovering: false)
Expand Down
Loading