Make :async feature awesome

[darwin]

This is a placeholder issue for people who want to track the progress of this experimental feature.

The announcement from Slack:

Hi, just wanted to share with you a half-baked idea which enables long stack traces for core.async in ClojureScript:
You can get this[1] instead of this[2]:
[1] https://dl.dropboxusercontent.com/u/559047/core-async-long-stack-traces.png
[2] https://dl.dropboxusercontent.com/u/559047/core-async-normal-traces.png
The trick is to replace goog.async.nextTick with a promise-based implementation. ES6 promises participate in Chrome DevTools “async” feature. it is not super useful ATM, because maxAsyncStackChainDepth is currently hard-coded in DevTools and set to only 4, which is not enough for more complex core.async code:
https://github.com/binaryage/dirac/blob/devtools/front_end/sdk/DebuggerModel.js#L200
but in Dirac I can lift that number and maybe walk the call stack in a better way, so loops won’t create long stack traces

here is the implementation if anyone interested: 86dbbbb

here is an upstream proposal how to handle long async-task chains generated by core.async:
https://bugs.chromium.org/p/chromium/issues/detail?id=622506

[danielcompton]

We ran into an obscure bug because of the :async feature. The nut of the issue is that the :async feature swaps goog.nextTick which schedules tasks, for a promise based mechanism which schedules microtasks. For interested readers, see Tasks, microtasks, queues, and schedules for more info on tasks and microtasks.

We were trying to schedule CPU intensive work to occur after an animation frame (task) had finished. goog.nextTick schedules a task to run after the frame has finished (and rendered), but the promise based implementation scheduled the work as a microtask. The microtask runs in the same task as the animation frame, therefore delaying rendering of the animation frame until the CPU intensive work has finished.

The docstring for nexttick says:

Fires the provided callbacks as soon as possible after the current JS execution context. setTimeout(…, 0) takes at least 4ms when called from within another setTimeout(…, 0) for legacy reasons.
This will not schedule the callback as a microtask (i.e. a task that can preempt user input or networking callbacks). It is meant to emulate what setTimeout(_, 0) would do if it were not throttled. If you desire microtask behavior, use {@see goog.Promise} instead.

I know that :async is experimental, but I wonder if a promise-based approach is sound, as it can subtly and confusingly change the behaviour of an app? Alternatively, should the :async monkeypatch be more tightly scoped to affect the behaviour of core.async go loops, and not other code which calls nexttick directly?

[mike-thompson-day8]

Just to add to what @danielcompton reported ... the development version of our app showed a bug (because it was using the patched goog.next.tick) whereas the production build did not. Which was utterly baffling. It took some luck and a lot of time looking at Chrome devtools' flame charts to figure it out.

But in some sense we were lucky. If this patch was masking a bug at dev time (instead of causing one at dev time), that would have been worse because you have much less chance of debugging optimised (production) code.

I would suggest that this :async feature should be, by default, turned off. Then someone can choose to explicitly turn it on, after having read the implications.

Edit: Hmm. I guess I mean it should be harder to include accidentally (eg: via :all). Make its inclusion a more deliberate action, which encourages more reading and understanding.

[darwin]

I'm sorry to hear about the problems it caused. Thanks for sharing your experience.

Alternatively, should the :async monkeypatch be more tightly scoped to affect the behaviour of core.async go loops, and not other code which calls nexttick directly?

This :async thing should be general, not only core.async specific. So I wanted to apply it globally. Also people could run into these timing issues with core.async alone.

Do you think a fix for this issue would be to use original goog.nextTick inside my promise? So I would resolve the promise after waiting for next tick internally. This way we would get original timing profile, but still devtools would display async callstack chain.

[danielcompton]

Do you think a fix for this issue would be to use original goog.nextTick inside my promise? So I would resolve the promise after waiting for next tick internally. This way we would get original timing profile, but still devtools would display async callstack chain.

That sounds possible. We can test that against our internal app to see if that fixes the problem. My understanding of how it would work would be:

1. run nexttick
2. create a promise
3. schedule the promise to be resolved with the real nexttick
4. nexttick fires, promise is resolved, scheduling a microtask
5. JS VM runs outstanding microtasks, executing the promise's "then" function

As long as the promise was resolved in a separate task (triggered by the original nexttick), I think that should work. However, I'm still a little bit cautious about this feature for re-frame apps, as it is quite sensitive to the behaviour of the JS task queue.

[darwin]

I tried a few experiments and I cannot make it to work.

As soon as I introduce goog.async.nextTick.getSetImmediateEmulator_ as a waiting step to get proper timing the devtools loses track of that "thread" of async calls.

[darwin]

I think we will have to wait for chrome devs to add proper support for postMessage/onmessage and treat them as async operations. At that point this :async hack won't be necessary anymore.

https://github.com/google/closure-library/blob/fd043939bde2de4cd0dae9272e3336fbc5f66962/closure/goog/async/nexttick.js#L217

[darwin]

relevant issues in Chromium:
https://bugs.chromium.org/p/chromium/issues/detail?id=272416
https://bugs.chromium.org/p/chromium/issues/detail?id=332624

[danielcompton]

Thanks for your detailed investigation on this :) I'll follow those chrome bugs.

[darwin]

Tracked as a new chromium issue here:
https://bugs.chromium.org/p/chromium/issues/detail?id=661705

[darwin]

FYI: the upstream issue was fixed, the :async feature will be removed from cljs-devtools eventually

https://bugs.chromium.org/p/chromium/issues/detail?id=661705

[dijonkitchen]

Should the :async feature be removed along with the console.log since most people are on Chrome 65+ now? https://caniuse.com/usage-table

[darwin]

The :async feature is disabled by default. I don't see any harm leaving it there as is. Removing it could force some people who have it enabled to revisit this issue or maybe silently affect behaviour of their code.