Frame Processing order |
|||
Issue descriptionI ran into the following behavior for frame submission: Frame A arrives in OnBeginFrame Frame B arrives in OnBeginFrame Frame B ends in DidNotProduceFrame through Scheduler::SendBeginFrameAck Frame A ends in SubmitCompositorFrame Is it a bug that Frame A and B are processed at different order as they arrive? More info: experiment cl: https://chromium-review.googlesource.com/c/chromium/src/+/1159167 observed crash in: https://chromium-review.googlesource.com/c/chromium/src/+/1159167/14 && https://chromium-review.googlesource.com/c/chromium/src/+/1159167/13 Log: [204030:204030:0906/172501.691866:ERROR:async_layer_tree_frame_sink.cc(263)] ++++++++++++++++++++4294967361 [204030:204030:0906/172501.691941:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.692059:ERROR:async_layer_tree_frame_sink.cc(263)] ++++++++++++++++++++4294967362 [204030:204030:0906/172501.692115:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 4294967361 [204030:204030:0906/172501.692155:ERROR:async_layer_tree_frame_sink.cc(221)] ------------------------actual: 4294967361 [204030:204030:0906/172501.692199:ERROR:async_layer_tree_frame_sink.cc(222)] ------------------------we think: 4294967360 [204030:204030:0906/172501.692306:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.692399:ERROR:async_layer_tree_frame_sink.cc(263)] ++++++++++++++++++++4294967363 [204030:204030:0906/172501.692455:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 4294967362 [204030:204030:0906/172501.692491:ERROR:async_layer_tree_frame_sink.cc(221)] ------------------------actual: 4294967362 [204030:204030:0906/172501.692527:ERROR:async_layer_tree_frame_sink.cc(222)] ------------------------we think: 4294967361 [204030:204030:0906/172501.692625:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.692724:ERROR:async_layer_tree_frame_sink.cc(263)] ++++++++++++++++++++4294967364 [204030:204030:0906/172501.692781:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 4294967363 [204030:204030:0906/172501.692818:ERROR:async_layer_tree_frame_sink.cc(221)] ------------------------actual: 4294967363 [204030:204030:0906/172501.692862:ERROR:async_layer_tree_frame_sink.cc(222)] ------------------------we think: 4294967362 [204030:204030:0906/172501.692986:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.693954:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.694099:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.694328:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.694462:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.694529:ERROR:scheduler.cc(759)] process scheduled action: 4294967360 [204030:204030:0906/172501.696092:ERROR:async_layer_tree_frame_sink.cc(157)] ------------------------4294967360 [204030:204030:0906/172501.696157:ERROR:async_layer_tree_frame_sink.cc(159)] trace_id is different: 4294967363 : 4294967360 [204030:204030:0906/172501.696204:ERROR:async_layer_tree_frame_sink.cc(160)] client_name: Browser
,
Sep 10
I have very similar assumption. @fsamuel suggested to do the following: 1. Compositor thread is busy 2. BeginFrame A arrives 3. BeginFrame B arrives 4. Compositor thread wakes 5. Compositor thread starts BeginFrame A 6. Set BeginFrame B to Abort state and do not process the abortion. 7. Compositor thread sends a frame for A. 8. Abort BeginFrame B. What do you think?
,
Sep 10
Stepping back a bit, what is the problem with sending the ack for B immediately?
,
Sep 10
I suppose maybe there's nothing wrong assuming Viz can handle out of order ACKs. Certainly, I was under the impression that with the introduction of BeginFrameAcks, that the following statements are true: 1. For every BeginFrame, there is one and only one BeginFrameAck via SubmitCompositorFrame or DidNotProduceFrame. 2. BeginFrameAcks get sent back to Viz in order. Is it worth making these invariants true if they're not already true? Measuring the graphics pipeline becomes a bit trickier because we only care about BeginFrames that have corresponding CompositorFrames, but we need to track BeginFrames in any order (can't necessarily use a queue). Maybe we should just use a flat_map then?
,
Sep 10
What are we tracking state-wise in the browser? Could we reconstruct it from what the renderer sends?
,
Sep 10
Do we process a BeginFrame that is past its deadline? I don't understand why cc starts working on BeginFrame A instead of discarding it.
,
Sep 10
,
Sep 10
I just found another bug: DidNotProduceFrame may issue twice for the same frame from function Scheduler::SendBeginFrameAck. patch: https://chromium-review.googlesource.com/c/chromium/src/+/1159167/16 output: [246217:246217:0910/163328.223497:ERROR:async_layer_tree_frame_sink.cc(256)] adding...: 4294967336 [246217:246217:0910/163328.223598:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 4294967336 [246217:246217:0910/163328.223665:ERROR:async_layer_tree_frame_sink.cc(217)] Removing...: 4294967336 [246217:246217:0910/163328.231173:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 4294967335 [246217:246217:0910/163328.231243:ERROR:async_layer_tree_frame_sink.cc(217)] Removing...: 4294967335 [1:8:0910/163328.233322:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 1407387768455188 [1:8:0910/163328.233523:ERROR:async_layer_tree_frame_sink.cc(217)] Removing...: 1407387768455188 [1:8:0910/163328.233869:ERROR:async_layer_tree_frame_sink.cc(256)] adding...: 1407387768455189 [1:8:0910/163328.250055:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 1407387768455189 [1:8:0910/163328.250373:ERROR:async_layer_tree_frame_sink.cc(217)] Removing...: 1407387768455189 [1:8:0910/163328.250740:ERROR:async_layer_tree_frame_sink.cc(256)] adding...: 1407387768455190 [246217:246217:0910/163328.264028:ERROR:async_layer_tree_frame_sink.cc(256)] adding...: 4294967337 [246217:246217:0910/163328.264164:ERROR:scheduler.cc(565)] go to Scheduler::SendBeginFrameAck: 4294967336 [246217:246217:0910/163328.264233:ERROR:async_layer_tree_frame_sink.cc(217)] Removing...: 4294967336
,
Sep 10
Frame 4294967336 is the one get to DidNotProduceFrame twice.
,
Sep 10
This is icky. Ideally we'd ACK once and ACKs would be sent in the order BeginFrames arrive but that is not the case. The BeginFrame protocol is more complicated than I initially thought. :(
,
Sep 13
I don't think i will fix this, removing myself from the owner. |
|||
►
Sign in to add a comment |
|||
Comment 1 by danakj@chromium.org
, Sep 10