Body.updateAABB increases CPU usage over time

[cnatale]

Test browser: Chrome 43.0.2357.134 (64-bit) Mac

I am working with a modified version of the ragdoll demo (you can view source here: https://bitbucket.org/chrisnatale/ihtai/src/d0aedb966d2f2011c7ffa33d15dd73effc7272aa/ragdolldemo.html?at=master). The total number of objects onscreen is static over time. There are four planes that serve as a container for the ragdoll, and the ragdoll itself.

One thing I am noticing while profiling is that total CPU usage by the Body.updateAABB() method continually increases over time. If I leave the simulation running overnight, performance slows to a crawl due to CPU usage of this method. Percentage of total CPU usage for this method increases as follows:

5 minutes: 1.57% 10 minutes: 2.93% 15 minutes: 5.14% ~8 hours: 53.84%

Looking at the method and methods calling it, nothing immediately jumps out. Any ideas on what would be causing this?

Attached: screenshots of Chrome's CPU Usage profiler results.

Five Minutes:

Ten Minutes:

Fifteen Minutes:

Eight Hours:

Update: here is the expanded call stack from the simulation after it has been running for ~eight hours:

[schteppe]

Hi, Very interesting.. Actually I have no idea what would cause this. Memory leak? Will have a look whenever I get some time over.

[cnatale]

Memory usage appears to be holding steady in these tests. I'll take some screen caps the next time I run it overnight, but I observed it maxing out at ~257 megs within a few minutes of starting the test (the a.i. engine I'm running is taking up most of that), and then stabilizing. Thanks.

[cnatale]

I ran the same memory and CPU usage tests on the ragdoll demo from P2's GitHub page overnight. There is no comparable increase in CPU usage of the Body.updateAABB() method over time.

I'm going to run more tests over the next few days to try and isolate which change I made to the demo introduced this problem.

[cnatale]

I've isolated the situation where this bug manifests. I'm using the following code to generate four planes that serve as a container for the ragdoll. When I remove the left, top, and right planes, it no longer manifests.

            var OTHER =     Math.pow(2,1),
                BODYPARTS = Math.pow(2,2),
                WALLS =     Math.pow(2,3),
                bodyPartShapes = []; 

            // ...

            // Create ground
            var groundShape = new p2.Plane();
            var ground = new p2.Body({
                position:[0,-1],
            });
            ground.addShape(groundShape);
            groundShape.collisionGroup = WALLS;
            groundShape.collisionMask =  BODYPARTS|OTHER;
            world.addBody(ground);

            //create walls
            var leftWallShape = new p2.Plane();
            var leftWall = new p2.Body({
                position:[-8,0],
                angle:[3*Math.PI/2]
            });

            leftWall.addShape(leftWallShape);
            leftWallShape.collisionGroup = WALLS;
            leftWallShape.collisionMask =  BODYPARTS|OTHER;
            world.addBody(leftWall);            

            var rightWallShape = new p2.Plane();
            var rightWall = new p2.Body({
                position:[8,0],
                angle:[Math.PI/2]
            });

            rightWall.addShape(rightWallShape);
            rightWallShape.collisionGroup = WALLS;
            rightWallShape.collisionMask =  BODYPARTS|OTHER;    
            world.addBody(rightWall);               

            var topWallShape = new p2.Plane();
            var topWall = new p2.Body({
                position:[0,10],
                angle:[Math.PI]
            });

            topWall.addShape(topWallShape);
            topWallShape.collisionGroup = WALLS;
            topWallShape.collisionMask =  BODYPARTS|OTHER;                  
            world.addBody(topWall);            

Also I was making a few other mistakes with setting the collision masks, so here is an updated, cleaner version of the source: https://bitbucket.org/chrisnatale/ihtai/src/738ffafbc8b888d52ed0fc4d9df51d479535c674/ragdolldemo.html?at=master

[schteppe]

Thanks for your help. I've tried to reproduce your test case but I'm not sure if I'm succeeding... So I optimized away some suspicious code. Can you try this patch? (just copy/paste it in any script after p2.js was included)

