Long RAF execution behavior in Chrome devtools

[ZYandu]

I'm getting a lot of inconsistencies in fps due to requestAnimationFrame calls randomly taking a long time where it doesn't look like there is anything being called inside of it until the tail end of the call. What it does show in the call tree only takes PIXI 1-3ms to flush or update transforms while the RAF call can last anywhere from 8-15ms. The devtools are also showing that the GPU and other threads aren't doing any irregular work when the long RAF call happens. It happens at least 10-20 times within a 30 second Chrome devtools performance recording. Has anyone else experienced this kind of thing before? 

https://imgur.com/a/8Uh8028

[ivan.popelyshev]

I think devtools affects it. Is that the only RAF you have? do you have 1000 setTimeouts by chance?

[ZYandu]

Yes I only have the one RAF and I have 0 setTimeouts in my code ^.^

[ivan.popelyshev]

Congratulations! Now I really dont know what can it be. Except profiler itself.

[ZYandu]

Here's an example of what my game is doing. ^.^ https://www.pixiplayground.com/#/edit/pYTkTrNrzUEica9rRZhpp

I'm even seeing some stuttering in fps in this bare bones example. Although some of it might be the mouse events interactions. ? Any big issues you see?

 

[ZYandu]

Fixed the pixi playground link I think.. ^.^

 

[ivan.popelyshev]

no, its clear

[ZYandu]

Oh you must run it in PIXI 5.1.0

[ZYandu]

If Pixi playground still isn't showing up for you then delete all the code and put this in x)

/*pixi playground consistant transform test*/
var img = document.createElement("img");
img.src = "https://i.postimg.cc/MKDkHyGN/background-Spice.jpg";
img.style.position = "absolute";
img.style.zIndex = -2;
document.body.appendChild(img);

var totalTimePassed = 0;

//webgl renderer
var renderer = new PIXI.Renderer({
    width: window.innerWidth,
    height: window.innerHeight,
    transparent: true
});
document.body.appendChild(renderer.view);

var stage = new PIXI.Container();

var loader = PIXI.Loader.shared;
loader.add('bunny', 'https://pixijs.io/examples/examples/assets/bunny.png')
    .load(startup);

function startup(loader, resources)
{
    var bunnyContainer = new PIXI.Container();
    bunnyContainer.position.set(0,0);

    //make 300 bunny sprites at the edge of the pixi canvas
    for(let i = 0; i < 300; i++){
        var bunny = new PIXI.Sprite(resources["bunny"].texture);
        bunny.visible = false;
        bunny.msUntilStartMoving = i * 1000;
        bunny.anchor.set(0.5);
        bunny.x = renderer.width;
        bunny.y = renderer.height / 2;
        bunnyContainer.addChild(bunny);
    }
    stage.addChild(bunnyContainer);
    
    animate();
}

function animate(delta) {
    requestAnimationFrame(animate);
    
    for(let i = 0; i < stage.children[0].children.length; i++){
        //Once enough time has passed kick the next sprite into moving
        if(stage.children[0].children[i].msUntilStartMoving < delta 
            && stage.children[0].children[i].x >= 0)
        {
            //unhide sprites at the edge to get ready for transforms
            if(stage.children[0].children[i].visible == false){
                stage.children[0].children[i].visible = true;
            }
            //consistantly transform x
            stage.children[0].children[i].x -= 3;
        }
        //once they make it to the left side of the screen, visible false for no transform overhead
        else{
            stage.children[0].children[i].visible = false;
        }
    }
    renderer.render(stage);
}

 

[ivan.popelyshev]

I meant that i dont see problems with your code.

[ZYandu]

Dang... are you seeing any of the visual stutters I mentioned? It still looks like it slips up on my MacBook Pro. Are you using a computer with a nice GPU?

[Exca]

Can you take a profiler dump/screenshot of profiler page of the page running? That could show what is happening. Example runs without problems on win10/chrome with nvidia 1060.

[ivan.popelyshev]

16 minutes ago, Exca said:

Can you take a profiler dump/screenshot of profiler page of the page running? That could show what is happening. Example runs without problems on win10/chrome with nvidia 1060.

screen is in the first post

[Exca]

1 minute ago, ivan.popelyshev said:

screen is in the first post

Oops, should have checked links also

That looks like garbage collection is ran during that frame.

[ivan.popelyshev]

Just now, Exca said:

Oops, should have checked links also

That looks like garbage collection is ran during that frame.

There's nothing to collect in that app

[Exca]

Yeah, but heap size looks like it changes in that frame on the memory graph. So something happens with memory. Though it should have a node with carbage collection if actual gc happens.

@ZYandu Can you take a profile of the posted example when stutter occurs?

[ZYandu]

Sorry I didn't really specify before @Exca, the screenshot in my first post is a part of the profile of my full game which uses the same code setup for consistently moving x values, just with more sprites. ? The moving parts are all the numbers and sprites in the middle section https://imgur.com/a/hhhIavE. I made the PIXI playground example and saw that it was also having some stutters for a much more simple version of my game so I figured it must've been an issue with how I was doing it. ^.^ Here's some more profile data on the pixi playground example to try and see similar issues! ?

30 second profile #1:

As Exca mentioned, I am seeing major GC happening a few times in the beginning of the example and then it stabilizes.

Longest major gc: https://imgur.com/a/LDklp5o 

4 main gc in beginning 25 seconds https://imgur.com/a/ODOoCL0

 

30 second profile #2:

I got something similar to what I see in my game, where the request animation frame seems to take up a lot of time (19.62 ms) without really doing anything. https://imgur.com/a/UARFcMb

I've seen both of these types of slowdowns in my game too, any advice? ?

Thank you!

[ivan.popelyshev]

I have no idea

[Exca]

Very mysterious indeed. Especially the second animation frame delay. Do you have lots of console.logs? Though if that was the case, then the problem would disappear when dev tools is closed (at least on windows).

[ZYandu]

I don't have any console.logs in my Pixi playground example if you look again. ?Thanks, yes the second animation frame delay is really what gets my game the most! ?

https://www.pixiplayground.com/#/edit/pYTkTrNrzUEica9rRZhpp

[Exca]

I think the first few GC's are something related to loading of the pixi playground as those I can get too. After the GCs though the rendering continues without a problem.

For some reason I cant upload a screenshot of the profiler. But here's a link to my profiling: https://imgur.com/wtTMvqX

Do you have some plugins installed?

[ZYandu]

Yes good idea! I turned off all my plugins for Chrome on my Macbook Pro and I haven't gotten a profile with a RAF failure in 3 separate 60 second profiles.

However, I still see it happen in my game ? My guess is that since an RAF is supposed to sync with the browser, Chrome is saying that it's not ready to draw yet and holds the RAF up until it is ready. Or maybe my Macbook Pro isn't giving Chrome the resources it wants to be able to draw again too when the temp rises and fans start up.

To test this, I did a profile on my Chromebook with the Pixi playground example and saw many slowdowns, most of them GPU related or caused by large spaces between frame executions. Also some GC. It is obvious that a Chromebook should perform much worse, but maybe it's highlighting the main problem to be with the Chrome browser itself or more of a device specific GPU + CPU available resources type of issue. 

https://imgur.com/a/0r7KhJ9

https://imgur.com/a/fAJpMID

https://imgur.com/a/D4ItbY8