"Object was retained too many times"

Following this discussion, I got lldb to produce a backtrace using this as the build command:

swift build -Xlinker --export-dynamic -Xswiftc -g -Xswiftc -Xfrontend -Xswiftc -serialize-debugging-options

Our backtrace:

(lldb) thread backtrace
* thread #170, name = 'NIO-ELT-0-#13', stop reason = signal SIGABRT
  * frame #0: 0x00007fffad62ff47 libc.so.6`gsignal + 199
    frame #1: 0x00007fffad6318b1 libc.so.6`abort + 321
    frame #2: 0x00005555560b094f ModelApp`swift_retain_hook(object=0x00007ffe80002670) at retain.c:24:11
    frame #3: 0x00007ffff6667ece libFoundation.so`CFRetain + 14
    frame #4: 0x00007ffff669a77d libFoundation.so`__CreateCFDateFormatter + 157
    frame #5: 0x00007ffff636149f libFoundation.so`Foundation.NSDate.description.getter : Swift.String + 159
    frame #6: 0x00007ffff6102ba6 libFoundation.so`Foundation.Date.description.getter : Swift.String + 70
    frame #7: 0x00007ffff61031df libFoundation.so`protocol witness for Swift.CustomStringConvertible.description.getter : Swift.String in conformance Foundation.Date : Swift.CustomStringConvertible in Foundation + 15
    frame #8: 0x00007ffff7960cd7 libswiftCore.so`Swift.DefaultStringInterpolation.appendInterpolation<τ_0_0 where τ_0_0: Swift.CustomStringConvertible>(τ_0_0) -> () + 23
    frame #9: 0x0000555555feb7d7 ModelApp`closure #1 in MyData.Callback(dataUpdates=3 values, self=0x0000555557a71be0) at MyData.swift:163:63
    frame #10: 0x0000555555ffffc6 ModelApp`closure #1 in DataStream.handleResponseString(self=0x00007fff0825b850, string="{\"channel\": \"data\", \"type\": \"update\", \"data\": {\"time\": 1601744938.7753208, \"action\": \"update\"}}") at DataStream.swift:152:30
    frame #11: 0x0000555555805e6f ModelApp`thunk for @escaping @callee_guaranteed () -> (@error @owned Error) at <compiler-generated>:0
    frame #12: 0x0000555556000464 ModelApp`thunk for @escaping @callee_guaranteed () -> (@error @owned Error)partial apply at <compiler-generated>:0
    frame #13: 0x0000555555c384d6 ModelApp`closure #1 in EventLoop.submit<Self>(promise=NIO.EventLoopPromise<()> @ 0x00007ffef17f35a8, task=0x0000555556000450 ModelApp`reabstraction thunk helper from @escaping @callee_guaranteed () -> (@error @owned Swift.Error) to @escaping @callee_guaranteed () -> (@out (), @error @owned Swift.Error)partial apply forwarder with unmangled suffix ".30" at <compiler-generated>) at EventLoop.swift:488:37
    frame #14: 0x0000555555cc6f1c ModelApp`thunk for @escaping @callee_guaranteed () -> () at <compiler-generated>:0
    frame #15: 0x0000555555ccb691 ModelApp`partial apply for thunk for @escaping @callee_guaranteed () -> () at <compiler-generated>:0
    frame #16: 0x0000555555cc6f3c ModelApp`thunk for @escaping @callee_guaranteed () -> (@out ()) at <compiler-generated>:0
    frame #17: 0x0000555555cc6f87 ModelApp`closure #4 in SelectableEventLoop.run(task=0x0000555555cca070 ModelApp`partial apply forwarder for reabstraction thunk helper from @escaping @callee_guaranteed () -> (@out ()) to @escaping @callee_guaranteed () -> () at <compiler-generated>) at SelectableEventLoop.swift:454:25
    frame #18: 0x0000555555b6d00f ModelApp`thunk for @callee_guaranteed () -> (@error @owned Error) at <compiler-generated>:0
    frame #19: 0x0000555555cca034 ModelApp`thunk for @callee_guaranteed () -> (@error @owned Error)partial apply at <compiler-generated>:0
    frame #20: 0x0000555555cc0a62 ModelApp`withAutoReleasePool<T>(execute=0x0000555555cca020 ModelApp`reabstraction thunk helper from @callee_guaranteed () -> (@error @owned Swift.Error) to @escaping @callee_guaranteed () -> (@out (), @error @owned Swift.Error)partial apply forwarder with unmangled suffix ".9" at <compiler-generated>) at SelectableEventLoop.swift:26:16
    frame #21: 0x0000555555cc52cc ModelApp`SelectableEventLoop.run(self=0x00007ffed4001000) at SelectableEventLoop.swift:453:21
    frame #22: 0x0000555555c3b82b ModelApp`static MultiThreadedEventLoopGroup.runTheLoop(thread=0x00007ffed4000b20, canEventLoopBeShutdownIndividually=false, selectorFactory=0x0000555555c3c370 ModelApp`implicit closure #1 () throws -> NIO.Selector<NIO.NIORegistration> in NIO.MultiThreadedEventLoopGroup.init(numberOfThreads: Swift.Int) -> NIO.MultiThreadedEventLoopGroup at EventLoop.swift, initializer=0x0000555555c42240 ModelApp`partial apply forwarder for reabstraction thunk helper from @escaping @callee_guaranteed (@in_guaranteed NIO.NIOThread) -> (@out ()) to @escaping @callee_guaranteed (@guaranteed NIO.NIOThread) -> () at <compiler-generated>, callback=0x0000555555c423c0 ModelApp`partial apply forwarder for closure #1 (NIO.SelectableEventLoop) -> () in closure #1 (NIO.NIOThread) -> () in static NIO.MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name: Swift.String, selectorFactory: () throws -> NIO.Selector<NIO.NIORegistration>, initializer: (NIO.NIOThread) -> ()) -> NIO.SelectableEventLoop at <compiler-generated>, self=NIO.MultiThreadedEventLoopGroup) at EventLoop.swift:824:22
    frame #23: 0x0000555555c3bfdf ModelApp`closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(t=0x00007ffed4000b20, selectorFactory=0x0000555555c3c370 ModelApp`implicit closure #1 () throws -> NIO.Selector<NIO.NIORegistration> in NIO.MultiThreadedEventLoopGroup.init(numberOfThreads: Swift.Int) -> NIO.MultiThreadedEventLoopGroup at EventLoop.swift, initializer=0x0000555555c42240 ModelApp`partial apply forwarder for reabstraction thunk helper from @escaping @callee_guaranteed (@in_guaranteed NIO.NIOThread) -> (@out ()) to @escaping @callee_guaranteed (@guaranteed NIO.NIOThread) -> () at <compiler-generated>, lock=(mutex = 0x0000555557a68d50), _loop=0x00007ffed4001000, loopUpAndRunningGroup=0x0000555557a68d80) at EventLoop.swift:844:41
    frame #24: 0x0000555555c42333 ModelApp`partial apply for closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:selectorFactory:initializer:) at <compiler-generated>:0
    frame #25: 0x0000555555c3c5ff ModelApp`thunk for @escaping @callee_guaranteed (@guaranteed NIOThread) -> () at <compiler-generated>:0
    frame #26: 0x0000555555d1b5f1 ModelApp`partial apply for thunk for @escaping @callee_guaranteed (@guaranteed NIOThread) -> () at <compiler-generated>:0
    frame #27: 0x0000555555d1eacc ModelApp`closure #1 in static ThreadOpsPosix.run($0=(_rawValue = 0x0000555557a68e90)) at ThreadPosix.swift:105:13
    frame #28: 0x0000555555d1ec69 ModelApp`@objc closure #1 in static ThreadOpsPosix.run(handle:args:detachThread:) at <compiler-generated>:0
    frame #29: 0x00007ffff75ba6db libpthread.so.0`start_thread + 219
    frame #30: 0x00007fffad712a3f libc.so.6`clone + 63

