Track all errors in Sentry #1558

Anderas · 2022-08-22T16:25:17Z

Following up on #1517, which tracked only some of MXLogError and MXLogFailure in analytics (Sentry for element-ios, assuming user consent), this PR extends this approach across the entire SDK and makes each error / failure trackable. This requires a number of changes:

add AnalyticsDestination to MXLog which sends errors to AnalyticsDelegate. Previous implementation simply hooked into the existing error methods and was a little hacky. Using destinations is the preffered approach
error and failure logs now require StaticString instead of String, meaning no variables can be present in the message. This may sound annoying but will make tracing of parameters more explicit by:
- not accidentally leaking sensitive data
- grouping errors by message without variable components
replace details argument with existing context argument that can be of any type. This is to both reduce the number of arguments as well as stay consistent with SwiftyBeaver
extract all variables from logs and pass them in the context, sometimes as a dictionary of values (this is the largest number of changes)

Anderas · 2022-08-22T16:29:00Z

MatrixSDK/Crypto/KeyBackup/MXKeyBackup.m

@@ -153,7 +153,8 @@ - (void)checkAndStartWithKeyBackupVersion:(nullable MXKeyBackupVersion*)keyBacku
            Class<MXKeyBackupAlgorithm> algorithmClass = AlgorithmClassesByName[keyBackupVersion.algorithm];
            if (algorithmClass == NULL)
            {
-                MXLogError(@"[MXKeyBackup] checkAndStartWithKeyBackupVersion: unknown algorithm: %@", keyBackupVersion.algorithm);
+                NSString *message = [NSString stringWithFormat:@"[MXKeyBackup] checkAndStartWithKeyBackupVersion: unknown algorithm: %@", keyBackupVersion.algorithm];


In some cases the variable is one of very few and it is okay making it a part of the message itself (objc has no StaticString equivalent, so this works)

Anderas · 2022-08-22T16:29:46Z

MatrixSDK/Crypto/MXCrypto.m

@@ -653,7 +661,12 @@ - (MXEventDecryptionResult *)decryptEvent2:(MXEvent *)event inTimeline:(NSString
        result = [alg decryptEvent:event inTimeline:timeline];
        if (result.error)
        {
-            MXLogError(@"[MXCrypto] decryptEvent: Error for %@: %@\nEvent: %@", event.eventId, result.error, event.JSONDictionary);
+            NSDictionary *details = @{


Annoyingly objc will crash if we ever add nil value to a dictionary, meaning it is safer to always default to something rather than risk logs crashing the app

Whereabouts does this crash actually happen? I'm wondering if there would be an opportune place we could map all of the nil values in the dictionary into @"unknown" before the crash takes place?

Otherwise it kind of feels like it would be an easy place for someone to introduce a crash by either not knowing this pitfall, or by not realising a value is nullable.

It is the actual construction of dictionary, for example this will crash:

NSString *value = nil; NSDictionary *dict = @{ @"value": value // If I passed nil here directly the compiler would catch it };

So we can't really put any kind of safety wrapper around it. The rest of the codebase has this issue as well but is seems we rarely have unexpected nil values. My justification for allowing this was that most new code we write is in swift and thus we won't be really adding new dictionary contexts in objective-c, but of course I could be wrong

TIL that this is standard objc behaviour! Ignore me 🤐

codecov-commenter · 2022-08-23T07:25:49Z

Codecov Report

Merging #1558 (5f4c854) into develop (62ec1ec) will decrease coverage by 0.07%.
The diff coverage is 12.67%.

@@             Coverage Diff             @@
##           develop    #1558      +/-   ##
===========================================
- Coverage    45.25%   45.17%   -0.08%     
===========================================
  Files          520      521       +1     
  Lines        84791    84957     +166     
  Branches     37520    37500      -20     
===========================================
+ Hits         38369    38381      +12     
- Misses       45320    45476     +156     
+ Partials      1102     1100       -2

Impacted Files	Coverage Δ
...gations/LocationSharing/MXBeaconAggregations.swift	`46.66% <0.00%> (-0.30%)`	⬇️
...ng/Store/Realm/MXBeaconInfoSummaryRealmStore.swift	`69.37% <0.00%> (ø)`
...rixSDK/Aggregations/MXAggregatedReactionsUpdater.m	`84.51% <0.00%> (-0.37%)`	⬇️
MatrixSDK/Background/MXBackgroundSyncService.swift	`63.25% <0.00%> (-0.35%)`	⬇️
...atrixSDK/Crypto/Dehydration/MXDehydrationService.m	`59.57% <0.00%> (-3.35%)`	⬇️
...KeyBackup/Data/Aes256/MXAes256KeyBackupAlgorithm.m	`74.76% <0.00%> (-0.72%)`	⬇️
...p/Data/Curve25519/MXCurve25519KeyBackupAlgorithm.m	`70.00% <0.00%> (-0.84%)`	⬇️
MatrixSDK/Crypto/KeyBackup/MXKeyBackup.m	`69.47% <0.00%> (-0.19%)`	⬇️
...SDK/Crypto/Verification/MXKeyVerificationManager.m	`4.06% <0.00%> (-0.01%)`	⬇️
...xSDK/Data/EventTimeline/Room/MXRoomEventTimeline.m	`74.29% <0.00%> (-0.25%)`	⬇️
... and 37 more

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

pixlwave

This looks like a great change overall to me 😎

pixlwave · 2022-08-23T10:19:07Z

MatrixSDK/Data/MXRoomSummary.m

@@ -552,7 +554,9 @@ - (void)setIsEncrypted:(BOOL)isEncrypted
    // This should never happen
    if (_isEncrypted && !isEncrypted)
    {
-        MXLogError(@"[MXRoomSummary] setIsEncrypted: Attempt to reset isEncrypted for room %@. Ignote it. Call stack: %@", self.roomId, [NSThread callStackSymbols]);


I'm presuming we don't need to worry about call stacks now that these go to Sentry.

Exactly, though it will be missing from rageshake files ... I think that is okay?

Yep yep, makes sense to me 👍

pixlwave · 2022-08-23T10:20:46Z

MatrixSDK/Data/Store/MXFileStore/MXFileStore.m

@@ -993,7 +993,7 @@ - (RoomReceiptsStore*)getOrCreateRoomReceiptsStore:(NSString *)roomId
                        @"roomId": roomId ?: @"",
                        @"exception": exception
                    };
-                    MXLogErrorWithDetails(@"[MXFileStore] Warning: loadReceipts file for room as been corrupted", logDetails);
+//                    MXLogErrorWithDetails(@"[MXFileStore] Warning: loadReceipts file for room as been corrupted", logDetails);


Is this intentionally left commented?

Oops sorry, thanks

pixlwave · 2022-08-23T10:26:55Z

MatrixSDK/Utils/Logs/AnalyticsDestination.swift

+import SwiftyBeaver
+
+/// SwiftyBeaver log destination that sends errors to analytics tracker
+class AnalyticsDestination: BaseDestination {


Maybe this should be MXAnalyticsDestination?

pixlwave · 2022-08-23T10:31:08Z

MatrixSDK/Utils/Logs/MXLog.h

 }
+
+// TODO: failure context


Is that todo different to the MXLogFailures above?

Missed that, thanks 🤦

pixlwave · 2022-08-23T10:33:04Z

MatrixSDK/Utils/Logs/MXLog.swift

+
+    /// Log failure with additional details
+    ///
+    /// A failure is any type of programming error which should never occur in production. In `DEBUG` confuguration


Suggested change

/// A failure is any type of programming error which should never occur in production. In `DEBUG` confuguration

/// A failure is any type of programming error which should never occur in production. In `DEBUG` configuration

pixlwave · 2022-08-23T10:36:33Z

MatrixSDK/Utils/Logs/MXLog.swift

    }
 }

 /// Convenience wrapper around `MXLog` which formats all logs as "[Name] function: <message>"
+///
+/// Note: Ideallly the `format` of `ConsoleDestination` is set to track filename and function automatically


Suggested change

/// Note: Ideallly the `format` of `ConsoleDestination` is set to track filename and function automatically

/// Note: Ideally the `format` of `ConsoleDestination` is set to track filename and function automatically

pixlwave · 2022-08-23T10:42:39Z

MatrixSDK/Crypto/MXCrypto.m

@@ -653,7 +661,12 @@ - (MXEventDecryptionResult *)decryptEvent2:(MXEvent *)event inTimeline:(NSString
        result = [alg decryptEvent:event inTimeline:timeline];
        if (result.error)
        {
-            MXLogError(@"[MXCrypto] decryptEvent: Error for %@: %@\nEvent: %@", event.eventId, result.error, event.JSONDictionary);
+            NSDictionary *details = @{


Whereabouts does this crash actually happen? I'm wondering if there would be an opportune place we could map all of the nil values in the dictionary into @"unknown" before the crash takes place?

Otherwise it kind of feels like it would be an easy place for someone to introduce a crash by either not knowing this pitfall, or by not realising a value is nullable.

pixlwave

LGTM 👍

Track all errors in Sentry

40445ca

Anderas marked this pull request as ready for review August 22, 2022 16:25

Changelog

6c55607

Anderas requested review from a team and pixlwave and removed request for a team August 22, 2022 16:26

Anderas commented Aug 22, 2022

View reviewed changes

Anderas mentioned this pull request Aug 22, 2022

Track all errors in Sentry element-hq/element-ios#6611

Merged

Missing files

df97e8a

Anderas force-pushed the andy/sentry branch from 7004b62 to df97e8a Compare August 22, 2022 16:37

Fix missing headers

5761b0f

pixlwave reviewed Aug 23, 2022

View reviewed changes

Code review changes

5f4c854

Anderas requested a review from pixlwave August 23, 2022 13:33

pixlwave approved these changes Aug 23, 2022

View reviewed changes

Anderas merged commit 66a3c3f into develop Aug 24, 2022

Anderas deleted the andy/sentry branch August 24, 2022 07:18

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Track all errors in Sentry #1558

Track all errors in Sentry #1558

Anderas commented Aug 22, 2022

Anderas Aug 22, 2022

Anderas Aug 22, 2022

pixlwave Aug 23, 2022

Anderas Aug 23, 2022

pixlwave Aug 23, 2022

codecov-commenter commented Aug 23, 2022 •

edited

pixlwave left a comment

pixlwave Aug 23, 2022

Anderas Aug 23, 2022

pixlwave Aug 23, 2022

pixlwave Aug 23, 2022

Anderas Aug 23, 2022

pixlwave Aug 23, 2022

pixlwave Aug 23, 2022

Anderas Aug 23, 2022

pixlwave Aug 23, 2022

pixlwave Aug 23, 2022

pixlwave Aug 23, 2022

pixlwave left a comment

	/// A failure is any type of programming error which should never occur in production. In `DEBUG` confuguration
	/// A failure is any type of programming error which should never occur in production. In `DEBUG` configuration

	/// Note: Ideallly the `format` of `ConsoleDestination` is set to track filename and function automatically
	/// Note: Ideally the `format` of `ConsoleDestination` is set to track filename and function automatically

Track all errors in Sentry #1558

Track all errors in Sentry #1558

Conversation

Anderas commented Aug 22, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

codecov-commenter commented Aug 23, 2022 • edited

Codecov Report

pixlwave left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pixlwave left a comment

Choose a reason for hiding this comment

codecov-commenter commented Aug 23, 2022 •

edited