You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
// ❗There is no unresolved await, so the body of the promise executes.
128
+
compress(notes); // ⚠️ ~4 seconds
129
+
resolve();
130
+
// function::save()
131
+
stopTimer();
132
+
</x-tq-task>
133
+
<x-tq-task type="browser-paint">
134
+
</x-tq-task>
135
+
</x-tq-container>
136
+
137
+
Here we can see that `stopTimer()` is called in the third task, after `compress()`.
138
+
The last task `browser-paint` is a special task that uses the same queue to give the browser a chance to update
139
+
the UI. The JavaScript tasks are generated and put on the queue as soon as JavaScript hits an unresolved `Promise`.
140
+
The browser never gets a chance to queue a `browser-paint` task in-between, thus the browser UI update is also blocked
141
+
behind the costly task that contains the `compress()` call. This is why the UI freezes.
105
142
106
143
OK... so Perry thinks their best bet is to _no longer_`await` the compression step.
144
+
This _should_ avoid creating a new task off of the first task in the queue above as there is no unresolved `Promise` being `await`ed.
107
145
108
146
<p>
109
147
{% highlight jsx linenos %}
@@ -139,36 +177,38 @@ Wait. The UI is _still frozen_ for 4 seconds.
139
177
140
178
What's up? The reduction in the measured latency is easy to explain - we now stop the timer before the `saveInternal``Promise` is `await`ed, so the time spent inside `saveInternal` is no longer measured. But why is the UI still frozen?
141
179
142
-
TODO(prprabhu) Introduce task queue vs. micro task queue.
143
-
Tip: Leaked promises are scary - you may not measure what you think you measure.
144
-
180
+
Enter, the micro-task queue. I fudged the facts in my description of task queues above. The browser execution model actually contains two nested queues - unresolved JavaScript `Promises` are put in a _micro-task queue_. This entire queue comprises a single task on the _task queue_ we described before. Thus, a _JavaScript execution_ task completes only when all the JavaScript micro-tasks that are put in the queue have completed. Only then can any other task, including the browser UI paint task, can run. Our un`await`ed code looks as follows in the new nested-queues execution model:
// ❗No `await`, so this does not create a new micro-task.
188
+
const result = this.saveInternal(notes);
189
+
// function::saveInternal()
190
+
// ❗`await`, so this creates a new microtask.
191
+
await prepare(notes);
192
+
// ❗But remember that save() does not await anything, so execution continues.
193
+
// function::save()
194
+
stopTimer();
195
+
return result;
157
196
</x-tq-micro-task>
158
197
<x-tq-micro-task>
159
-
async saveInternal(notes) {
160
-
await prepare(notes);
161
-
return new Promise((resolve) => {
162
-
compress(notes);
163
-
resolve();
164
-
});
165
-
}
198
+
// function::saveInternal()
199
+
return new Promise(...)
200
+
// function::saveInternal::Promise
201
+
// ❗There is no unresolved await, so the body of the promise executes.
202
+
compress(notes); // ⚠️ ~4 seconds
203
+
resolve();
166
204
</x-tq-micro-task>
167
205
</x-tq-task>
168
206
<x-tq-task type="browser-paint">
169
207
</x-tq-task>
170
208
</x-tq-container>
171
209
210
+
The first and the last micro-tasks here are most relevant. In the first task, `stopTimer()` is called before
211
+
any of the awaited promises resolve. This is why our latency reporting is broken. In the last micro-task, `compress()` is called, yet again before the browser is able to update the UI. As mentioned above, the JavaScript micro-task queue must be emptied of all posted `Promise`s, even if there is nothing `await`ing them before the next task on the parent task queue can be scheduled. This is why the browser still gets no chance to update the UI before the costly `compress()` operation can complete.
172
212
173
213
You may think that this example is made up and you would never make the mistake of leaking a `Promise` like that if you
174
214
were in Perry's place. Well then, know that this example ain't made up. The sequence of events we're walking through
@@ -203,7 +243,40 @@ We do not expect any difference to the UI freeze bug due to this change. But wha
203
243
204
244
Instead of rising by ~100 milliseconds to account for the extra operation, latency jumps back to over 4 seconds! Somehow... the micro-task that contains the call to `stopTimer()` is now once again running after the micro-task with the call to `compress()`. Let's look at our micro-task queue again to understand why:
// ❗No `await`, so this does not create a new micro-task.
252
+
const result = this.saveInternal(notes);
253
+
// function::saveInternal()
254
+
// ❗`await`, so this creates a new microtask.
255
+
await prepare(notes);
256
+
// ❗But remember that save() does not await anything, so execution continues.
257
+
// function::save()
258
+
// ❗`await`, so this creates a new microtask. save() must now suspend
259
+
await finalize(notes)
260
+
</x-tq-micro-task>
261
+
<x-tq-micro-task>
262
+
// function::saveInternal()
263
+
return new Promise(...)
264
+
// function::saveInternal::Promise
265
+
// ❗There is no unresolved await, so the body of the promise executes.
266
+
compress(notes); // ⚠️ ~4 seconds
267
+
resolve();
268
+
</x-tq-micro-task>
269
+
<x-tq-micro-task>
270
+
// function::save()
271
+
stopTimer()
272
+
return result;
273
+
</x-tq-micro-task>
274
+
</x-tq-task>
275
+
<x-tq-task type="browser-paint">
276
+
</x-tq-task>
277
+
</x-tq-container>
278
+
279
+
The extra `await` point added to `save()` due to the call to `finalize()` led to a new micro-task getting created for the last two statements in the function. Worse, this happened _after_ the micro-task inside `saveIneternal` due to the `await` for `prepare()` was posted. Thus, the costly micro-task posted from `saveInternal()` now once again runs before the last part of `save()` that stops the timer. There is an intricate ordering of the micro-tasks in the micro-task queue that depends on the length of the chain of suspended promises in the code-paths that determines whether `stopTimer()` or `compress()` gets to execute first. As the code evolves, the latency measurement is liable to flip-flop between including the costly computation or missing it.
207
280
208
281
Once again, this situation is not theoretical. A similar change (with several layers of abstractions and interveaning teams involved) was shipped in my production chat app, leading to general confusion and several hours of meeting time getting folks to agree on
209
282
there being a problem in the first place. My situation was even worse: There were two different latency measurements being reported
@@ -251,9 +324,36 @@ My hopes are not high that this will help. Try it out anyways:
251
324
So... mostly the same, but worse? The note now appears immedately on save, but the UI is frozen right after (both the
252
325
timer and the saving animation freeze after the note appears in the list). Creating a new task only moved the costly work
253
326
around. Yes, it did give the browser a chance to paint the screen - once - and that is why the note appeared in the saved
254
-
list. But the 4 second compression operation ran right after and froze the UI all over again:
327
+
list. But the 4 second compression operation ran right after and froze the UI all over again (blocking the second `browser-paint` task below):
0 commit comments