Not connecting to RPC server in release mode, but works fine in debug mode

I have a command line app that does the following:

  • downloads an RSS feed with torrent links
  • stores it in a sqlite database and tags them as "added" or "ignored"
  • connects to a transmission server (in my local network)
  • loads items from sqlite marked as "added" and adds to transmission server

The above works fine in debug mode. However, when I build for release and try to run directly or from launchd, it always times out. The most relevant code is in main.swift which goes below.

private func getTransmissionClient() -> Transmission? {
        let client = Transmission(
            baseURL: serverConfig.server,
            username: serverConfig.username,
            password: serverConfig.password)

        var cancellables = Set<AnyCancellable>()

        let group = DispatchGroup()
        group.enter()
        print("[INFO] Connecting to client")
        client.request(.rpcVersion)
            .sink(
                receiveCompletion: { _ in group.leave() },
                receiveValue: { rpcVersion in
                    print("[INFO]: Successfully Connected! RPC Version: \(rpcVersion)")
            })
            .store(in: &cancellables)
        let wallTimeout = DispatchWallTime.now() +
            DispatchTimeInterval.seconds(serverConfig.secondsTimeout ?? 15)
        let res = group.wait(wallTimeout: wallTimeout)

        if res == DispatchTimeoutResult.success {
            return client
        } else {
            return nil
        }

    }

    public func updateTransmission() throws {

        print("[INFO] [\(Date())] Starting Transmission Update")

        let clientOpt = getTransmissionClient()
        guard let client = clientOpt else {
            print("[ERROR] Failed to connect to transmission client")
            exit(1)
        }

        var cancellables = Set<AnyCancellable>()

        let items = try store.getPendingDownload()
        print("[INFO] [\(Date())] Adding \(items.count) new items to transmission")

        let group = DispatchGroup()
        for item in items {

            let linkComponents = "\(item.link)".components(separatedBy: "&")
            assert(linkComponents.count > 0, "Link seems wrong")

            group.enter()
            client.request(.add(url: item.link))
                .sink(receiveCompletion: { completion in
                    if case let .failure(error) = completion {
                        print("[Failure] \(item.title)")
                        print("[Failure] Details: \(error)")

                    }
                    group.leave()
                }, receiveValue: { _ in
                    print("[Success] \(item.title)")
                    do {
                        try self.store.update(item: item, with: .downloaded)

                    } catch {
                        print("[Error] Couldn't save new status to DB")
                    }
                })
                .store(in: &cancellables)
        }


        let wallTimeout = DispatchWallTime.now() +
            DispatchTimeInterval.seconds(serverConfig.secondsTimeout ?? 15)
        let res = group.wait(wallTimeout: wallTimeout)
        if res == DispatchTimeoutResult.success {
            print("Tasks successfully submitted")
        } else {
            print("Timed out")
            exit(1)
        }
    }

Oddly enough, the code seemed to work fine before I added the database. The DispatchGroup was already there, as well as the Transmission-Swift client. I guess something that I did is being "optimized away" by the compiler? This is just speculation though after seeing some other questions on StackOverflow, but I am still not clear on it.

I am using macOS 10.15 and Swift 5.2.2.

  • Full code available in github (link to specific commit that has the bug).
  • I have also posted this earlier on StackOverflow, as I didn't know about this forum.

It’s hard to offer debugging advice here without knowing more about what’s going wrong. You wrote:

when I build for release and try to run directly or from launchd, it
always times out.

To start, you should tease apart these cases:

  • If you run a Release build in the debugger, does it work?

  • If you run a Debug build as a launchd job, does it work?

That will tell you whether it’s a problem with the build or a problem with the environment.