p2.Plane.prototype.computeAABB = function(out, position, angle){
    var a = angle % (2 * Math.PI);
    var set = p2.vec2.set;
    var max = 1e7;
    var lowerBound = out.lowerBound;
    var upperBound = out.upperBound;

    // Set max bounds
    set(lowerBound, -max, -max);
    set(upperBound,  max,  max);

    if(a === 0){
        // y goes from -inf to 0
        upperBound[1] = 0;

    } else if(a === Math.PI / 2){

        // x goes from 0 to inf
        lowerBound[0] = 0;

    } else if(a === Math.PI){

        // y goes from 0 to inf
        lowerBound[1] = 0;

    } else if(a === 3*Math.PI/2){

        // x goes from -inf to 0
        upperBound[0] = 0;

    }
};

Not sure if this is going to help, but might be worth a try.

[cnatale]

Thanks. I'm still seeing a gradual increase in CPU usage over time after adding the prototype method. When I get some time, I'll step through the source at various intervals and see if I can spot what exactly is causing updateAABB() to either take longer to run or be triggered much more often the longer the demo is running.

UPDATE 7/27/2015: I was actually wrong about this. The updated computeAABB() prototype method does indeed result in much better performance for updateAABB(). The reason I didn't notice this is that performance of other methods in internalStep were still showing the same kind of CPU usage growth as before. Looking through the source, I can't see any reason for this in terms of the algorithms being used by said methods. I was expecting to see something being iterated over, and a bug causing the size of the iteration to increase over time. I haven't spotted anything like that though. It's a real head scratcher.

[cnatale]

I've narrowed this down to the garbage collector getting triggered almost every time P2's rendering loop executes. I've included a screen shot of a few of the cycles. This fits with not actually seeing the total memory climb, yet performance slowing to a crawl. Basically, it looks like the library is cleaning up after itself, but allocating a lot of memory that leads to the constant GC calls. I still have no idea where the ~14 megs of allocations every 50 milliseconds are coming from, though.

This could also explain why it looked like methods in the rendering loop like updateAABB() were causing the slowdown. If the gc is getting triggered during the rendering loop, it could be affecting the time measurements for these methods, making them appear to be the cause of the problem instead of a symptom.

I'm thinking it's somehow linked to a lot of collision events being triggered. I've isolated this by disabling my a.i. engine and assigning the ragdoll muscle movements only using Math.random(). There are a few Arrays and Objects being initialized by this method every cycle, but nothing approaching the 14 megs being gc'd every 50 milliseconds I'm seeing. I see identical behavior in this scenario as when the engine is running every cycle. However, the behavior described in this bug does not seem to occur when the random muscle spasms are disabled, and the ragdoll isn't moving.

I also still have no idea why this problem increases over time.

Note that this behavior builds up slowly over time. The gc doesn't occur this close together until 1/2 hour to an hour into the simulation.

[cnatale]

I ran another test with the goal of isolating where the problem is coming from. I ripped out the WebGLRenderer and used a custom-rolled Canvas renderer based on P2's Canvas demos. I turned off my a.i. engine and applied random forces to limbs every cycle. The results were the same as before. Performance degrading slowly over time, until it slows to a crawl after about an hour of simulation. This suggests that it is indeed a problem with the P2 core library.

[cnatale]

I think I finally figured out what is going on. I turned down the number of substeps to 1, and this fixed the problem. I'm hypothesizing that Chrome's gc is unable to keep up with the flow of released variables when the number of substeps is set to the default 10 per iteration. In particular, the beginContact and endContact events being emitted are churning out a ton of Objects (see screenshot below). This would explain why performance degrades over time. As the number of released objects builds up, gc is called more and more often. It can never keep up, though, and the backlog of objects to release only increases. This leads to the constant gc calls and performance degradation I've been documenting.

To recap, this appeared to be caused by updateAABB() and a few other methods in P2's update cycle because the gc was getting triggered during these methods, making them appear slower than they actually are. Sorry for the false lead.

I tried commenting out where these events were emitted in the P2 source, but this only slowed the performance degredation. This suggests that there's no magic bullet optimization to the source to prevent the problem. Since decreasing substeps is an acceptable solution for me, I consider this bug closed.