Crafty-23.3 very slow

Discussion of anything and everything relating to chess playing software and machines.

Moderators: hgm, Rebel, chrisw

zullil
Posts: 6442
Joined: Tue Jan 09, 2007 12:31 am
Location: PA USA
Full name: Louis Zulli

Crafty-23.3 very slow

Post by zullil »

Probably I'm being dumb, but it's been a week and I'm still stumped.

Summary: I've just built Crafty-23.2 and Crafty-23.3 from source using the same Makefile and the same compiler. 23.3 is much, much slower than 23.2.

This is under Mac OS X 10.6.4 on a Nehalem Mac Pro.

Here's some evidence:

Code: Select all

LZsMacPro-OSX6: ~/Documents/Chess/Crafty/Crafty-23.2] make darwin
make target=FreeBSD \
		CC=gcc-mp-4.4 CXX=g++-mp-4.4 \
		CFLAGS='-O3 -m64 -fomit-frame-pointer -fno-tree-pre' \
		CXFLAGS='-O3 -m64 -fomit-frame-pointer -fno-tree-pre' \
		LDFLAGS= \
		LIBS='-lstdc++' \
		opt=' -DCPUS=16 -DINLINE64 -DPOPCNT \
                     -DLOGDIR=\"./Logs\" -DBOOKDIR=\"./Books\" \
                     -DTBDIR=\"../TB\"' \
		crafty-make
