gwynne
commented
1 year ago While you are correct that the setter for the pingInterval property does not properly dispatch to the socket's event loop when calling pingAndScheduleNextTimeoutTask(), that does not quite look to be the direct proximate cause of this crash. The backtrace shows that the crash occurs in a call made by the scheduled task, which is explicitly on the event loop. I also can't see anything that pingAndScheduleNextTimeoutTask() does that's sufficiently unsafe to cause the segmentation fault that backtrace is reporting, certainly not on the first line of the method (this suggests that self has become invalid, which shouldn't be possible since the scheduled task should be holding at least one retain on it).
This being said, the logic for handling "locking" in this code has at least three TOCTOU errors I've seen so far. (To be sure, I mean no insult to @0xTim or his efforts to make the code Sendable; this code was already a twisty mess to begin with and Sendable is no picnic to get right. Whole thing should be rewritten as a state machine...) I suspect your fix is changing the timing of something enough to sidestep some race or another. My best guess is the TOCTOU races are allowing reentrant execution of something on multiple threads in a way that defeats the locks, resulting in a crash (although I still can't quite work out exactly what sequence of execution would cause that).
In any event, while your fix is definitely in the correct spirit (and that method should definitely be making that check, even if only as an assertion), I don't think it's actually solving the underlying issue, just hiding it. Off the top of my head, the fixes that are needed include:
- Get rid of the separate
NIOLockedValueBoxes for the three ping-related properties (waitingForPong,scheduledTimeoutTask,_pingInterval); replace those three properties with a little struct of their own (something likestruct AutopingState { var waitingForPong: Bool /* etc */ }), and wrap that entire struct with aNIOLockedValueBox. When the code is appropriately updated for this change, this removes the various races that can occur between checking one property and updating another. - Put the checks of property values and the corresponding updates of those properties within the same locking context - and do this for all locked properties, not just the ping-related ones. For example, this code:
guard !self.waitingForClose.withLockedValue({ $0 }) else { promise?.succeed(()) return } self.waitingForClose.withLockedValue { $0 = true }should look more like this:
let wasAlreadyWaiting = self.waitingForClose.withLockedValue { defer { $0 = true } return $0 } guard !wasAlreadyWaiting else { return promise?.succeed() ?? () } - Speaking of the "close" logic,
waitingForCloseand_closeCodeshould also be part of the same locked value box. - The
scheduledTimeoutTaskshould be canceled and set tonilwhen 1)close()is called, and 2)pingIntervalis set tonil.
I think that covers all the obvious issues I saw so far.
I know this is a lot - if you aren't sure how to tackle it, I'll see if I can do at least some of it this weekend (assuming @0xTim doesn't beat me to it).
koraykoska
I have been guessing in the dark for a while but this seems to fix the crash (see below) that is happening in certain cases. I cannot reproduce them other than extremely heavy load for hours or sometimes days. In general, having ~2000 active Websocket connections with 10 second ping intervals each on 8 different servers generates 1-2 of those crashes per day.
I assumed it was a race condition, which was confirmed by a few people on the Discord as well. These changes seem to fix it, which means I haven't been able to see the crash since.
In general, being in the EventLoop is a good approach anyways, even if I am not sure why there are cases of race conditions.
One idea I had is that setting
pingIntervaltriggers the schedule function, but is not guaranteed to be in the EventLoop. If channel is accessed at the same time from somewhere else the race condition might occur. It's a guess though.Original Crash Report: