Curious behavior of Houdini search

[OneTrickPony]

[d] r1bqkbnr/1ppp1ppp/p1B5/4p3/4P3/5N2/PPPP1PPP/RNBQK2R b KQkq - 0 4 [/d]

I use Houdini 3 64bit.
I run the following sequence of commands:

ucinewgame
setoption name clear hash
position fen r1bqkbnr/1ppp1ppp/p1B5/4p3/4P3/5N2/PPPP1PPP/RNBQK2R b KQkq - 0 4
setoption name threads value 1
go searchmoves b7c6 d7c6 depth 20

average time (out o 3 measurements): 7693ms

Now I run this test:

ucinewgame
setoption name clear hash
position fen r1bqkbnr/1ppp1ppp/p1B5/4p3/4P3/5N2/PPPP1PPP/RNBQK2R b KQkq - 0 4
setoption name threads value 1
go depth 20

Average time: 14214 ms

Now, what is curious is that d7c6 and b7c6 are the only moves which makes the slightest sense. Why is Houdini spending more than 50% of it's time looking at other moves. I mean, I only provided information which should be obvious after few miliseconds anyway.

On the other hand:
[d]rnbqkb1r/ppp1pp1p/6p1/3n4/3PP3/2N5/PP3PPP/R1BQKBNR b KQkq e3 0 5[/d]

Here the results for go searchmoves d5b4 d5c3 d5b6 d5f6 depth 20 and go depth 20 are 25536ms (again avg out of 3) and 18812ms

This time Houdini managed to reach depth 20 faster without helpful information from me. Even if I eliminate Nd5-b4 from searchmoves list it still takes more time to reach d20.

This is puzzling to say the least. Could anyone explain ?

(I wanted to test Stockfish as well but it doesn't cooperate with UCI command searchmoves; Critter 1.6 doesn't implement UCI as well; it refuses to send info about time along with bestmove when switched to 1 thread).

[syzygy]

Now, what is curious is that d7c6 and b7c6 are the only moves which makes the slightest sense.

To you. Computers are stupid. They have no sense.

[OneTrickPony]

Well, spending 50% of your searching time for positions with piece down for nothing is pretty bad, engine or human, sense or not.
Something is wrong here.

[S.Taylor]

Well, spending 50% of your searching time for positions with piece down for nothing is pretty bad, engine or human, sense or not.
Something is wrong here.

especially if it didn't have breakfast or fruit or fish or chips that morning, engine or human.

[hgm]

Well, spending 50% of your searching time for positions with piece down for nothing is pretty bad, engine or human, sense or not.
Something is wrong here.

That is very fast, not? There are many more other moves, so it must reject them an order of magnitude faster than the sensible ones. If you are still a piece down at 19 ply, you might not be a Rook up at 20 ply. And this will not be known 'after a few msec'. By not searching the alternatives to the full depth you would restrict the engine to playing only moves that look good at low depth, effectively reducing its level to that low depth.

[Uri Blass]

Well, spending 50% of your searching time for positions with piece down for nothing is pretty bad, engine or human, sense or not.
Something is wrong here.

That is very fast, not? There are many more other moves, so it must reject them an order of magnitude faster than the sensible ones. If you are still a piece down at 19 ply, you might not be a Rook up at 20 ply. And this will not be known 'after a few msec'. By not searching the alternatives to the full depth you would restrict the engine to playing only moves that look good at low depth, effectively reducing its level to that low depth.

No it is not very fast and practically it is not correct that houdini spend 50% of the searching time on other moves.
The branching factor of houdini is often lower than 2 so even if a move is not forced it often spend less than 50% of the time on root moves that are not the best move based on houdini's search.

I guess that the search of houdini3 is different when you tell it to search only part of the root moves so comparing time between searching only dxc6 and bxc6 and searching all the moves is not relevant.

[hgm]

No need to guess. You can easily test this theory by running a normal search, and look at how long it took for each root move by looking at the time-stamps on the info-string commands. (E.g. in the GUI log).

[OneTrickPony]

especially if it didn't have breakfast or fruit or fish or chips that morning, engine or human.

Please don't troll my thread.

That is very fast, not? There are many more other moves, so it must reject them an order of magnitude faster than the sensible ones

Let me ask you this:
at say depth 10 there is already many more problematic positions to search after dc6 or bc6 than at say depth 5 after all other moves. What is more productive, spending time on those problematic positions which may contain refutation to one of our "good" moves or digging deeper into positions where you are piece down and can't make any threats ?

There is something wrong with search design if engine spends more than 50% of its time resolving piece up for nothing positions.

No it is not very fast and practically it is not correct that houdini spend 50% of the searching time on other moves.
The branching factor of houdini is often lower than 2 so even if a move is not forced it often spend less than 50% of the time on root moves that are not the best move based on houdini's search.

Sanity check. If it wasn't true for the best engine on the planet it would be time to give up everything and commit full time to engine development.

I guess that the search of houdini3 is different when you tell it to search only part of the root moves so comparing time between searching only dxc6 and bxc6 and searching all the moves is not relevant.

Yeah, probably but why ?
It seems like the job is the same in both cases: "decide between d7c6 b7c6". While engine has to determine it itself without clues it still should assign heavy reduction penalties (or w/e) to focus efforts on important nodes. Maybe depth is counted differently for searchmoves ?

No need to guess. You can easily test this theory by running a normal search, and look at how long it took for each root move by looking at the time-stamps on the info-string commands. (E.g. in the GUI log).

Could you suggest a GUI which does it (ie log with its own timestamps) ? Houdini output unfortunately doesn't contain timestamps frequent enough to determine. (Although for example it spends 6018ms for last ply out of which 1270ms for all moves besides d7c6/b7c6/a8b8/h7h6 which still seems high to me but nowhere close 50% bad.


Btw it's very annoying for a new comer to chess programming that implementation of UCI is so different in every engine, some doesn't respect commands, some answer, some don't, some change output randomly depending on state while not providing any coherent documentation; it makes life hard

[S.Taylor]

especially if it didn't have breakfast or fruit or fish or chips that morning, engine or human.

Please don't troll my thread.

(

1).welcome to the forum!
2). Obviously you are not used to it here yet. You may take one little joke in good humor.
3). At any rate, i probably didn't understand it anyway, so i'm sorry for laughing about that which i did not understand.

[hgm]

Could you suggest a GUI which does it (ie log with its own timestamps) ? Houdini output unfortunately doesn't contain timestamps frequent enough to determine. (Although for example it spends 6018ms for last ply out of which 1270ms for all moves besides d7c6/b7c6/a8b8/h7h6 which still seems high to me but nowhere close 50% bad.

As I am only familiar with WinBoard, the way I would do it is run Houdini with the UCI2WB adapter in debug mode (which then relays all raw communication with the engine also to the GUI, so they appear in the log there). Because WB by default uses Polyglot rather than UCI2WB, this makes the install a bit more cumbersome than usual, as you would have to explicitly mention UCI2WB:

Engine (*.exe): UCI2WB.exe
command-line parameters: debug houdini.exe HOUDINIFOLDER
Special WinBoard options: -debug
directory: .
(All in the Load First Engine dialog; you could have browsed to UCI2WB.exe, which is in the WinBoard folder, and which would automaticaly take care of the directory being properly set, so you could leave that field blank).

(and do NOT tick the UCI checkbox!)

This should create a winboard.debug file containing everything the engine said with time stamps.

But I guess it would be simpler on a GUI that supports UCI without adapter. (But I wouldn't know how to do that.)