My engine finds a move, but Arena plays something else...???

[JBNielsen]

[d]5k2/2P5/5K2/8/5p2/2r5/6RP/8 b - - 0 56

My engine wants to play c3c7, but Arena plays -,Rg3???

I have seen this quite often.
And mostly it plays a move my engine has never considered the best move.

What happens?


56.Kxf6
(e6f6 34 1/27 happens= M1.....78.......... easyfac=0.81 mat=1/10 sel=4,6 hash=78 hashHit4ply=447/64<score>/33<sw10> score: 34 n=1218036 time=2.93 N/S=415712 mainline=) +0.34/9 5
56...Rg3
(c3c7 -41 searched to move:10/19 Extended search at move 10! happens= L.2.4Q.78....3..... easyfac=1.86 mat=0/10 sel=4,6 hash=78 hashHit4ply=219/0<score>/87<sw10> score: 41 n=1859530 time=3.08 N/S=603744) -0.41/9 3
57.c8=Q#
(c7c8Q 29999 1/23 happens= M1.....78.......... easyfac=0.50 mat=2/10 sel=4,6 hash=78 hashHit4ply=0/0<score>/0<sw10> mate in 1 n=111 time=0.00 mainline=wrong mainline-move: 83 116 ) +M0/2 0
1-0

[abulmo2]

[d]5k2/2P5/5K2/8/5p2/2r5/6RP/8 b - - 0 56

My engine wants to play c3c7, but Arena plays -,Rg3???

I have seen this quite often.
And mostly it plays a move my engine has never considered the best move.

What happens?


56.Kxf6
(e6f6 34 1/27 happens= M1.....78.......... easyfac=0.81 mat=1/10 sel=4,6 hash=78 hashHit4ply=447/64<score>/33<sw10> score: 34 n=1218036 time=2.93 N/S=415712 mainline=) +0.34/9 5
56...Rg3
(c3c7 -41 searched to move:10/19 Extended search at move 10! happens= L.2.4Q.78....3..... easyfac=1.86 mat=0/10 sel=4,6 hash=78 hashHit4ply=219/0<score>/87<sw10> score: 41 n=1859530 time=3.08 N/S=603744) -0.41/9 3
57.c8=Q#
(c7c8Q 29999 1/23 happens= M1.....78.......... easyfac=0.50 mat=2/10 sel=4,6 hash=78 hashHit4ply=0/0<score>/0<sw10> mate in 1 n=111 time=0.00 mainline=wrong mainline-move: 83 116 ) +M0/2 0
1-0

You should keep a log file with the communication between your engine and Arena. To me, it seems that c3c7 is from the pv of your engine's search and Rg3 is the bestmove sent to Arena. A bug in your program may explain the mismatch between the bestmove of the pv searched and the bestmove sent to Arena. To be sure you need to log the data that your program sends to Arena.

[Jim Ablett]

Hi Jens,

Hope you are well. Nice to see you still improving your engine after all this time. I asked Claude Ai about the bug and this is
what it came up with after analysing the code >

I found it. In mainline() (the function that builds/prints the PV and is what actually sends the move to Arena's pondering/PV display), there's a leftover debug goto leave2; that unconditionally jumps past the code that would apply and print the real best move — and past the whole loop that walks the hash table to build the rest of the PV:

Code: Select all

  if (hashmove_is_wrong(move_fr[0][0], move_to[0][0])==true)
       {printf("wrong mainline-move: %d %d ",move_fr[0][0], move_to[0][0]);
        happens[0]='M';
		}
		
	goto leave2; 	          // <-- BUG: always taken, skips everything below


   mainline_move(move_fr[0][0], move_to[0][0], maliout, undoply);   // <-- dead code, never runs

Since the goto leave2; has no surrounding if, mainline_move() (which prints the PV squares via print_a1_h8 and advances the position so the hash-table walk at label r: can find the rest of the line) never executes. That whole r: loop right after it is skipped too. So the pv field in your info depth ... pv output is built from stale/incomplete state, while the actual move sent to Arena is taken straight from best_move_fr[0]/best_move_to[0] in print_best_move_ply_zero() — which is correct and independent of this broken function. That's exactly why the displayed PV and the played move can disagree.

Root cause: in mainline(), right after the hashmove_is_wrong() diagnostic check, there was an unconditional goto leave2; sitting with no if around it — a leftover debug bypass. It ran every single time mainline() was called with undoply==0 (the normal case), which meant:

mainline_move(move_fr[0][0], move_to[0][0], ...) — the call that actually prints and applies the top move for the PV — never executed.
The hash-table walk right after it (label r:) that reconstructs the rest of the PV line by following transposition-table entries also never ran.

So the info depth ... pv ... line sent to Arena was built from stale/incomplete state, while the move Arena actually plays comes from a separate, correct path (best_move_fr[0]/best_move_to[0] via print_best_move_ply_zero()). That's the mismatch you were seeing.

best,
Jim.

[JBNielsen]

Thanks; I hope you are doing well too!
So nice to hear from you after all these years!

I have not touched Dabbaba since 2013.
But now I am trying again.
Hash-tables are almost working now.

The mainline has never worked.
It does not deliver any moves.
So I don't think that is the error.
But I should take a look at it....

I once tried to walk through the hashtables to produce a mainline.
But it failed and I gave it up.
I will return to that some day.

Your copy of Dabbaba must be old!
But I do think it also had that frustrating Arena-error.
One of the reasons why I put Dabbaba aside.

In my post you can see the move -,Rg3.
And just below that what I delivered to Arena: (c3c7 -41......

I have a suspicion that it happens when the time manager stops the search.
And not all of the moves of the last iteration have been searched.
In my diagram it has "searched to move:10/19"....

Thank you very much for a nice attempt!

[mysammoore]

Yeah your suspicion is right, and your own log tells you which move. "searched to move:10/19" and "Extended search at move 10!" means the search got stopped while it was in the middle of move 10, and move 10 is Rg3. So the time manager kills the search, the subtree it was in returns whatever it had at that moment which is garbage, and if your root loop checks that score against alpha before it checks the stop flag then Rg3 just became the best move and overwrote c3c7. The PV still shows c3c7 because that came from the part of the iteration that actually finished, but by the time the bestmove goes out it's Rg3. Arena isn't doing anything, it's playing exactly what you sent it.

What I'd do is check the stop flag the moment the recursive call returns, before touching alpha or the best move at all, an interrupted score should never get compared to anything. And if the iteration got aborted, play the best move from the last completed iteration instead. The only time the new iteration's best move is trustworthy is if that move fully finished searching before the stop hit. I hit a cousin of this in my own engine where a quit racing the search made it spit out the first root move, same family of bug, whatever leaves the engine when a search gets interrupted has to be airtight.

Richard's right about logging the bestmove line too. You'll see Rg3 go out while the PV says c3c7 and that settles that it's the root loop and not Arena.