Fix for crash caused by persistent logging #321
Conversation
KennyHuRadar
changed the title
RadarSDK/Radar.m
Outdated
| onComplete(status); | ||
| }]; | ||
| } | ||
| onComplete(status); |
There was a problem hiding this comment.
Do we know what thread is being used to call this completion handler (could also be the main thread)
There was a problem hiding this comment.
It's not easy to reason through which thread will call this chunk at runtime. It won't t hurt to be explicit in this case. I should just send it to a another thread.
RadarSDK/RadarLogger.m
Outdated
| @@ -70,7 +70,9 @@ - (void)logWithLevel:(RadarLogLevel)level type:(RadarLogType)type message:(NSStr | |||
|
|
|||
| os_log(OS_LOG_DEFAULT, "%@", log); | |||
|
|
|||
| [[RadarDelegateHolder sharedInstance] didLogMessage:log]; | |||
| dispatch_async(dispatch_get_main_queue(), ^{ | |||
There was a problem hiding this comment.
Why does this need to use the main thread?
There was a problem hiding this comment.
I guess this is the typical pattern we use throughout the codebase callbacks
There was a problem hiding this comment.
Here we are calling the dispatcher, we should use the main thread as the lister on the other end may decide to use it to update the UI. e.g. have a super user log console that print out logs as they occur. I think our current pattern is an oversimplification. I think we should only call "end user supplied" callbacks and delegate dispatches on the main thread as those may be used to cause UI updates. Other callbacks within the internal working of our SDK should not needlessly crowd the main thread baring threading/synchronization concerns.
There was a problem hiding this comment.
Looking back at this, I'm thinking we shouldn't have this on the main thread. Unlikely a production user is gonna update UI based on the logs, and if there's lots of logging happening this could be contributing to main thread bloat
There was a problem hiding this comment.
Sounds right to me. But this is technically a breaking change so I'm adding a note in migration guide for completeness.
lmeier
force-pushed
the
make-resign-active-log-append
branch
from
756538a
to
a9a884d
Compare
* make notification take same custom icon and background as foreground service * implemented new radarnotificationsoptions class with usage in creating notifications and tests * cleanup * make name singular and formatting changes * changed comments * add punctioation to comment * spacing formatting
Context
There were some crash logs coming in that suggests a potential issue introduced by our implementation of persistent logging.
This is the reason for termination:
This error is caused when a process is blocking the main thread for some time. https://developer.apple.com/documentation/xcode/addressing-watchdog-terminations
The frames of the logs contain these notable snippets:
This suggests that this chunk of code was dispatched to the main queue.
This suggest that the
sortedArrayFromRange:options:usingComparatorwithinRadarFileStoragewas ran.Another notable part is that before each crash, the app seemed to progress to a different point of the sort.
Discussion
The first suspected culprit was definitely the sort. But a closer look at the implementation of the sort casts some doubt on that hypothesis. The sort is being carried out on an immutable array of strings with the comparator casting the string into NSIntergers. If the comparator fails to parse the strings, the strings will simply be unsorted. It is unlikely that such a sort would itself cause terrible lag. The fact that the app seemed to be progressing through different points of the sort when it got shut down seems to suggest that there is no one part of the sort that is deterministically slowing everything down.
The second culprit is the thread in which the crashes were occurring in the main thread. The main thread is responsible for updating the UI and is generally considered "less performant" and more "crowded". Close inspection of the code path revealed 2 instances where logging-related operations were dispatched to the main thread. Considering how persistent logging involves synchronized reads and writes to storage, this implementation is not appropriate and will impact UI performance.
Furthermore, a ramped-up tracking state creates a lot of logs while also attempting to sync logs with the server frequently. This may cause a "backup" of synchronized calls waiting to be executed. Hence, a persistent logging operation that was dispatched to the main queue may be blocked by preceding persistent logging operations, increasing the likelihood of the watchdog shutting the operation down.
Suggested Remediations
Limitations