We've been using our own logging system for quite a long time but we are interested in the benefits offered by Logger/OSLog
and plan to migrate to it.
Before modifying thousands of logging calls, we want to understand a bit more how, when and where (ie. from which thread/queue) OSLog
strings interpolation is performed.
More specifically, we are concerned by simultaneous access to properties from different threads. Our app usually handles that using DispatchQueues (single or concurrent) and calls to our logging system is safe as the log string is built synchronously.
On the other hand, when using Logger/OSLog
, the provided string is in fact an OSLogMessage which keeps a reference to values and properties in order to build the final String later (asynchronously). If it is correct, the "later" part concerns us.
Example
Let's consider the following class property profile
(instance of Profile
class which implements CustomStringConvertible
):
private var profile: Profile?
With our own logging system, we used to log the profile
property at the time the logging method is called (and when the access to profile
is safe):
Log.debug(logModule, "Current profile: \(profile)")
Now moving to Logger/OSLog
, the following error appears:
logger.debug("Current profile: \(profile)")
// Reference to property 'profile' in closure requires explicit use of 'self' to make capture semantics explicit
Our understanding is that the property profile
is not accessed synchronously but later, possibly after or even worse while the property is being mutated from another thread (-> crash). In which case fixing the error using "Current profile: \(self.profile)"
instead would be a very bad idea...
The same goes with class instance properties used in the implementation of CustomStringConvertible.description
property. If the description
property is built asynchronously, the class instance properties may have been mutated or may be being mutated from another thread.
TL;DR
We have searched for good practices when using Logger/OSLog
but could not find any dealing with the thread-safeness of logged objects.
- Is it a good idea to capture self in Logger calls?
- Is it safe to log non value-type objects such as class instances?
Thanks for clarifications.