Details
-
Type:
Defect
-
Status:
Open
-
Priority:
Major
-
Resolution: Unresolved
-
Affects Version/s: None
-
Fix Version/s: None
-
Component/s: None
-
Labels:None
Description
Hi all, bit of a tricky bug to report here... We're seeing some problems with using core.async in ClojureScript on Safari 7. Our application is built around a large event loop that blocks on a message from one of many channels that correspond to user activity or API calls. The problem seems to lie within this event loop - we are using alts! to pull a message out of any available channel, but sometimes logging shows that we reach alts! and never unblock. However, with a little more logging, I can see that there are subsequent writes to one of the channels in the list of channels passed to alts!, so I'm not really sure what's going on.
That's the high level overview, now on to some code.
Our main event loop is as follows:
(log "Entering main event loop.") (go (while true (log "alts! channel hashes: " (map hash (:channels @app))) (let [[message channel] (alts! (seq (:channels @app)))] (log "alts! unblocked, calling our process-message") (swap! app process-message message channel) (log "process-message completed, looping"))))
process-message here is our a function internal to our application, but I don't think it's details are necessarily important. In the scenario where Safari gets stuck, the log looks like:
[Log] process-message completed, looping (main.js, line 62)
[Log] alts! channel hashes: (16 12 19 33) (main.js, line 82)
[Log] Socket connected. (socket.js, line 309)
[Log] put! to channel with hash 19 (socket.js, line 86)
[Log] The message is [:metronome [:staff [{:description nil, :deletable true, :email nil, :isAdmin true, :isTrainer false, :telephone nil, :name "Fynder Admin", :picture nil, :userId 1} {:description nil, :deletable fa... (socket.js, line 87)
[Log] put! callback gave us true (socket.js, line 89)
[Debug] Metronome: staff data decoded. put! complete.: 12.282ms (socket.js, line 93)
[Log] put! to channel with hash 19 (socket.js, line 86)
[Log] The message is [:metronome [:class-types [{:deletable false, :picture nil, :name "CycleCore", :id 2, :description "CycleCore is a 55-minute dual workout concept that combines 30 minutes of intense cardiovascular ... (socket.js, line 87)
[Log] put! callback gave us true (socket.js, line 89)
[Debug] Metronome: class-types data decoded. put! complete.: 1.288ms (socket.js, line 93)
[Log] put! to channel with hash 19 (socket.js, line 86)
[Log] The message is [:metronome [:locations [{:studios [{:deletable false, :name "Kensington", :id 1, :locationId 1, :description "Studio (11a) sits just off Stratford Road in Stratford Studios. To find us, just pass ... (socket.js, line 87)
[Debug] Metronome: locations data decoded. put! complete.: 0.884ms (socket.js, line 93)
Note that we see a log entry for "alts! channel hashes", but we never seen "alts! unblocked". However, note the list of hashes passed to alts!. Channel 19 is mentioned, but subsequently we put! to channel 19... yet we still don't get unblocked. Something that also strikes me as suspicious, is that while we're blocked at alts!, two calls to put! have succeeded immediately, for a channel that is bounded to contain only one element at a time. Maybe I'm misunderstanding something, but I wouldn't expect the immediate-put callback to be invoked more than once. Interestingly that last put! doesn't invoke the callback.
Unfortunately, reproduction of this bug is reasonably difficult. I can somewhat reliably reproduce it by quitting Safari, re-opening it, and navigating to the dev server. About 1 in 15 attempts get stuck in this fashion. I wondered if it was something to do with Safari's MessageChannel implementation - you can see in the log entries where nexttick.js calls its callback, which seems to be how dispatch is working in my browser.
I'd be very happy to help provide any more information that's useful, but this problem is now outside my ability to debug it. While the code is proprietary, I'd be happy to temporarily add people to the Github project in order to try and get this fixed. We have development APIs servers that you can point at, so it should be just a case of running lein cljs.
I've attached our code for our Socket.io wrapper and our main event loop. Sadly I do not yet have a minimal test-case - I wouldn't really know where to begin.
I went deep into the guts of the Google Closure library and changed getSetImmediateEmulator_ to:
goog.async.nextTick.getSetImmediateEmulator_ = function() { // Fall back to setTimeout with 0. In browsers this creates a delay of 5ms // or more. return function(cb) { goog.global.setTimeout(cb, 0); }; };and I haven't been able to get it stuck. So maybe MessageChannel has problems in Safari...
goog.async.nextTick.getSetImmediateEmulator_ = function() { // Fall back to setTimeout with 0. In browsers this creates a delay of 5ms // or more. return function(cb) { goog.global.setTimeout(cb, 0); }; };