Profiling Comparisons

[D Sceviour]

What is the approximate percentage of time that routines should be spending?

Here is a 32-bit profile output with the percentage time spent for a single thread (1 CPU). There are sixteen general categories to make comparisons easier. For example, some programs use the term MovePick() instead of SORT(). Of course, it is easy to break up the categories into sub fragments if desired, as they are many different ways of displaying the information.

The attack boards seem to be taking a lot of time, but the time has to be spent somewhere.

Sample Profile

% cumulative time
23.91 ATTACKBOARDS()
15.10 EVALUATION()
8.82 POPCNT()
7.49 SEARCH()
5.72 GEN_MOVES()
5.22 GEN_EXCHANGES()
5.13 PAWNSTRUCTURE()
4.76 QUIESCENCE()
4.58 MAKEMOVE()
4.50 BITSCAN()
3.98 SORT()
3.23 HASHPROBE()
1.42 TAKEBACK()
1.02 EVASION()
0.94 MATERIAL()
4.18 other
-------
100.00%

[Sven]

What does ATTACKBOARDS() cover in this case?

[D Sceviour]

Sven Schüle asked,

What does ATTACKBOARDS() cover in this case?

ATTACKBOARDS means the calculation of magic bitboards, and king safety which is calculated at the same time.

[Sven]

Sven Schüle asked,

What does ATTACKBOARDS() cover in this case?

ATTACKBOARDS means the calculation of magic bitboards

Only in the context of the evaluation, or also of other parts of the engine, e.g. movegen, make/unmake move, isInCheck?

In case of the latter I'd say your numbers are hard to compare to other engines since many people divide their profiling summary into higher-level categories only, like evaluation/movegen/make-unmake etc. Calculation of attack bitboards occurs here and there, and is nowadays almost a low-level operation like addition or multiplication (I say "almost", of course).

[D Sceviour]

Sven Schüle wrote,

In case of the latter I'd say your numbers are hard to compare to other engines since many people divide their profiling summary into higher-level categories only, like evaluation/movegen/make-unmake etc.

That is easy to compare. Simply add:

EVALUATION + GEN_MOVES + MAKEMOVE + TAKEBACK = 26.82%

_____________________________________________

Sven Schüle wrote,

Calculation of attack bitboards occurs here and there.

Magic and rotated bitboards are a specific calculation that can be profiled in a separate routine.

[Sven]

Sven Schüle wrote,

In case of the latter I'd say your numbers are hard to compare to other engines since many people divide their profiling summary into higher-level categories only, like evaluation/movegen/make-unmake etc.

That is easy to compare. Simply add:

EVALUATION + GEN_MOVES + MAKEMOVE + TAKEBACK = 26.82%

_____________________________________________

Sven Schüle wrote,

Calculation of attack bitboards occurs here and there.

Magic and rotated bitboards are a specific calculation that can be profiled in a separate routine.

Sorry for not having expressed my point well enough.

This clearly seems to belong to static eval:
15.10 EVALUATION()
5.13 PAWNSTRUCTURE()
0.94 MATERIAL()

This to the search:
7.49 SEARCH()
4.76 QUIESCENCE()
3.98 SORT()
3.23 HASHPROBE()
1.02 EVASION()

This looks like move generation:
5.72 GEN_MOVES()
5.22 GEN_EXCHANGES()

And this is make/unmake:
4.58 MAKEMOVE()
1.42 TAKEBACK()

But these are distributed over any of the four main sections I listed above:
23.91 ATTACKBOARDS()
8.82 POPCNT()
4.50 BITSCAN()

Can you tell how much of the last part is used within static eval, move generation and so on?

[D Sceviour]

Sven Schüle asked,

Can you tell how much of the last part is used within static eval, move generation and so on?

To be certain, make sure that a flat profile is being presented above.

Profiles are generated as a separate part of the debugging stage and are attached to functions or routines. Your program must be compiled with profiling enabled. Once you have a profile output, it should be easy to figure out how to compare the data. There are undoubtedly more involved references depending on the compiler, but here is a link to a general introduction:

https://en.wikipedia.org/wiki/Profile-g ... timization

[bob]

Sven Schüle wrote,

In case of the latter I'd say your numbers are hard to compare to other engines since many people divide their profiling summary into higher-level categories only, like evaluation/movegen/make-unmake etc.

That is easy to compare. Simply add:

EVALUATION + GEN_MOVES + MAKEMOVE + TAKEBACK = 26.82%

_____________________________________________

Sven Schüle wrote,

Calculation of attack bitboards occurs here and there.

Magic and rotated bitboards are a specific calculation that can be profiled in a separate routine.

How? Their use ought to be inlined everywhere magics are used. Not done through actual procedure calls.

[bob]

Sven Schüle asked,

Can you tell how much of the last part is used within static eval, move generation and so on?

To be certain, make sure that a flat profile is being presented above.

Profiles are generated as a separate part of the debugging stage and are attached to functions or routines. Your program must be compiled with profiling enabled. Once you have a profile output, it should be easy to figure out how to compare the data. There are undoubtedly more involved references depending on the compiler, but here is a link to a general introduction:

https://en.wikipedia.org/wiki/Profile-g ... timization

You are missing his point / question.

When you generate legal moves, you use magics. When you evaluate sliding piece mobility, you use magics. So how much of the usage goes to evaluate, and how much to movgen? I'd imagine ALL of the popcnt's are in evaluation, but maybe not...

[D Sceviour]

Bob Hyatt asked,

When you generate legal moves, you use magics. When you evaluate sliding piece mobility, you use magics. So how much of the usage goes to evaluate, and how much to movgen?

Perhaps the error is mine in the use of magics as my algorithm uses attack boards (bitboards) and not magics to generate legal moves, and perhaps that is why my ATTACKBOARD() usage is so high. For example, a specific profile call to generate a Rook attack (in pseudo code):

ulonglong Rank_Attack(sq,occupancy)
{
occupancy AND= rookmask(sq);
Index = (occupancy * magicrook(sq)) SHR ROOK_SHIFT;
j = R_Index(sq,index);
return (R_Moves(j));
}

This returns a bitboard of the rook attack.

Likewise, there are profiled routines for Bishop, Queen, pawns, etc. These are added to produce 23.91% of the cumulative time. The profile above does not give the percentage breakdown of how many calls to generate attacks are made from the move generator.
_______________________________________________________

Bob Hyatt wrote,

I'd imagine ALL of the popcnt's are in evaluation, but maybe not...

That does not address the question being asked in the OP. The popcnt profile in question would be the equivalent of Crafty's 32-bit representation:

int PopCnt(register BITBOARD a)

The BITSCAN() refers to calls to a 32-bit DeBruijn solution for BitScanForward. I agree that bitboards are used everywhere, but the question is how much profile time is acceptable for their calculation? Someone out there must have done a profile on their chess engine before.