Next, I recommend that you look in to os_log. Debugging with print is fine when you’re running from Xcode, but doesn’t help when you run in weird environments like a launchd job. To set this up:

  1. Import os.log.

  2. Create your own log handle. For simplicity, you can just stash this in a global variable

  3. Log using os_log. For example:

     import os.log
    
     let log = OSLog(subsystem: "com.example.apple-samplecode.Test36251", category: "main")
    
     os_log(.debug, log: log, "did %{public}@ with %@", "something", 1)
    

    Change the subsystem to be something more appropriate to your product.

  4. Use Console to view your logging. Specifically, make sure that both Action > Include Info Messages and Action > Include Debug Messages are checked, then paste subsystem:com.example.apple-samplecode.Test36251 into the search box.

Share and Enjoy

Quinn “The Eskimo!” @ DTS @ Apple

Hi @eskimo, thanks for your reply!

Indeed some clarity is missing. Regarding your questions:
Question 1)

I tried this, but it actually didn’t compile complaining the tests were not suited for release. I found it weird because I was trying to run the executable, which does not depends on the tests sub-project. I didn’t investigate it further. Do you think it is worth running Release in the debugger? I was not sure if this was possible when I got that problem.

Question 2)

Yes, it does. The Debug build works fine when I run on my user on the command line, or even on launchd. That’s why I was thinking it was a problem with the build.

Os_log) Thanks for the recommendation on os.log, I will try to update it soon. One thing though: I didn’t try debugging the programming running on launchd. I managed to reproduce the bug without launchd, running on the command line with the same arguments as when I ran from Xcode, except that it was a release mode.

So if the Debug build runs from launchd and the Release build reproduces the problem from Terminal I think it’s safe to conclude that this is a Debug / Release problem, not a launchd environment problem.

I’ve seen plenty of Debug / Release problems before, including a subset with similar symptoms to what you’ve described here (where async work simply doesn’t happen). In my experience the most common cause is that the async work is being done on behalf of some object and, if you release the object, the async works cancels. The Debug and Release builds have very different retain and release patterns, with the Release build generally being more aggressive. So, imagine you have code like this:

let obj = SomeAsyncWork(…)
obj.completionHandle = {
    … signal completion …
}
obj.start()
… wait for completion …

This can fail on Release builds because obj is no longer referenced after line 5 so the compiler releases it before line 6, and releasing obj cancels the async operation.

I should stress that this isn’t the only cause of such problems, just one that I’ve seen a bunch of times.

I generally tackle these problems by setting a breakpoint (or adding a log entry) in the async operation’s deinitialiser, to make sure it’s not being deallocated early.

Share and Enjoy

Quinn “The Eskimo!” @ DTS @ Apple

1 Like

@eskimo I believe the problem is solved now! Thanks so much!

After reading your message I started looking at my functions to see if some object could be the culprit. Most of the items I was working on were structs in fact, so I left analysing them for later. The only class I found was a Set<AnyCancellable>. I was actually not using it for anything besides storing the Combine subscription as I saw in some examples. I updated my code in the following fashion:

diff --git a/Sources/TorrentRSS/TorrentRSS.swift b/Sources/TorrentRSS/TorrentRSS.swift
index 17e1a6b..0b80cd5 100644
--- a/Sources/TorrentRSS/TorrentRSS.swift
+++ b/Sources/TorrentRSS/TorrentRSS.swift
@@ -63,6 +63,10 @@ public struct TorrentRSS {
             DispatchTimeInterval.seconds(serverConfig.secondsTimeout ?? 15)
         let res = group.wait(wallTimeout: wallTimeout)

+        for cancellable in cancellables {
+            cancellable.cancel()
+        }
+
         if res == DispatchTimeoutResult.success {
             return client
         } else {
@@ -117,6 +121,11 @@ public struct TorrentRSS {
         let wallTimeout = DispatchWallTime.now() +
             DispatchTimeInterval.seconds(serverConfig.secondsTimeout ?? 15)
         let res = group.wait(wallTimeout: wallTimeout)
+
+        for cancellable in cancellables {
+            cancellable.cancel()
+        }
+
         if res == DispatchTimeoutResult.success {
             print("Tasks successfully submitted")
         } else

And now release mode works! Many thanks!