[SR-13628] Deadlock when using the print function

[swift-ci]

Previous ID	SR-13628
Radar	rdar://problem/69750351
Original Reporter	Peter_Schorn (JIRA User)
Type	Bug

Environment

MacBook Pro late 2013. macOS Catalina 10.15.6 Swift 5.3

Additional Detail from JIRA

| | | |------------------|-----------------| |Votes | 0 | |Component/s | | |Labels | Bug | |Assignee | None | |Priority | Medium | md5: fb6f9bef31cb1091796bc335465ed993

Issue Description:

I found this really strange bug in which the print function causes a deadlock when called within a dispatch queue.

The deadlock occurs at the line

print("AuthorizationManager.description: BEFORE queue")

in AuthorizationManager.description, which is indirectly called by

print(self)

Intriguingly, changing the above line to any of the following prevents the deadlock:

 print(self.description)
 print("\(self)")
 print(self, to: &self.someString)

Furthermore, removing the line

print("Refreshing")

also prevents the deadlock.

I suspect that this bug is related to the fact that the print function is synchronized.

I also tested out other locking mechanisms instead of DispatchQueue, including NSLock, NSRecursiveLock and even this fancy implementation from swift-log, and I experienced the exact same bug.

I posted this issue on the swift forums, and a commenter summarized the cause of the bug as follows:

So I found that for a dead lock to happen, you need to repeatedly and concurrently do the following:

1. You run a block in dispatchQueue,

2. The block prints anything [In this case it is the line `print("Refreshing")`],

3. The block runs print(X) on a separated concurrent queue, where

   • X is CustomStringConvertible that uses dispatchQueue inside description.

Here is the code that causes the issue:

import Foundation

class AuthorizationManager: CustomStringConvertible {

    let dispatchQueue = DispatchQueue(label: "AuthorizationManager")

    var description: String {
        print("AuthorizationManager.description: BEFORE queue")
        // MARK: - Deadlock Occurs Here -
        return dispatchQueue.sync {
            print("AuthorizationManager.description: INSIDE queue")
            return "I am an authorization manager"
        }
    }

    func refreshTokens() {
        dispatchQueue.sync {
            print("Refreshing")
        }
        DispatchQueue.global().async {
            print(self)

        }
    }

}

/// Entry Point.
func testDeadlock2() {

    let authorizationManager = AuthorizationManager()

    for i in 0..<100 {
        print(i)
        authorizationManager.refreshTokens()
    }

    print("\n--- Finished ---\n")

}

[typesanitizer]

@swift-ci create

[swift-ci]

Comment by Peter Schorn (JIRA)

theindigamer (JIRA User) So is this definitely a bug then? Or am I doing something wrong?

[typesanitizer]

I think it's a bug. Sorry, my previous comment wasn't meant for you: I was cloning the bug to Radar (Apple's internal bug tracker).

[swift-ci]

Comment by Peter Schorn (JIRA)

I assumed the comment wasn't meant directly for me; I was wondering if it was an indication that this is, in fact, a bug.

[eeckstein]

Peter_Schorn (JIRA User) This is not a bug.
What print does is locking the output stream (stdout) and while the output stream is locked getting the description from the object to print. So if you call print inside the "description" getter it ends up in a deadlock.

the reason why

print(self.description)
print("(self)")

does not dead lock, is that description is retrieved before print is called.

print(self, to: &self.someString)

does not dead lock because it's not printing to Stdout.

[swift-ci]

Comment by Peter Schorn (JIRA)

@eeckstein Then why is it the case that removing the print statements inside the description computed property still does not prevent the deadlock?

[eeckstein]

That's a good question.

[swift-ci]

Comment by Peter Schorn (JIRA)

@eeckstein And let me remind you that using a locking abstraction that allows for recursively taking a lock—such as NSRecursiveLock—does not prevent the deadlock either. So I presume you're just as stumped as I am now?

[eeckstein]

cc kylemacomber (JIRA User)

[swift-ci]

Comment by Peter Schorn (JIRA)

Any updates on this bug? Has anyone discovered the cause?

[eeckstein]

kylemacomber (JIRA User)?

[swift-ci]

Comment by Kyle Macomber (JIRA)

We'll take a look.