930926 - First composite after idle can take 40ms

Status: RESOLVED WORKSFORME

(Core :: Graphics, defect, P1)

Description

[Benoit Girard (:BenWa)]

Attachment: Screenshot

I can reproduce this fairly consistently with the hamachi device. When profiling the homescreen after being idle the first composite can take 40ms and causes us to miss 3 frames significantly increasing time to the touch response. All the sub-sequent composites are fast.

http://people.mozilla.org/~bgirard/cleopatra/#report=1a16c320066e2be47f40d07f2c6eb96f3f30a2de

This profile shows the problem at the start. Notice the first blue composite is really slow compared to the rest. It appears the time is spent in a syscall that can't be interrupted by a signal so we're unable to profile it so I don't know where it's at.

Perhaps this has to do with a low power mode optimization that it has to wake up from?

If that's the case Bas suggest we could ask the compositor to wake up the GPU while the main thread is preparing the first frame. This would cut down our latency by about 3 frames (40ms). But we need to confirm that this is the problem first.

Comment 1

[Benoit Girard (:BenWa)]

Milan do we have a contact that could clarify this? It would certainly shortcut having to manually debug this which I suspect will be difficult since it might be in a syscall.

Comment 2

[Benoit Girard (:BenWa)]

(In reply to Benoit Girard (:BenWa) from comment #0)
> This would cut down
> our latency by about 3 frames (40ms).

Actually down by 2 frames*, we still need to wait for vsync for the frame.

Comment 3

[Milan Sreckovic [:milan] (needinfo for best results)]

(In reply to Benoit Girard (:BenWa) from comment #0)
> ...
> 
> Perhaps this has to do with a low power mode optimization that it has to
> wake up from?

Michael, who can help us get an answer to this?

Comment 4

[Michael Vines [:m1] [:evilmachines]]

Vikram -- could you please take a look at this?

:BenWa -- Is Hwc or GPU composition being used here?  Have you observed any difference between the two?

Comment 5

[Benoit Girard (:BenWa)]

I have HWC displated (to always have the FPS counter). This is with GPU.

Comment 6

[Michael Vines [:m1] [:evilmachines]]

Can you please try with Hwc too?  FPS counter for Hwc is in logcat.

Comment 7

[Benoit Girard (:BenWa)]

It's also there :(

Comment 8

[Michael Vines [:m1] [:evilmachines]]

That's actually helpful.  If we're using Hwc for compositing, and assuming there's no GPU usage during the render then sounds like it's something else and not simply the GPU spinning up slowly.

Comment 9

[Mandyam Vikram]

Will take a look.

Can you please describe the exact scenario? Is it initiating a scroll of the applist while the phone is idle? Usually, GPU is used to scroll "to" the first page of the apps but scrolling between subsequent app pages uses HWC.

Comment 10

[Benoit Girard (:BenWa)]

Turn off screen lock/ autodisable
idle at home screen for some duration (time while I run profile.sh) maybe 2 mins
start home screen swipe
compositor thread will block and mask profiling signal. easy to reproduce on Hamachi.

Comment 11

[Mandyam Vikram]

What I observe profiling it on my own is that when the device is idle and a scroll is initiated, the first couple of frames are rendered via HWC. The third frame is rendered by the GPU and, I do see that the GPU takes about 35 ms to "wake up" causing the first frame's "Render" function to take about 45 msecs. Subsequent Render calls take about 20 ms, but these don't seem to be content bound.
So, waking up the GPU ahead of time of the first GPU frame to be rendered in theory would address this situation. 
However, the Compositor needs to determine if the layers are compatible to be rendered by HWC which happens only when the TryRender() function is called within the rendering of the layers themselves. We ought to be careful to not wake up the GPU if the layers are going to be composed by HWC as this would cause unnecessary power consumption.
BTW, how do I zoom in and expand on the Cleopatra UI trace to get more detail on the attachment to describe the problem that you describe? I can't seem to be able to zoo in especially on the Frames.

Comment 12

[Benoit Girard (:BenWa)]

(In reply to Mandyam Vikram from comment #11)
> However, the Compositor needs to determine if the layers are compatible to
> be rendered by HWC which happens only when the TryRender() function is
> called within the rendering of the layers themselves. We ought to be careful
> to not wake up the GPU if the layers are going to be composed by HWC as this
> would cause unnecessary power consumption.

Or perhaps we can ask our contacts why the GPU wakeup takes this long. Perhaps it just hasn't been optimized very much yet or we're hitting a slow path.


> BTW, how do I zoom in and expand on the Cleopatra UI trace to get more
> detail on the attachment to describe the problem that you describe? I can't
> seem to be able to zoo in especially on the Frames.

Select a range in a thread histogram (not the frame view) by dragging the gray selection. Then a breadcrumb will appear in the top middle/left, click on that.

Comment 13

[Mandyam Vikram]

This issue has been resolved in our Adreno driver for 1.4 KK.

Comment 14

[Mike Lee [:mlee]]

Bhavana,

Does Vikram's comment 13 mean this bug should be whiteboard-tagged [POVB] and RESOLVED FIXED?

Thanks,
Mike

Comment 15

[bhavana bajaj [:bajaj]]

(In reply to Mike Lee [:mlee] from comment #14)
> Bhavana,
> 
> Does Vikram's comment 13 mean this bug should be whiteboard-tagged [POVB]
> and RESOLVED FIXED?
> 
> Thanks,
> Mike

POVB and resolved WFM.