gcc-mp-4.4 -O3 -m64 -fomit-frame-pointer -fno-tree-pre -DCPUS=16 -DINLINE64 -DPOPCNT                      -DLOGDIR=\"./Logs\" -DBOOKDIR=\"./Books\"                      -DTBDIR=\"../TB\" -DFreeBSD -c crafty.c
g++-mp-4.4 -c -O3 -m64 -fomit-frame-pointer -fno-tree-pre -DCPUS=16 -DINLINE64 -DPOPCNT                      -DLOGDIR=\"./Logs\" -DBOOKDIR=\"./Books\"                      -DTBDIR=\"../TB\" -DFreeBSD egtb.cpp
gcc-mp-4.4  -o crafty-23.2 crafty.o egtb.o -lm  -lstdc++
LZsMacPro-OSX6: ~/Documents/Chess/Crafty/Crafty-23.2] ./crafty-23.2 
unable to open book file [./Books/book.bin].
book is disabled
unable to open book file [./Books/books.bin].
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly (using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.2 (8 cpus)

White(1): setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1 
White(1): st 60
search time set to 60.00.
White(1): display stats
display statistics at end of each search.
White(1): go
              time limit 1:00 (+0.00) (1:00)
              depth   time  score   variation (1)
starting thread 1
starting thread 2
starting thread 3
starting thread 4
starting thread 5
starting thread 6
starting thread 7
                7->   0.04  -0.45   1. Bc4+ Be6 2. Bxe6+ Rxe6 3. Qg4 Kf7
                                    4. Bh4 Re2 5. Qc4+ Re6 (s=2)
                8     0.06  -0.67   1. Bc4+ Be6 2. Be3 f5 3. Bxe6+ Rxe6
                                    4. Qh5 Qf6 5. Rd5 Ne5 6. Nxe5 Rxe5
                8     0.07  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5
                8->   0.07  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5 (s=2)
                9     0.09  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.11  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10     0.13  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.18  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 (s=6)
               11     0.21  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 (s=5)
               11->   0.36  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 (s=5)
               12     0.47  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    (s=4)
               12->   1.11  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    (s=8)
               13     1.29  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    (s=7)
               13->   2.15  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    (s=6)
               14     2.61  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 <HT> &#40;s=5&#41;
               14->   4.60  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 <HT> &#40;s=5&#41;
               15     5.87  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6 &#40;s=4&#41;
               15->  10.05  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6 &#40;s=5&#41;
               16    11.97  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 Rb8 8. Be4 Ne5 9. Qxd7 Bxd7 &#40;s=4&#41;
               16->  27.72  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 Rb8 8. Be4 Ne5 9. Qxd7 Bxd7 &#40;s=7&#41;
               17    34.50  -0.59   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=6&#41;
              time=1&#58;00  mat=-1  n=1340204462  fh=95%  nps=22.1M      
              extensions=83.7M qchecks=84.4M reduced=104.7M pruned=594.3M
              predicted=0  evals=140.4M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=257875  aborts=21186  data=94/1024  elap=1&#58;00
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;00

Code: Select all

LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.3&#93; make darwin
make target=FreeBSD \
		CC=gcc-mp-4.4 CXX=g++-mp-4.4 \
		CFLAGS='-O3 -m64 -fomit-frame-pointer -fno-tree-pre' \
		CXFLAGS='-O3 -m64 -fomit-frame-pointer -fno-tree-pre' \
		LDFLAGS= \
		LIBS='-lstdc++' \
		opt=' -DCPUS=16 -DINLINE64 -DPOPCNT \
                     -DLOGDIR=\"./Logs\" -DBOOKDIR=\"./Books\" \
                     -DTBDIR=\"../TB\"' \
		crafty-make
gcc-mp-4.4 -O3 -m64 -fomit-frame-pointer -fno-tree-pre -DCPUS=16 -DINLINE64 -DPOPCNT                      -DLOGDIR=\"./Logs\" -DBOOKDIR=\"./Books\"                      -DTBDIR=\"../TB\" -DFreeBSD -c crafty.c
g++-mp-4.4 -c -O3 -m64 -fomit-frame-pointer -fno-tree-pre -DCPUS=16 -DINLINE64 -DPOPCNT                      -DLOGDIR=\"./Logs\" -DBOOKDIR=\"./Books\"                      -DTBDIR=\"../TB\" -DFreeBSD egtb.cpp
gcc-mp-4.4  -o crafty-23.3 crafty.o egtb.o -lm  -lstdc++
LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.3&#93; ./crafty-23.3 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.3 &#40;8 cpus&#41;

White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1 
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
starting thread 1
starting thread 2
starting thread 3
starting thread 4
starting thread 5
starting thread 6
starting thread 7
                8     0.05  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5 &#40;s=4&#41;
                8->   0.07  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5
                9     0.08  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.10  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=2&#41;
               10     0.11  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.15  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=6&#41;
               11     0.21  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=5&#41;
               11->   0.26  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               12     0.34  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qc8 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    <HT>
               12->   0.49  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qc8 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    <HT> &#40;s=5&#41;
               13     0.58  -0.70   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Kh8 5. Rhe1 Bb6 6. Be4 f5 7. Bc2
                                    &#40;s=4&#41;
               13->   0.91  -0.70   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Kh8 5. Rhe1 Bb6 6. Be4 f5 7. Bc2
                                    &#40;s=5&#41;
               14     1.06  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=4&#41;
               14->   1.60  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=7&#41;
               15     1.88  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    h4 Ne5 8. Qxd7 <HT> &#40;s=6&#41;
               15->   3.37  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    h4 Ne5 8. Qxd7 <HT> &#40;s=8&#41;
               16     3.81  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=7&#41;
               16->   6.97  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=10&#41;
               17     7.64  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=9&#41;
               17->  14.98  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=11&#41;
               18    18.63  -0.68   1. Be3 Be6 2. Bg6 Re7 3. a3 Ba5 4.
                                    Qa4 Kh8 5. Be4 Bb6 6. Bxc6 bxc6 7.
                                    Qxc6 Rb8 8. Rhe1 Bf5 9. Nd4 Be4 &#40;s=10&#41;
               18->  28.74  -0.68   1. Be3 Be6 2. Bg6 Re7 3. a3 Ba5 4.
                                    Qa4 Kh8 5. Be4 Bb6 6. Bxc6 bxc6 7.
                                    Qxc6 Rb8 8. Rhe1 Bf5 9. Nd4 Be4 &#40;s=6&#41;
               19    33.28  -0.65   1. Be3 Be6 2. Bg6 Re7 3. a3 Ba5 4.
                                    Qa4 Kh8 5. Be4 Bb6 6. Bxc6 bxc6 7.
                                    Qxc6 Rb8 8. Bxb6 Rxb6 9. Qa4 Qb8 10.
                                    b3 &#40;s=5&#41;
               19->  49.23  -0.65   1. Be3 Be6 2. Bg6 Re7 3. a3 Ba5 4.
                                    Qa4 Kh8 5. Be4 Bb6 6. Bxc6 bxc6 7.
                                    Qxc6 Rb8 8. Bxb6 Rxb6 9. Qa4 Qb8 10.
                                    b3 &#40;s=5&#41;
               20    58.98  -0.66   1. Be3 Be6 2. Bg6 Re7 3. a3 Ba5 4.
                                    Qa4 Kh8 5. Nh4 Bb6 6. Qf4 Bxe3+ 7.
                                    fxe3 Ne5 8. Be4 c5 9. Nf5 Rd7 10. Rhf1
                                    Qb6 &#40;s=4&#41;
              time=1&#58;01  mat=-1  n=511785715  fh=90%  nps=8.3M       
              extensions=8.6M qchecks=25.7M reduced=58.3M pruned=189.9M
              predicted=0  evals=125.6M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=99038  aborts=11179  data=55/1024  elap=1&#58;01
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;01
zullil
Posts: 6442
Joined: Tue Jan 09, 2007 12:31 am
Location: PA USA
Full name: Louis Zulli

Re: Crafty-23.3 very slow

Post by zullil »

Should have included single thread data too. Using smpmt=1, 23.3 is still slower than 23.2, but not dramatically so:

Code: Select all

LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.2&#93; ./crafty-23.2
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.2 &#40;8 cpus&#41;

White&#40;1&#41;&#58; smpmt=1
Warning--  xboard 'cores' option disabled
max threads set to 1.
White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
                7->   0.06  -0.45   1. Bc4+ Be6 2. Bxe6+ Rxe6 3. Qg4 Kf7
                                    4. Bh4 Re2 5. Qc4+ Re6
                8     0.11  -0.67   1. Bc4+ Be6 2. Be3 f5 3. Bxe6+ Rxe6
                                    4. Qh5 Qf6 5. Rd5 Ne5 6. Nxe5 Rxe5
                8     0.14  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5
                8->   0.18  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5
                9     0.23  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.33  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10     0.39  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.60  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               11     0.74  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               11->   1.33  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               12     1.86  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
               12->   5.08  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
               13     5.59  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
               13->  10.08  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
               14    12.22  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               14->  19.76  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               15    26.00  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6
               15->  51.01  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6
               16    59.17  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 Rb8 8. Be4 Ne5 9. Qxd7 Bxd7
              time=1&#58;00  mat=-1  n=250315163  fh=95%  nps=4.1M       
              extensions=13.8M qchecks=14.1M reduced=20.9M pruned=111.4M
              predicted=0  evals=30.7M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=0  aborts=0  data=0/1024  elap=1&#58;00
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;00

Code: Select all

LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.3&#93; ./crafty-23.3 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.3 &#40;8 cpus&#41;

White&#40;1&#41;&#58; smpmt=1
Warning--  xboard 'cores' option disabled
max threads set to 1.
White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
                8->   0.07  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5
                9     0.07  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5 5. Bf7+ Kf8
                9->   0.11  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5 5. Bf7+ Kf8
               10     0.15  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.22  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               11     0.26  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               11->   0.37  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               12     0.50  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               12->   0.81  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               13     0.92  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               13->   1.56  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               14     1.83  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5
               14->   2.98  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5
               15     3.44  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6
               15->   6.69  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6
               16     7.40  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6
               16->  13.25  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6
               17    14.44  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6
               17->  26.65  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6
               18    33.94  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7
               18->  59.65  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7
              time=1&#58;00  mat=-1  n=229055049  fh=89%  nps=3.8M       
              extensions=4.5M qchecks=13.0M reduced=25.2M pruned=88.9M
              predicted=0  evals=50.6M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=0  aborts=0  data=0/1024  elap=1&#58;00
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;00
zullil
Posts: 6442
Joined: Tue Jan 09, 2007 12:31 am
Location: PA USA
Full name: Louis Zulli

Re: Crafty-23.3 very slow

Post by zullil »

Perhaps Bob has some ideas? I'm really stumped.
bob
Posts: 20943
Joined: Mon Feb 27, 2006 7:30 pm
Location: Birmingham, AL

Re: Crafty-23.3 very slow

Post by bob »

zullil wrote:Perhaps Bob has some ideas? I'm really stumped.
Here's my tests. First, 23.2 and 23.3 mt=1, your position, 30 secs:

time=30.12 mat=-1 n=108302664 fh=94% nps=3.6M
time=31.00 mat=-1 n=100567350 fh=88% nps=3.2M

ditto for mt=8:

time=30.95 mat=-1 n=681825282 fh=94% nps=22.0M
time=30.55 mat=-1 n=627401767 fh=87% nps=20.5M

That is not a Nehalem box, but it is a decent core-2 type machine with dual quad-cores. I can't imagine what would make the mt=8 run slower unless something else runs at the same time, or if you somehow have profiling or something turned on by accident...
zullil
Posts: 6442
Joined: Tue Jan 09, 2007 12:31 am
Location: PA USA
Full name: Louis Zulli

Re: Crafty-23.3 very slow

Post by zullil »

bob wrote:
zullil wrote:Perhaps Bob has some ideas? I'm really stumped.
Here's my tests. First, 23.2 and 23.3 mt=1, your position, 30 secs:

time=30.12 mat=-1 n=108302664 fh=94% nps=3.6M
time=31.00 mat=-1 n=100567350 fh=88% nps=3.2M

ditto for mt=8:

time=30.95 mat=-1 n=681825282 fh=94% nps=22.0M
time=30.55 mat=-1 n=627401767 fh=87% nps=20.5M

That is not a Nehalem box, but it is a decent core-2 type machine with dual quad-cores. I can't imagine what would make the mt=8 run slower unless something else runs at the same time, or if you somehow have profiling or something turned on by accident...
Thanks for the reply. I'm still mystified. I checked that each binary was running on 8 cores without competition from other apps.

These were built from the .zip archives on your ftp server. Any possibility that there's some debug code or something in the Crafty-23.3 source?
bob
Posts: 20943
Joined: Mon Feb 27, 2006 7:30 pm
Location: Birmingham, AL

Re: Crafty-23.3 very slow

Post by bob »

zullil wrote:
bob wrote:
zullil wrote:Perhaps Bob has some ideas? I'm really stumped.
Here's my tests. First, 23.2 and 23.3 mt=1, your position, 30 secs:

time=30.12 mat=-1 n=108302664 fh=94% nps=3.6M
time=31.00 mat=-1 n=100567350 fh=88% nps=3.2M

ditto for mt=8:

time=30.95 mat=-1 n=681825282 fh=94% nps=22.0M
time=30.55 mat=-1 n=627401767 fh=87% nps=20.5M

That is not a Nehalem box, but it is a decent core-2 type machine with dual quad-cores. I can't imagine what would make the mt=8 run slower unless something else runs at the same time, or if you somehow have profiling or something turned on by accident...
Thanks for the reply. I'm still mystified. I checked that each binary was running on 8 cores without competition from other apps.

These were built from the .zip archives on your ftp server. Any possibility that there's some debug code or something in the Crafty-23.3 source?
Looking at your one CPU tests, it does not look like it. There is a -DDEBUG option, but that typically drops NPS by 10x. And you would see it in the 1 cpu test as well.

Is this a real 8-core box or is it 4 cores with hyperthreading? It looks like 8 real cores from the 23.2 data, and looks like 4 real cores with 23.3. If this is a real 8-core box, just for fun I would turn hyperthreading off in the BIOS so that you won't run into odd process scheduling issues where there is more than one thread scheduled on a physical core...
zullil
Posts: 6442
Joined: Tue Jan 09, 2007 12:31 am
Location: PA USA
Full name: Louis Zulli

Re: Crafty-23.3 very slow

Post by zullil »

bob wrote: Looking at your one CPU tests, it does not look like it. There is a -DDEBUG option, but that typically drops NPS by 10x. And you would see it in the 1 cpu test as well.

Is this a real 8-core box or is it 4 cores with hyperthreading? It looks like 8 real cores from the 23.2 data, and looks like 4 real cores with 23.3. If this is a real 8-core box, just for fun I would turn hyperthreading off in the BIOS so that you won't run into odd process scheduling issues where there is more than one thread scheduled on a physical core...
This is an 8-core box, and I've checked again that 8 distinct cores are being utilized by each binary. I just did a comparison of 23.2 and 23.3 with smpmt=2, and the slowness of 23.3 is apparent even with just two threads (see below). I'm using the same Makefile, the same compiler and the same hardware for both versions. What's going on? :(

Code: Select all

LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.2&#93; ./crafty-23.2 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.2 &#40;8 cpus&#41;

White&#40;1&#41;&#58; smpmt=2
Warning--  xboard 'cores' option disabled
max threads set to 2.
White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
starting thread 1
                7->   0.05  -0.45   1. Bc4+ Be6 2. Bxe6+ Rxe6 3. Qg4 Kf7
                                    4. Bh4 Re2 5. Qc4+ Re6 &#40;s=3&#41;
                8     0.09  -0.67   1. Bc4+ Be6 2. Be3 f5 3. Bxe6+ Rxe6
                                    4. Qh5 Qf6 5. Rd5 Ne5 6. Nxe5 Rxe5
                                    &#40;s=2&#41;
                8     0.11  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5
                8->   0.13  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5 &#40;s=2&#41;
                9     0.19  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.25  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10     0.28  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.41  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=4&#41;
               11     0.49  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               11->   0.85  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=5&#41;
               12     1.11  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=4&#41;
               12->   2.93  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=8&#41;
               13     3.32  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=7&#41;
               13->   5.50  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=6&#41;
               14     6.49  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=5&#41;
               14->  11.35  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=5&#41;
               15    13.07  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6 &#40;s=4&#41;
               15->  25.37  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6 &#40;s=6&#41;
               16    33.67  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 Rb8 8. Be4 Ne5 9. Qxd7 Bxd7 &#40;s=5&#41;
              time=1&#58;00  mat=-1  n=492374976  fh=95%  nps=8.1M       
              extensions=31.1M qchecks=32.6M reduced=36.7M pruned=219.4M
              predicted=0  evals=47.6M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=1393  aborts=136  data=7/1024  elap=1&#58;00
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;00



LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.3&#93; ./crafty-23.3 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.3 &#40;8 cpus&#41;

White&#40;1&#41;&#58; smpmt=2
Warning--  xboard 'cores' option disabled
max threads set to 2.
White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
starting thread 1
                8->   0.07  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5
                9     0.09  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.12  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               10     0.14  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=2&#41;
               10->   0.18  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               11     0.22  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=2&#41;
               11->   0.30  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               12     0.37  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=2&#41;
               12->   0.60  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=5&#41;
               13     0.69  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=4&#41;
               13->   1.17  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=8&#41;
               14     1.43  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=7&#41;
               14->   2.31  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=6&#41;
               15     2.66  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=5&#41;
               15->   5.10  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=12&#41;
               16     5.68  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=11&#41;
               16->  10.57  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=11&#41;
               17    11.73  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=10&#41;
               17->  20.88  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=10&#41;
               18    30.97  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7 &#40;s=9&#41;
               18->  46.38  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7 &#40;s=2&#41;
               19    51.92  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Rb8 6. h4 Qd7 7. Bxb6
                                    axb6 8. h5 Ne5 9. Qa7 Rf8 10. Be4 Nxf3
                                    11. Bxf3
              time=1&#58;01  mat=-1  n=325469679  fh=90%  nps=5.3M       
              extensions=6.1M qchecks=17.9M reduced=36.2M pruned=125.8M
              predicted=0  evals=73.3M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=2076  aborts=254  data=8/1024  elap=1&#58;01
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;01
zullil
Posts: 6442
Joined: Tue Jan 09, 2007 12:31 am
Location: PA USA
Full name: Louis Zulli

Re: Crafty-23.3 very slow

Post by zullil »

Changing to gcc-4.2 has an interesting effect:

Code: Select all

LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/crafty-23.2&#93; ./crafty-23.2 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.2 &#40;8 cpus&#41;

White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
starting thread 1
starting thread 2
starting thread 3
starting thread 4
starting thread 5
starting thread 6
starting thread 7
                7->   0.04  -0.45   1. Bc4+ Be6 2. Bxe6+ Rxe6 3. Qg4 Kf7
                                    4. Bh4 Re2 5. Qc4+ Re6 &#40;s=2&#41;
                8     0.07  -0.67   1. Bc4+ Be6 2. Be3 f5 3. Bxe6+ Rxe6
                                    4. Qh5 Qf6 5. Rd5 Ne5 6. Nxe5 Rxe5
                8     0.09  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5
                8->   0.09  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5 &#40;s=2&#41;
                9     0.12  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 <HT>
                9->   0.15  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 <HT>
               10     0.18  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.25  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=6&#41;
               11     0.29  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=5&#41;
               11->   0.49  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=5&#41;
               12     0.66  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Be4 Bc4 5. a3 Ba5 6. b3 d5 7. bxc4
                                    Rxe4 8. Rxd5 Rxh4 9. Rxd7 Rxc4 &#40;s=4&#41;
               12->   1.47  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Be4 Bc4 5. a3 Ba5 6. b3 d5 7. bxc4
                                    Rxe4 8. Rxd5 Rxh4 9. Rxd7 Rxc4 &#40;s=7&#41;
               13     1.69  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qd5+ Qe6 6. Qb5 Bxf3 7.
                                    gxf3 Rb8 &#40;s=6&#41;
               13->   2.76  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qd5+ Qe6 6. Qb5 Bxf3 7.
                                    gxf3 Rb8 &#40;s=5&#41;
               14     3.33  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qd5+ Qe6 6. Qb5 Qc8 7. Rhg1
                                    Kh8 8. Qd5 &#40;s=4&#41;
               14->   6.27  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qd5+ Qe6 6. Qb5 Qc8 7. Rhg1
                                    Kh8 8. Qd5 &#40;s=5&#41;
               15     7.16  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qb5 Qc8 6. h4 a6 7. Qd5+
                                    Qe6 8. h5 Qxd5 9. Rxd5 &#40;s=4&#41;
               15->  14.68  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qb5 Qc8 6. h4 a6 7. Qd5+
                                    Qe6 8. h5 Qxd5 9. Rxd5 &#40;s=7&#41;
               16    19.99  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qb5 Qc8 6. h4 a6 7. Qd5+
                                    Qe6 8. h5 Qxd5 9. Rxd5 &#40;s=6&#41;
               16->  42.98  -0.57   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qd7 4.
                                    Qh5 Bg4 5. Qb5 Qc8 6. h4 a6 7. Qd5+
                                    Qe6 8. h5 Qxd5 9. Rxd5 &#40;s=5&#41;
               17    51.24  -0.58   1. Be3 Be6 2. Bg6 Re7 3. Kb1 Qf8 4.
                                    c3 Ba5 5. Rhe1 Bf7 6. Qg4 Bxg6+ 7.
                                    Qxg6 Qf7 8. Qf5 Qe6 9. Qxe6+ Rxe6 10.
                                    Rd5 &#40;s=4&#41;
              time=1&#58;00  mat=-1  n=954260745  fh=95%  nps=15.7M       
              extensions=57.4M qchecks=58.2M reduced=74.9M pruned=419.7M
              predicted=0  evals=109.7M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=154273  aborts=15370  data=76/1024  elap=1&#58;00
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;00

Code: Select all

LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.3&#93; ./crafty-23.3 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.3 &#40;8 cpus&#41;

White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
starting thread 1
starting thread 2
starting thread 3
starting thread 4
starting thread 5
starting thread 6
starting thread 7
                8     0.04  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5 &#40;s=3&#41;
                8->   0.05  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5
                9     0.06  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.07  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=2&#41;
               10     0.08  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.11  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=6&#41;
               11     0.14  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=5&#41;
               11->   0.18  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               12     0.25  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               12->   0.34  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=2&#41;
               13     0.41  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5
               13->   0.63  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=4&#41;
               14     0.71  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=3&#41;
               14->   1.11  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=8&#41;
               15     1.26  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=7&#41;
               15->   2.36  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=8&#41;
               16     2.60  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=7&#41;
               16->   4.95  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=11&#41;
               17     5.40  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=10&#41;
               17->  10.64  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=11&#41;
               18    13.88  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7 &#40;s=10&#41;
               18->  21.26  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7 &#40;s=5&#41;
               19    23.91  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Rb8 6. h4 Qd7 7. Bxb6
                                    axb6 8. h5 Ne5 9. Qa7 Rf8 10. Be4 Nxf3
                                    11. Bxf3 &#40;s=4&#41;
               19->  41.54  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Rb8 6. h4 Qd7 7. Bxb6
                                    axb6 8. h5 Ne5 9. Qa7 Rf8 10. Be4 Nxf3
                                    11. Bxf3 &#40;s=7&#41;
               20    45.87  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Rb8 6. h4 Qd7 7. Bxb6
                                    axb6 8. h5 Ne5 9. Qa7 Rf8 10. Be4 Nxf3
                                    11. Bxf3 &#40;s=6&#41;
              time=1&#58;01  mat=-1  n=800574854  fh=89%  nps=13.1M       
              extensions=15.9M qchecks=46.1M reduced=87.0M pruned=304.7M
              predicted=0  evals=180.9M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=160822  aborts=18070  data=56/1024  elap=1&#58;01
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;01
bob
Posts: 20943
Joined: Mon Feb 27, 2006 7:30 pm
Location: Birmingham, AL

Re: Crafty-23.3 very slow

Post by bob »

zullil wrote:
bob wrote: Looking at your one CPU tests, it does not look like it. There is a -DDEBUG option, but that typically drops NPS by 10x. And you would see it in the 1 cpu test as well.

Is this a real 8-core box or is it 4 cores with hyperthreading? It looks like 8 real cores from the 23.2 data, and looks like 4 real cores with 23.3. If this is a real 8-core box, just for fun I would turn hyperthreading off in the BIOS so that you won't run into odd process scheduling issues where there is more than one thread scheduled on a physical core...
Strange indeed. Is it possible to set up a remote login at some point? I could at least look at things as it runs and perhaps get an idea. Last time I ran on a Nehalem box it ran like the blazes. It might just need some tuning. One thing is for sure, LMR is way more aggressive (just compare the depths on your two 8-thread searches, the one running 1/2 normal speed went 3 plies deeper). It might be that smpsn needs tuning. If you want to run a few tests, try "smpsn=2000", smpsn=4000, and even smpsn=8000. Run a test for 60 secs, 8 threads, and run the same position 4 times. Then change the smpsn value and repeat. You can fine-tune it even better but usually changing by the above will at least point you in the right area to try...

I'll run a couple of these tests on my 8-core box to see if it is also sensitive to ths more than I realize...




This is an 8-core box, and I've checked again that 8 distinct cores are being utilized by each binary. I just did a comparison of 23.2 and 23.3 with smpmt=2, and the slowness of 23.3 is apparent even with just two threads (see below). I'm using the same Makefile, the same compiler and the same hardware for both versions. What's going on? :(

Code: Select all

LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.2&#93; ./crafty-23.2 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.2 &#40;8 cpus&#41;

White&#40;1&#41;&#58; smpmt=2
Warning--  xboard 'cores' option disabled
max threads set to 2.
White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
starting thread 1
                7->   0.05  -0.45   1. Bc4+ Be6 2. Bxe6+ Rxe6 3. Qg4 Kf7
                                    4. Bh4 Re2 5. Qc4+ Re6 &#40;s=3&#41;
                8     0.09  -0.67   1. Bc4+ Be6 2. Be3 f5 3. Bxe6+ Rxe6
                                    4. Qh5 Qf6 5. Rd5 Ne5 6. Nxe5 Rxe5
                                    &#40;s=2&#41;
                8     0.11  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5
                8->   0.13  -0.43   1. Be3 f5 2. c3 Ba5 3. Qh5 Qf6 4. Rhe1
                                    Ne5 &#40;s=2&#41;
                9     0.19  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.25  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10     0.28  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
               10->   0.41  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=4&#41;
               11     0.49  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               11->   0.85  -0.53   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=5&#41;
               12     1.11  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=4&#41;
               12->   2.93  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=8&#41;
               13     3.32  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=7&#41;
               13->   5.50  -0.64   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 Bb6 5. a3 f5 6. Bd5 Bxd5 7. Rxd5
                                    &#40;s=6&#41;
               14     6.49  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=5&#41;
               14->  11.35  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=5&#41;
               15    13.07  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6 &#40;s=4&#41;
               15->  25.37  -0.53   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 Bb6 &#40;s=6&#41;
               16    33.67  -0.55   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 Rb8 8. Be4 Ne5 9. Qxd7 Bxd7 &#40;s=5&#41;
              time=1&#58;00  mat=-1  n=492374976  fh=95%  nps=8.1M       
              extensions=31.1M qchecks=32.6M reduced=36.7M pruned=219.4M
              predicted=0  evals=47.6M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=1393  aborts=136  data=7/1024  elap=1&#58;00
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;00



LZsMacPro-OSX6&#58; ~/Documents/Chess/Crafty/Crafty-23.3&#93; ./crafty-23.3 
unable to open book file &#91;./Books/book.bin&#93;.
book is disabled
unable to open book file &#91;./Books/books.bin&#93;.
Warning--  xboard 'cores' option disabled
max threads set to 8.
EGTB access enabled
using tbpath=../TB
5 piece tablebase files found
14108kb of RAM used for TB indices and decompression tables
EGTB cache memory =  256M bytes.
Warning--  xboard 'memory' option disabled
hash table memory = 2048M bytes.
Warning--  xboard 'memory' option disabled
pawn hash table memory =  128M bytes.
choose from book moves randomly &#40;using weights.)
choose from 5 best moves.
pondering disabled.
Audio output disabled
 game/10 minutes primary time control


Crafty v23.3 &#40;8 cpus&#41;

White&#40;1&#41;&#58; smpmt=2
Warning--  xboard 'cores' option disabled
max threads set to 2.
White&#40;1&#41;&#58; setboard r2qr1k1/pppb2p1/2np1p1p/6B1/1b5Q/3B1N2/PPP2PPP/2KR3R w - - 0 1
White&#40;1&#41;&#58; st 60
search time set to 60.00.
White&#40;1&#41;&#58; display stats
display statistics at end of each search.
White&#40;1&#41;&#58; go
              time limit 1&#58;00 (+0.00&#41; &#40;1&#58;00&#41;
              depth   time  score   variation &#40;1&#41;
starting thread 1
                8->   0.07  -0.61   1. Be3 Ba5 2. Bg6 Re7 3. Qh5 Ne5 4.
                                    Nxe5 Rxe5
                9     0.09  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5
                9->   0.12  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               10     0.14  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=2&#41;
               10->   0.18  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               11     0.22  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=2&#41;
               11->   0.30  -0.63   1. Be3 Be6 2. Bg6 Re7 3. Be4 Ba5 4.
                                    Qh5 f5 5. Bd5 Bxd5 6. Rxd5 &#40;s=3&#41;
               12     0.37  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=2&#41;
               12->   0.60  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=5&#41;
               13     0.69  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=4&#41;
               13->   1.17  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Kb1 Qd7 5. Qh5 Bg4 6. Qd5+ Qe6 7. Rhe1
                                    Qxd5 8. Rxd5 &#40;s=8&#41;
               14     1.43  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=7&#41;
               14->   2.31  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 a5 &#40;s=6&#41;
               15     2.66  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=5&#41;
               15->   5.10  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=12&#41;
               16     5.68  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=11&#41;
               16->  10.57  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 bxc6 &#40;s=11&#41;
               17    11.73  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=10&#41;
               17->  20.88  -0.72   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Be4 f5 8. Bxc6 Qxc6 9. Qxc6 bxc6 &#40;s=10&#41;
               18    30.97  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7 &#40;s=9&#41;
               18->  46.38  -0.64   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Bxe3+ 6. Rxe3 Qd7 7.
                                    Qb5 a5 8. Rde1 Rd8 9. Qxb7 Bxa2 10.
                                    Rxe7 Nxe7 &#40;s=2&#41;
               19    51.92  -0.69   1. Be3 Be6 2. Bg6 Re7 3. c3 Ba5 4.
                                    Qa4 Bb6 5. Rhe1 Rb8 6. h4 Qd7 7. Bxb6
                                    axb6 8. h5 Ne5 9. Qa7 Rf8 10. Be4 Nxf3
                                    11. Bxf3
              time=1&#58;01  mat=-1  n=325469679  fh=90%  nps=5.3M       
              extensions=6.1M qchecks=17.9M reduced=36.2M pruned=125.8M
              predicted=0  evals=73.3M  50move=0  EGTBprobes=0  hits=0
              SMP->  splits=2076  aborts=254  data=8/1024  elap=1&#58;01
terminating SMP processes.
White&#40;1&#41;&#58; Be3
              time used&#58;   1&#58;01
zullil
Posts: 6442
Joined: Tue Jan 09, 2007 12:31 am
Location: PA USA
Full name: Louis Zulli

Re: Crafty-23.3 very slow

Post by zullil »

bob wrote: Strange indeed. Is it possible to set up a remote login at some point? I could at least look at things as it runs and perhaps get an idea. Last time I ran on a Nehalem box it ran like the blazes. It might just need some tuning. One thing is for sure, LMR is way more aggressive (just compare the depths on your two 8-thread searches, the one running 1/2 normal speed went 3 plies deeper). It might be that smpsn needs tuning. If you want to run a few tests, try "smpsn=2000", smpsn=4000, and even smpsn=8000. Run a test for 60 secs, 8 threads, and run the same position 4 times. Then change the smpsn value and repeat. You can fine-tune it even better but usually changing by the above will at least point you in the right area to try...

I'll run a couple of these tests on my 8-core box to see if it is also sensitive to ths more than I realize...
Varying the smpsn parameter had essentially no effect.

I'm coming to the conclusion that this is a gcc-related issue. Have you tried compiling with gcc? I know you use icc.

Here are summary results for 23.2 and 23.3 respectively, each compiled with three versions of gcc.

Code: Select all

gcc version 4.2.1 &#40;Apple Inc. build 5664&#41;
Crafty v23.2 &#40;8 cpus&#41;
              time=1&#58;02  mat=-1  n=820623467  fh=94%  nps=13.2M       

gcc version 4.4.4 &#40;GCC&#41; 
Crafty v23.2 &#40;8 cpus&#41;
              time=1&#58;00  mat=-1  n=1244905755  fh=94%  nps=20.7M      
 
gcc version 4.5.0 &#40;GCC&#41; 
Crafty v23.2 &#40;8 cpus&#41;
              time=1&#58;00  mat=-1  n=611061880  fh=94%  nps=10.1M       



gcc version 4.2.1 &#40;Apple Inc. build 5664&#41;
Crafty v23.3 &#40;8 cpus&#41;
              time=1&#58;01  mat=-1  n=823531770  fh=87%  nps=13.5M       

gcc version 4.4.4 &#40;GCC&#41; 
Crafty v23.3 &#40;8 cpus&#41;
              time=1&#58;00  mat=-1  n=484844694  fh=86%  nps=8.1M       

gcc version 4.5.0 &#40;GCC&#41; 
Crafty v23.3 &#40;8 cpus&#41;
              time=1&#58;02  mat=-1  n=531897007  fh=88%  nps=8.6M       
 
Here's the relevant portion of the Makefile. I changed the CC and CXX flags as needed.

Code: Select all

darwin&#58;
        $&#40;MAKE&#41; target=FreeBSD \
                CC=gcc-mp-4.5 CXX=g++-mp-4.5 \
                CFLAGS='-Wall -Wextra -pipe -O3' \
                CXFLAGS='-Wall -pipe -O3' \
                LDFLAGS=$&#40;LDFLAGS&#41; \
                LIBS='-lstdc++' \
                opt='$&#40;opt&#41; -DCPUS=8' \
                crafty-make
Some recent change in the Crafty source really affected gcc-4.4.