Log uncaught exceptions #53

NickEntin · 2017-10-22T07:08:51Z

No description provided.

dfed

Love the work here! Some comments below. Would be great to add a section to the README as well.

dfed · 2017-10-22T19:13:23Z

Aardvark/ARKExceptionLogging.h

+@import Foundation;
+
+
+/// Enables logging uncaught exceptions.


Might be good to explain here how this will interop with crash reporters. i.e. if this call should be executed before or after setting up a crash reporter.

dfed · 2017-10-22T19:13:49Z

Aardvark/ARKExceptionLogging.h

+/// Enables logging uncaught exceptions.
+OBJC_EXTERN void ARKEnableLogOnUncaughtException(void);
+
+/// Disables logging uncaught exceptions.


Would be good to explain what state the app is returned to here, especially with regards to crash reporters.

dfed · 2017-10-22T19:14:50Z

Aardvark/ARKExceptionLogging.h

@@ -0,0 +1,28 @@
+//
+//  ARKExceptionLogging.h
+//  Aardvark


Should this be a part of CoreAardvark? This seems like core functionality, but I'm not sure if the APIs we're using here are extension safe.

I think it should be fine in CoreAardvark. I'll do some testing, but don't see anything that says it isn't extension safe.

dfed · 2017-10-22T19:18:07Z

Aardvark/ARKExceptionLogging.m

