Need help with efficiency NXC code

[muntoo]

Modified NXC files with the .prf file in the source directory. (I didn't have my NXT for a while, so it took a while.)

@spillerrec Of course, it's illegal for any function to call main(), according to the C++ standard.

P.S. @linusa You've got competition.

[linusa]

Modified NXC files with the .prf file in the source directory. (I didn't have my NXT for a while, so it took a while.)

Thanks so much, I uploaded the profiled source code: http://linus.saydoo.com/mGameTask.html
I reformatted the mGameTask.nxc to avoid some long linebreaks (my crappy HTML table design causes it to look uncomfortable, otherwise). Also I had to make sure PROFILER_ENDSECTION(12) got its own line. My Python parser couldn't find this section otherwise, which caused the whole HTML view to be messed up.

But now it's fine, thanks again. I'll post a short analysis in a new post.

P.S. @linusa You've got competition.

YEAH!!! Rock on. Really cool . Hope you put a blog post and/or manual + description. I browsed your source but not long, so I couldn't be bothered to work out what your "HISTORY" does and if it's basically the same concept I used. Are there key differences to my concept?

[muntoo]

Continued hijacking of nxtboyiii's thread.

what your "HISTORY" does and if it's basically the same concept I used. Are there key differences to my concept?

I've no clue about yours (I haven't looked at yours much either ), but HISTORY will (once I get it working) record previous TIMER states. Basically:

Code: Select all

ENDSECTION
{
    PUSH TIMER onto HISTORY
}

I just started it, so only TOTAL "works".

How does your .PRF file format look like? Do you store the name of the profiled file/etc? Currently, mine's just HEADER={file_format, size of TOTAL/HISTORY} and DATA={TOTAL, HISTORY}.

My biggest challenge ATM is learning Perl. (I've only been programming in it for less than a few days!)

[linusa]

Performance analysis (Edit: All based on http://linus.saydoo.com/mGameTask.html of course), here we go.

First of all,

Code: Select all

PROFILER_BEGINSECTION(7);
Tile();
PROFILER_ENDSECTION(7);

Tile() is the most "expensive" function. No surprise here (I guess it does the whole screen/background painting). This alone limits the whole loop framerate to 20FPS (1s / 50ms).


Now I haven't played the game, but I guess the loop is inclusive menu and level selection and so on, and the actual "currently the game is being played" is between the ******************s? If so, then we've got 586 frames of real gameplay captured.

First of all one can notice the sections whichwere never executed. Optimizing here is pointless -- at least for this testcase muntoo provided...

The next thing is that EMYMoveLeft(E) + EMYMoveRight(E) + EMYMoveDown(E) took alone ~9ms, and EMYMoveUp was never executed.

The last two sections are obviously expensive too, but they're not inside the inner play-game loop.

One "cool" thing is this:

Code: Select all

                                PROFILER_BEGINSECTION(11);
                                if (E.eat != 8)
                                    EMYMoveDown(E);
                                PROFILER_ENDSECTION(11);

The HTML's "time per call" says:

> 2.8 ms (in 94%)
< 1.0 ms (in 5%)

This tells us, that in 5% of the calls, this section was executed really quickly. In this case it probably means that (E.eat == 8) was true 5% of the cases (could be useful to make estimates where to optimize).


You can see, I clearly didn't place the sections optimally. The % estimates of total profiled time (28% for the Tile() call) are now "mixed" with the whole big outer loop, and the inner (play == 1) section...
Also I should've placed much more sections, but I couldn't be bothered (and didn't know how much memory was available). One could go ahead and place the sections "where they make sense" now. Maybe just one big section inside the (play == 1) part. That way one has an estimate how fast this part is, and can compare after modifactions.

A missing feature is nested profiler sections, I know. They would come in really handy. I think the NXC code of my profiler supports this, but the Python parser doesn't (just because of me being lazy and because I didn't really know how to fit it into the current HTML layout).


Anyway, John & spiller, if you want to do your performance tests with the profiler, you're very welcome. Parsing the .prf file is really easy, you just need Python installed and a command line. I'm happy to analyze files and upload HTML versions when anybody sends my matching pairs of .nxc and .prf files.
And since I'm happy now, I won't bother you anymore with "please test the profiler". Thanks.

[linusa]

How does your .PRF file format look like? Do you store the name of the profiled file/etc? Currently, mine's just HEADER={file_format, size of TOTAL/HISTORY} and DATA={TOTAL, HISTORY}.

I store Firmware Version, Enhanced flag, TotalRunTime, ProfiledRunTime (sum of execution time inside all sections), and then PROFILER_MAXSECTIONS. After that there are PROFILER_MAXSECTIONS "data entries", with 3 longs for each section: ExecutionCount, ExecutionsSameMs (number executions of a section where the firmware "didn't tick"), ElapsedTicks (sum of execution time of this section).

[nxtboyiii]

So how exactly do I optimize it?

[linusa]

So how exactly do I optimize it?

That depends on what you mean by it. If the whole game, then have a look at Tile() in mTileCheck.nxc and profile/analyze that. If you want that ******* part, then I'd do 2 things:
1) Create more useful profiler sections inside *****, and around parts which seem "interesting", and profile again
2) Focus on the EMYMove* functions. For example, let's take EMYMoveDown.

Do what spiller & John were discussing: Replace

Code: Select all

if(A.sc == 'D' || map[A.mex][A.mey-1].sld == 0)
{
    if(A.sc == 'D' || (map[A.mex+A.pex][A.mey-1].sld == 0 && A.sc == 'N' && (A.eat != -2 || (A.eat == -2 && A.U == 0))))
    {

with

Code: Select all

bool executeMe = false;
if(A.sc == 'D') {
  executeMe = true;
} else if(map[A.mex][A.mey-1].sld == 0) {
  executeMe = true;
} else if(A.sc == 'N') {
  if (A.eat != -2 || (A.eat == -2 && A.U == 0)) {
    if (map[A.mex+A.pex][A.mey-1].sld == 0) {
      executeMe = true;
    }//end if
  }//end if
}//end if

// now the old inner part becomes
if (executeMe)
{
            A.mc=0;
            if(A.eat != -2 && A.eat != 4)
//...

See what I did there? I used the knowledge from above, that in boolean expressions with &&, apparently all things ARE evaluated in NXC at the moment. So I followed spillers advice and added more ifs to exit that branch as fast as possible.
Also the expensive array lookup is the last thing to do, so it's at the less likeliest position.

Do so for the other enemy move functions, and compare execution time to this version. It might also help to profile all the conditions in here to see how often that A.mc=0; // etc... part is actually executed.

Anyway, one big problem is the structure of your code. You check A.sc == 'D' too often, you check A.eat != -2 more than once -- there's got to be a better logical way. But, I can't (don't want to) help in here, as this requires knowledge of your whole game. Start using CONSTANTS pr #defines for your magic values. If it says A.eat != ENEMY_EATING instead of -2, you and others reading your code will at once know what it means. And this in turn makes optimizing easier...


BTW, please make sure my code example above is correct. I might as well have introduced a bug there. Be sure to check again, and make backup copies / use version control.

[nxtboyiii]

Wow, thanks! That helps a lot.(I changed some of the numbers to constants to make it easier to understand)

[linusa]

Wow, thanks! That helps a lot.(I changed some of the numbers to constants to make it easier to understand)

Does it run faster?

[afanofosc]

in boolean expressions with &&, apparently all things ARE evaluated in NXC at the moment. So I followed spillers advice and added more ifs to exit that branch as fast as possible.

There is some confusion here. NXC has always had short circuit evaluation of && and || in boolean expressions. The thing that I was doing that I did not need to do was pushing the primary register onto the stack after the LHS and then popping it off the stack after the RHS (if the evaluation was not short circuited) and ANDing or ORing the two sides. Since I was already short circuiting the expression evaluation I didn't need to do the pushPrim or the popAnd/popOr bits. Spillerec also wanted me to ignore the boolean expression's value (0 or 1) but that is not generally safe since the boolean expression's 0 or 1 value can be used in comparisons, bitwise operations, math ops of any kind, or in assignments. Handling all of these possibilities correctly in any way other than always storing the value (0 or 1) in the primary register is non-trivial or maybe even impossible.

John Hansen