Crash due to non thread safe destinations property

[dlbuckley]

Overview

We have been seeing a crash when logging from within an NSOperation from a few of our users. I've been trying to track it down for the past few hours and have managed to track it down to the destinations property not being thread safe.

Details

We have a number of services that start when the app starts and one of those is to do with sending network requests that have failed or have been cached previously. If the user starts the app without a network connection the request fails very quickly and so the operation fails which in turn triggers an issue to be logged. This is fine but the SwiftyBeaver service is being started at the same time and is having it's destinations added. The crash seems to come down to the destinations being modified while they are also being accessed.

As you can see from the crash log, the issue is appearing in SwiftyBeaver.swift at line 149 in version 1.7 (app name replaced with XXXXX for privacy reasons).

Crashed: NSOperationQueue 0x2818c39a0 (QOS: UTILITY)
0  libobjc.A.dylib                0x1f83de530 objc_msgSend + 16
1  libswiftCore.dylib             0x226942ca8 __CocoaSet.Iterator.next() + 92
2  SwiftyBeaver                   0x1020ef734 specialized static SwiftyBeaver.dispatch_send(level:message:thread:file:function:line:context:) + 149 (<compiler-generated>:149)
3  SwiftyBeaver                   0x1020eca40 static SwiftyBeaver.custom(level:message:file:function:line:context:) (SwiftyBeaver.swift)
4  asensei                        0x1013a1414 protocol witness for static Logger.custom(level:message:file:function:line:context:) in conformance SwiftyBeaver (<compiler-generated>)
5  XXXXX                        0x10141c630 static Logger.debug(_:_:_:line:context:) + 4301932080
6  XXXXX                        0x10141bf00 static Logger.error(_:_:_:line:context:) + 4301930240
7  XXXXX                        0x10128104c specialized closure #1 in ReliableOperationQueue.Storage.loadOperations(completion:) + 247 (ReliableOperationQueue.swift:247)
8  XXXXX                        0x10125403c thunk for @escaping @callee_guaranteed () -> () (<compiler-generated>)
9  Foundation                     0x1f9c50ef8 __NSBLOCKOPERATION_IS_CALLING_OUT_TO_A_BLOCK__ + 16
10 Foundation                     0x1f9b5d3e0 -[NSBlockOperation main] + 72
11 Foundation                     0x1f9b5c8c8 -[__NSOperationInternal _start:] + 740
12 Foundation                     0x1f9c52c7c __NSOQSchedule_f + 272
13 libdispatch.dylib              0x1f8bda7f0 _dispatch_block_async_invoke2 + 104
14 libdispatch.dylib              0x1f8c2c7d4 _dispatch_client_callout + 16
15 libdispatch.dylib              0x1f8bd1018 _dispatch_continuation_pop$VARIANT$mp + 412
16 libdispatch.dylib              0x1f8bd06dc _dispatch_async_redirect_invoke + 600
17 libdispatch.dylib              0x1f8bdd02c _dispatch_root_queue_drain + 372
18 libdispatch.dylib              0x1f8bdd8d0 _dispatch_worker_thread2 + 128
19 libsystem_pthread.dylib        0x1f8e0c1b4 _pthread_wqthread + 464
20 libsystem_pthread.dylib        0x1f8e0ecd4 start_wqthread + 4

Note

While it's not typically expected to start logging until the logger has started, it is also not expected to provoke a crash. This is one has come to light as it's actually a network request going through our own networking code in our own logger destination that triggers the log. Its a bit of a "chicken and the egg" situation.

[skreutzberger]

Thanks for posting this and taking your time to investigate the issue! Can you please also share how you set up the logger?

[Valpertui]

I'm encountering the same issue.
The logger is set up inside a DispatchQueue.concurentPerform iteration on different tools to initialize on app start

    SwiftyBeaver.setupConsole()
    SwiftyBeaver.setOSLog(enabled: true)

This is the setup code.

[skreutzberger]

Ah I think we found the issue! SwiftyBeaver is spawning using its own thread for logging operations to not slow down an app and that seems to create race conditions during the setup. Please try not to put SwiftyBeaver into an own thread and initialize it on the main thread.

[Valpertui]

This is the change I did : Move the setup out of the DispatchQueue.concurentPerform to the main thread, thanks :)

[valeriomazzeo]

In our case the setup is performed in the main thread, as soon as the app start.
In another thread (within an NSOperation), there are some calls to log - meanwhile additional destinations are being added.

We (myself and @dlbuckley) believe the issue is related to the destinations array not being thread safe.

@skreutzberger can you please reopen this issue?

[remy-bardou-lifeonair]

We've been running into the same issue on our project. Just put up a fix for it here: #504