Logging appears to leak memory

[mattwelborn]

Running following code results in a growth of memory usage to 500 MB

func testMemoryLeak() {
        var loggers = [LogConfiguration]()
        let xcodeConfig = XcodeLogConfiguration(minimumSeverity: LogSeverity.verbose,
                                                logToASL: false)
        loggers.append(xcodeConfig)
        Log.enable(configuration: loggers)

        for _ in 1...1000000 {
            Log.info?.message("Test")
        }
}

This issue came up in bmichotte/HSTracker#495.

[emaloney]

@mattwelborn Thanks for the report. I can confirm seeing the same behavior as you in Instruments given the test code above.

What appears to be happening is that the code is running in such a tight loop that the autorelease pools aren't getting a change to drain. It looks like this scenario can be handled defensively within CleanroomLogger, so I'll issue a point-point release sometime soon to address it.

[emaloney]

Upon further investigation, it looks like we were hitting two distinct problems: The tight loop preventing the autorelease pools from draining as described above, but there also appears to be a memory leak within dispatch_async() itself when one async queue dispatches to another. You can trigger it using this code:

let q = dispatch_queue_create("foo", DISPATCH_QUEUE_SERIAL)
let q2 = dispatch_queue_create("foo2", DISPATCH_QUEUE_SERIAL)

for _ in 1...1000000 {
    autoreleasepool {
        dispatch_async(q) {
            autoreleasepool {
                dispatch_async(q2) {
                    autoreleasepool {
                        print("test @ \(NSDate())")
                    }
                }
            }
        }
    }
}

Interestingly, changing the call from dispatch_async() to dispatch_sync() avoids the problem. (And this is why I didn't hit the GCD leak while trying to diagnose your example above; on my installation, I run CleanroomLogger in synchronous mode when debugging, and the leak does not occur in synchronous mode.)

[emaloney]

Another possible way to explain the behavior above is simply that we're putting work into the GCD queue faster than it can handle processing it. If that's the case, it would look like a leak, but that's only because unprocessed work is backing up in the queue. The problem doesn't show up with dispatch_sync() because—by it's very nature—in a loop like above, you can't add more work than the queue can process.