So, it looks like Foundation is creating the DateFormatter each time my project receives some data over the network and decodes it into an object. The MyData.swift:163 it's referencing is this code:

    func updatesCallback(type: MyType) -> (([Update]) -> Void) {
        return { updates in
            let LinkedList = self.updates[type]!
            // The below if statement and for loop entire code block are a debug check to see how often the lack of
            //  FIFO guarantee on async dispatch queues causes old data to be inserted after new data
            if LinkedList.count > 0 && updates.count > 0 {
                for update in updates {
                    let topUpdate = linkedList.suffix(1)![0]
                    let errorText = """
                    Expected FIFO execution of async dispatch queues, but found historical data being inserted onto \
                    linked list. Top of linked list has time \(update.time) \
                    (\(update.timeDouble)), \
                    while inserted update with time \(topUpdate.time) (\(topUpdate.timeDouble))
                    """
                    if topUpdate.time > update.time {
                        self.logger.error(Logger.Message(stringLiteral: errorText))
                        assertionFailure(errorText)
                    }
                }
            }
            linkedList.append(contentsOf: updates)
        }
    }

linked list. Top of linked list has time \(update.time) \ is line 163.

So Foundation is creating a DateFormatter to put the object's Date into the String. I wrote this as a debug clause to test if the lack of FIFO guarantee in dispatch asyncs actually leads to out-of-order data. (It never has). Notice that the errorText is being created even when the the error condition is not met. When I move it inside the if topUpdate.time > update.time, the retain issue completely goes away! :partying_face: I ran for 20+ minutes and never saw any object reach a retain >10000.

So, the compiler bug case appears to be this:

  • Each time data is received over the network, JSON decode it into Update objects that contain Date properties.
  • Call a partially evaluated callback function (like func updatesCallback(type: MyType) -> (([Update]) -> Void)) with every Update.
  • In this function, put the Update's Date property into a string: let string = "\(update.date)". Then do nothing with the variable string.

This is the case causing the retain accretion. Thanks very much @Joe_Groff and @lukasa for teaching me the tools necessary to track this down. Simply by creating an object only when it's actually used I've solved this issue for myself for the time being, but it is a complier bug. I will attempt to provide enough information in the bug report to help the team fix it.

11 Likes