+
+void ARKEnableLogOnUncaughtException()
+{
+    ARKPreviousUncaughtExceptionHandler = NSGetUncaughtExceptionHandler();


Do we need to consider threading here? Should this be called only from the Main thread? Or is this call thread safe?

I don't see anything about threading in the documentation and from some testing it seems to work fine setting it from either the main thread or a background thread. In either case, the exception handler gets called on the thread on which the exception occurred, and the previously-set exception handler gets chained correctly.

Nice. Makes sense that Apple would make this thread safe (though sucky that they didn't make this explicit in the documentation).

dfed · 2017-10-22T19:19:30Z

Aardvark/ARKExceptionLogging.m

+
+void ARKHandleUncaughtException(NSException *exception)
+{
+    ARKLogWithType(ARKLogTypeError, nil, @"Uncaught exception '%@':\n%@", exception.name, exception.debugDescription);


Why use debugDescription rather than description?

debugDescription includes both the description and the stack trace

dfed · 2017-10-22T19:24:05Z

One more thing: we should hook this code into to the sample app :)

dfed · 2018-06-23T00:23:58Z

CoreAardvark/ARKExceptionLogging.m

+{
+    ARKLogWithType(ARKLogTypeError, nil, @"Uncaught exception '%@':\n%@", exception.name, exception.debugDescription);
+    dispatch_semaphore_t logDistributionSemaphore = dispatch_semaphore_create(0);
+    [[ARKLogDistributor defaultDistributor] distributeAllPendingLogsWithCompletionHandler:^{


We should probably add a comment here that we're trying to flush all logs prior to crashing. It may also be worth giving ARKLogObserver a - (void)processAllPendingLogsWithCompletionHandler:(nonnull dispatch_block_t)completionHandler; method, and calling it here on each log distributor.

Right now, you're distributing all logs to your log observers, but your log observers may be doing async tasks & not be complete processing them by the time this callback is executed.

Also, I'm curious: what happens if an exception is triggered while we wait for all logs to be distributed? Do we enter an infinite crash loop?

From what I can tell, it won't reenter the exception handler if an exception occurs.

Added a call to -[ARKLogDistributor distributeAllPendingLogsWithCompletionHandler:] to bump the thread priority. My goal here was to make sure that the final exception log gets written to disk (so only the default log distributor), not to flush all log distributors/observers. Flushing all logs might be helpful though, since that could give context around the crash.

Since adding that functionality to the log observers would be a breaking change, what do you think about making it only flush the default distributor for now, and file an issue to flush all observers too in 4.0?

Filed #68 to track

…gesture to sample app

dfed

LGTM! Solid job making the default distributor distribute all logs. Adding an issue for all distributors seems reasonable to me.

However, thoughts on ARKEnableLogOnUncaughtException taking an array of distributors to flush as an argument? That wouldn't be a breaking change, right?

dfed · 2018-09-28T20:33:48Z

README.md

@@ -61,6 +61,9 @@ Want to look at logs on device? Push an instance of [ARKLogTableViewController](
 ## Performance
 Logs are distributed to loggers on an internal background queue that will never slow down your app. Logs observed by the log store are incrementally appended to disk and not stored in memory.

+## Exception Logging
+To turn on logging of uncaught exceptions, call `ARKEnableLogOnUncaughtException()`. When an uncaught exception occurs, the stack trace will be logged to the default log distributor. To test this out in the sample app, hold one finger down on the screen for at least 5 seconds.


We should add in here that we'll propagate the exceptions back to any existing crash handler.

NickEntin · 2018-09-28T22:02:33Z

Instead of taking an array, I made it so you can specify which distributor you want, and call it multiple times to support multiple log distributors.

dfed · 2018-09-28T22:46:36Z

AardvarkSample/AardvarkSample/AppDelegate.swift

+// MARK: - Uncaught Exception Handling
+
+func existingUncaughtExceptionHandler(exception: NSException) {
+    print("Existing uncaught exception handler got called")


should we print the exception here?

this is super nifty btw

dfed · 2018-09-28T22:48:32Z

CoreAardvark/ARKExceptionLogging.h

+OBJC_EXTERN void ARKEnableLogOnUncaughtException(void);
+
+/// Enables logging uncaught exceptions to the specified log distributor. Calls into previously-set uncaught exception handler after logging if one has been set.
+OBJC_EXTERN void ARKEnableLogOnUncaughtExceptionToLogDistributor(ARKLogDistributor *_Nonnull logDistributor);


dope nullable annotation

dfed · 2018-09-28T22:48:58Z

CoreAardvark/ARKExceptionLogging.m

+
+void ARKHandleUncaughtException(NSException *exception)
+{
+    for (ARKLogDistributor *logDistributor in ARKUncaughtExceptionLogDistributors) {


const 😉

(super non-blocking)

dfed · 2018-09-28T22:50:10Z

CoreAardvark/ARKExceptionLogging.m

+{
+    [ARKUncaughtExceptionLogDistributors removeObject:logDistributor];
+
+    // If that was the last log distributor, clean up the handler.


love this. Like, really love the thoroughness.

but: where are the tests?

Best way I can think of to test is creating an internal object that has the NSSetUncaughtExceptionHandler and NSGetUncaughtExceptionHandler methods handed to it via blocks so you can swap them out for test methods. Then use that internal object under the hood here.

Love the new tests!

dfed · 2018-09-28T22:52:06Z

CoreAardvark/ARKExceptionLogging.h

+
+@class ARKLogDistributor;
+
+


should we have a note in this file about thread safety? Given what's happening under the hood, these methods should all be called from the same thread.

Good point. I'll add a comment.

Instead, added locks to make it thread safe. :)

dfed · 2018-09-28T22:53:49Z

CoreAardvark/ARKExceptionLogging.m

+    if (ARKUncaughtExceptionLogDistributors == nil) {
+        ARKUncaughtExceptionLogDistributors = [NSMutableArray arrayWithObject:logDistributor];
+
+        ARKPreviousUncaughtExceptionHandler = NSGetUncaughtExceptionHandler();


I think you need a stack of ARKPreviousUncaughtExceptionHandlers. Otherwise the following code

ARKEnableLogOnUncaughtException() ARKEnableLogOnUncaughtExceptionToLogDistributor(mySpecialDistributor)

will nuke whatever uncaught exception handler was previously set.

Also, if you do the above, how many times will ARKHandleUncaughtException (which logs to all registered log distributors) be called? I think twice?

It should only ever get called once. Unless I missed something (or they get called on different threads, as you pointed out above), it should be in one of two states:

Exception logging is disabled. ARKHandleUncaughtException is not the specified uncaught exception handler. ARKUncaughtExceptionLogDistributors is nil. ARKPreviousUncaughtExceptionHandler is nil.

Exception logging is enabled. ARKHandleUncaughtException is the specified uncaught exception handler. ARKUncaughtExceptionLogDistributors has at least one log distributor. ARKPreviousUncaughtExceptionHandler is set to the previously-set uncaught exception handler.

When you enable logging and there are no existing log distributors set up, it will perform the initial setup (setting itself as the uncaught exception handler, and storing the existing one to chain). When you enable logging on additional distributors, it will only add them to the list of distributors to use.

When you disable logging, it will remove the log distributor from the list. Then, it checks if the list is now empty, and if so reverses the setup process, removing itself as the uncaught exception handler (and restoring the previous one) and clearing out the distributor list.

FWIW, I tested calling enable twice, and it logged the message twice, then called the existing handler.

🤦‍♂️ I missed the ARKUncaughtExceptionLogDistributors == nil check somehow. Thank you for the detailed explanation. I agree that this works and my fears are unfounded. This is a really simple/clever way to make this work.

A comment above this line saying "we only want to register ourselves as an exception handler the first time a log distributor is registered" might help with long-term maintenance, but so would reading more carefully 🙂

dfed · 2018-09-28T23:36:30Z

CoreAardvark/ARKExceptionLogging.m

+{
+    static dispatch_once_t onceToken;
+    dispatch_once(&onceToken, ^{
+        ARKUncaughtExceptionLogDistributorsLock = [[NSLock alloc] init];


supnit: new

dfed · 2018-09-28T23:37:57Z

CoreAardvark/ARKExceptionLogging.m

 void ARKHandleUncaughtException(NSException *exception)
 {
-    for (ARKLogDistributor *logDistributor in ARKUncaughtExceptionLogDistributors) {


we should lock around this method too, since the lock should be protecting ARKUncaughtExceptionLogDistributors in addition to ARKPreviousUncaughtExceptionHandler, right?

dfed

The tests are really great! Only blocking comment is where we unlock. Besides that, this is ready to merge.

dfed · 2018-09-29T02:09:12Z

CoreAardvark/ARKExceptionLogging.m

-
-    if (ARKPreviousUncaughtExceptionHandler != nil) {
+
+    [logDistributorsLock unlock];


unlock should go after we access ARKPreviousUncaughtExceptionHandler below

Moved the reading of ARKPreviousUncaughtExceptionHandler inside the lock, but left the calling outside, to avoid deadlock in case the previous handler somehow calls back into this one.

dfed · 2018-09-29T02:09:23Z

CoreAardvark/ARKExceptionLogging.m

+{
+    [ARKUncaughtExceptionLogDistributors removeObject:logDistributor];
+
+    // If that was the last log distributor, clean up the handler.


Love the new tests!

dfed reviewed Oct 22, 2017

View reviewed changes

NickEntin force-pushed the entin/exception-logging branch from a723c01 to 58221d7 Compare October 22, 2017 21:02

dfed reviewed Jun 23, 2018

View reviewed changes

NickEntin added 3 commits September 28, 2018 00:37

Add uncaught exception handling

241379d

Bump Aardvark pod version to 3.2.0

2999a5e

Flush default log distributor after logging exception, add exception …

81b5013

…gesture to sample app

NickEntin force-pushed the entin/exception-logging branch from e5ec963 to 81b5013 Compare September 28, 2018 07:46

Add section to README describing exception logging functionality

adebe5f

dfed approved these changes Sep 28, 2018

View reviewed changes

Support logging to multiple log distributors

34488d9

dfed reviewed Sep 28, 2018

View reviewed changes

NickEntin added 2 commits September 28, 2018 16:06

Bump CoreAardvark, not Aardvark

99794a0

Thread safety, address feedback

f56717f

dfed reviewed Sep 28, 2018

View reviewed changes

NickEntin added 2 commits September 28, 2018 17:54

Add unit tests, address feedback

feb7345

Add missing nullability specifiers

143c1e7

dfed reviewed Sep 29, 2018

View reviewed changes

Read previous handler inside lock

c84ad30

dfed approved these changes Sep 30, 2018

View reviewed changes

NickEntin merged commit ae05c36 into square:master Oct 2, 2018

NickEntin deleted the entin/exception-logging branch October 2, 2018 01:28

NickEntin mentioned this pull request Oct 2, 2018

Flush all log observers when logging an uncaught exception #68

Closed


		if (ARKPreviousUncaughtExceptionHandler != nil) {

		[logDistributorsLock unlock];


		@class ARKLogDistributor;

Log uncaught exceptions #53

Log uncaught exceptions #53

Conversation

NickEntin commented Oct 22, 2017

dfed 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

dfed commented Oct 22, 2017

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

dfed left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

NickEntin commented Sep 28, 2018

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

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dfed 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