Time to depth measuring tool

[petero2]

I have written a program that can be used to measure "time to depth" for a UCI engine. The program creates a log file which can be processed by an octave script to produce a table with information similar to the result tables in Dr Hyatt's DTS article.

The program takes as input parameters: positions file, engine name, hash size, and a list of number of threads.

Each line in the input file contains a search depth and a FEN string. I have used 24 positions taken from the black side of the game in appendix A in the DTS article as input.

The program also takes a depth adjustment value as input parameter. This value is added to all depths from the input file so that you can easily adjust the total computation time without having to edit every line in the input file.

For each combination of position and number of threads, the chess engine is instructed to search to a given depth and the search time is measured by my program. The number of nodes searched and the PV score is extracted from the UCI "info" strings. The chess engine is restarted between all searches.

I ran this program to measure how Stockfish 3 behaves when the number of threads are 1,2,3,4. The test computer has a quad-core CPU identified as "Intel(R) Core(TM) i7-3820QM CPU @ 2.70GHz" by linux. I disabled turbo-boost while running these tests. The hash size was 256MB.

The first run gave the following results:

Code: Select all

pos  d     time   spd2   spd3   spd4      nodes     n2     n3     n4      nps   nps2   nps3   nps4 score   ds2   ds3   ds4
  1 21   65.513  2.980  2.514  3.431   89016943  0.665  1.153  1.085  1358770  1.983  2.898  3.722   -68   -28    16     4
  2 21   54.536  1.640  3.307  3.217   75851025  1.170  0.836  1.101  1390850  1.919  2.764  3.543  -109    53     4    41
  3 20   51.297  2.308  2.993  5.831   69127122  0.880  0.986  0.620  1347600  2.031  2.949  3.613   -64    -8    -8    12
  4 21   24.348  1.543  2.766  3.256   35737261  1.287  1.025  1.053  1467740  1.986  2.836  3.429   -44   -48    -8    12
  5 21   14.535  2.502  2.348  2.951   20552547  0.786  1.152  1.211  1413990  1.967  2.704  3.575   -20   -16   -16     4
  6 22   41.273  1.474  2.902  5.286   61171947  1.246  0.937  0.636  1482130  1.836  2.719  3.363     0     0     0   -16
  7 21   70.389  2.538  7.106  9.624  107208604  0.773  0.396  0.367  1523080  1.962  2.813  3.534   -88    -4   -33     0
  8 21   76.226  3.340  4.056  6.647  117539822  0.581  0.698  0.549  1542000  1.939  2.830  3.647   -84    -8     0    -4
  9 21   38.030  2.825  4.189  5.896   58503107  0.687  0.664  0.616  1538330  1.941  2.784  3.634  -105    17    13    21
 10 21   71.388  1.191  2.104  1.774  106923246  1.606  1.336  2.059  1497780  1.913  2.812  3.653  -169    12   -53   -16
 11 21   17.718  2.267  2.880  3.266   28488510  0.861  0.968  1.093  1607860  1.953  2.790  3.570    32     8   -32    12
 12 23   44.397  3.899  7.221  4.566   73156418  0.493  0.382  0.771  1647790  1.921  2.761  3.518     0    32     4    36
 13 22   22.519  2.312  2.661  5.080   37957137  0.837  1.054  0.643  1685530  1.936  2.805  3.265    52   -24   -16     4
 14 22   20.730  2.366  6.033  5.188   34272374  0.820  0.470  0.659  1653250  1.941  2.835  3.418     0     8     8     0
 15 22    8.465  1.952  3.313  3.277   14463822  1.013  0.846  1.065  1708570  1.977  2.802  3.490     0     0     0     0
 16 23   19.037  1.613  2.442  2.900   30790704  1.231  1.151  1.250  1617440  1.986  2.811  3.624     0     0     0    12
 17 24   20.413  2.026  2.552  3.833   35392906  0.996  1.151  0.969  1733830  2.018  2.937  3.716     0     0     0     0
 18 23    6.917  1.883  2.186  2.068   12772264  1.048  1.284  1.742  1846560  1.973  2.807  3.604     0     0     0     0
 19 22    5.457  1.446  1.639  2.455   10567309  1.297  1.579  1.375  1936460  1.875  2.589  3.376     0     0     0     0
 20 24  129.242  4.041  4.950  4.314  269410409  0.484  0.608  0.911  2084550  1.958  3.012  3.928   185   -60  -101   -68
 21 22   22.433  1.338  2.486  2.114   46535552  1.476  1.121  1.805  2074450  1.974  2.788  3.816    80    69    41    -8
 22 21   50.785  3.326  3.446  5.389  112778695  0.605  0.829  0.651  2220700  2.014  2.855  3.510   157     8   -12   -44
 23 21   42.638  2.526  4.425  9.238   94104217  0.768  0.639  0.392  2207040  1.940  2.826  3.619   113    48     8    48
 24 22  120.528  3.620  3.481  4.768  268512025  0.544  0.840  0.770  2227790  1.968  2.925  3.671   319   -65   -89   -16
avg      43.284  2.373  3.500  4.432   75451415  0.923  0.921  0.975  1700587  1.955  2.819  3.576

Explanation of the columns:
d: Search depth
time: Search time when using 1 thread
spdX: Search time when using 1 thread divided by search time when using X threads
nodes: Number of nodes searched when using 1 thread
nX: Number of nodes searched when using X threads divided by number of nodes searched when using 1 thread
nps: Nodes per second when using 1 thread
npsX: Nodes per second when using X threads divided by nodes per second when using 1 thread
score: Score corresponding to PV when using 1 thread
dsX: Score corresponding to PV when using X threads minus score corresponding to PV when using 1 thread

The last row contains averages for each column where I think the average is meaningful.

Since the table shows some anomalies, I ran the same test again:

Code: Select all

pos  d     time   spd2   spd3   spd4      nodes     n2     n3     n4      nps   nps2   nps3   nps4 score   ds2   ds3   ds4
  1 21   65.573  2.199  2.150  4.626   89016943  0.908  1.349  0.794  1357520  1.996  2.900  3.671   -68    -8     0     8
  2 21   53.610  4.353  2.578  3.218   75851025  0.444  1.089  1.110  1414880  1.932  2.806  3.573  -109    21    33    37
  3 20   49.741  2.552  4.585  4.105   69127122  0.763  0.615  0.885  1389730  1.948  2.820  3.633   -64     0   -12    -4
  4 21   24.351  2.601  6.063  4.195   35737261  0.738  0.454  0.833  1467600  1.918  2.751  3.494   -44    12   -40    -4
  5 21   14.431  1.650  1.132  2.778   20552547  1.189  2.463  1.263  1424200  1.962  2.789  3.508   -20    20    28    20
  6 22   41.420  3.018  2.623  2.686   61171947  0.650  1.053  1.269  1476880  1.962  2.763  3.410     0    -8     8     0
  7 21   70.295  2.580  5.267  4.375  107208604  0.761  0.540  0.843  1525120  1.962  2.846  3.689   -88   -17   -13   -49
  8 21   76.660  2.795  3.625  6.012  117539822  0.693  0.780  0.610  1533270  1.937  2.827  3.666   -84     4    -4    -8
  9 21   38.009  4.137  4.296  8.493   58503107  0.473  0.662  0.425  1539190  1.958  2.844  3.612  -105    17    41    21
 10 21   71.748  1.860  2.286  3.614  106923246  1.047  1.234  1.016  1490260  1.947  2.820  3.672  -169   -24   -12     8
 11 21   17.695  1.956  2.651  4.020   28488510  1.016  1.035  0.857  1609990  1.987  2.744  3.447    32   -20   -20   -16
 12 23   44.536  4.023  7.622  6.077   73156418  0.488  0.363  0.579  1642640  1.962  2.767  3.521     0    12    28     0
 13 22   22.481  2.485  4.657  4.161   37957137  0.783  0.584  0.850  1688420  1.946  2.718  3.536    52   -20   -12   -12
 14 22   20.600  3.502  4.249  4.815   34272374  0.545  0.637  0.722  1663740  1.910  2.705  3.478     0     0     0     0
 15 22    8.475  1.861  1.261  4.182   14463822  1.057  2.191  0.829  1706610  1.968  2.764  3.467     0     0     0     0
 16 23   19.066  1.591  4.085  2.140   30790704  1.241  0.684  1.665  1614960  1.975  2.794  3.562     0     0     0     0
 17 24   20.318  1.564  2.936  3.996   35392906  1.273  0.970  0.903  1741990  1.991  2.849  3.607     0     0     0     0
 18 23    6.883  1.725  2.061  2.549   12772264  1.126  1.353  1.381  1855660  1.943  2.788  3.521     0     0     0     0
 19 22    5.449  2.188  2.826  3.868   10567309  0.867  0.949  0.849  1939400  1.897  2.684  3.285     0     0     0     0
 20 24  129.578  5.393  5.200  6.159  269410409  0.358  0.569  0.613  2079130  1.932  2.956  3.774   185   -84   -97   -89
 21 22   22.512  1.766  1.775  1.959   46535552  1.191  1.738  1.960  2067100  2.103  3.084  3.839    80    12    25    12
 22 21   50.564  1.680  4.154  4.488  112778695  1.186  0.681  0.791  2230410  1.993  2.829  3.550   157   -28     0     8
 23 21   42.536  1.542  3.210  3.744   94104217  1.286  0.903  0.971  2212320  1.983  2.898  3.635   113     8    44    52
 24 22  120.458  3.613  4.064  6.431  268512025  0.547  0.705  0.568  2229090  1.978  2.865  3.653   319   -69   -69   -73
avg      43.208  2.610  3.556  4.279   75451415  0.860  0.983  0.941  1704171  1.962  2.817  3.575

As expected, the single thread node values are the same and the single thread search times are quite repeatable. The multi-thread values differ quite a bit though.

I then ran the test again with the search depth increased by one. I ran this test twice and the table below shows the two runs interleaved to make it easier to compare differences for the same positions:

Code: Select all

pos  d     time   spd2   spd3   spd4      nodes     n2     n3     n4      nps   nps2   nps3   nps4 score   ds2   ds3   ds4
  1 22  121.177  3.028  3.545  6.706  165279257  0.653  0.818  0.554  1363950  1.977  2.899  3.716   -24   -36    -4   -48
  1 22  121.244  2.337  4.874  4.537  165279257  0.846  0.585  0.816  1363200  1.976  2.853  3.702   -24     0   -44   -32
  2 22   68.758  1.452  3.639  2.636   96583487  1.337  0.772  1.399  1404700  1.941  2.808  3.688   -72    20     0    -4
  2 22   69.048  2.393  3.669  2.331   96583487  0.812  0.746  1.583  1398790  1.944  2.736  3.691   -72   -12    16   -12
  3 21   55.092  1.750  2.824  2.687   76453587  1.128  1.018  1.383  1387730  1.975  2.874  3.716   -64   -12     4   -32
  3 21   55.412  2.156  1.598  3.130   76453587  0.914  1.826  1.189  1379730  1.971  2.918  3.723   -64   -53     4   -45
  4 22   37.627  2.636  5.620  5.014   55408314  0.738  0.498  0.685  1472550  1.944  2.797  3.433   -32   -12     0     0
  4 22   37.608  1.459  2.327  6.210   55408314  1.333  1.206  0.557  1473330  1.945  2.807  3.460   -32   -28     8    -4
  5 22   33.992  2.271  3.440  6.801   48025183  0.877  0.831  0.527  1412850  1.991  2.858  3.585    -8     8   -12   -16
  5 22   34.122  2.526  2.954  4.671   48025183  0.803  0.985  0.783  1407460  2.028  2.910  3.658    -8     8    12     4
  6 23   44.802  1.868  2.150  3.825   66488508  1.012  1.277  0.894  1484040  1.890  2.747  3.418     0     8    -4   -40
  6 23   44.837  1.548  1.683  1.466   66488508  1.207  1.630  2.384  1482880  1.869  2.744  3.494     0   -16     8     0
  7 22   74.751  2.660  5.331  4.546  113730769  0.738  0.534  0.813  1521460  1.962  2.847  3.694   -88   -21    -4   -37
  7 22   75.242  4.471  4.991  4.435  113730769  0.440  0.571  0.842  1511530  1.967  2.850  3.732   -88   -25   -33   -33
  8 22   98.524  1.381  2.527  2.465  151002320  1.420  1.142  1.529  1532640  1.962  2.885  3.770   -96    28    24     4
  8 22   98.447  1.305  1.822  2.907  151002320  1.518  1.593  1.293  1533840  1.980  2.902  3.759   -96    12    -9    16
  9 22   78.772  2.231  5.647  2.186  120875281  0.876  0.509  1.712  1534490  1.955  2.876  3.742   -80   -12     4     8
  9 22   79.136  3.175  4.836  6.014  120875281  0.612  0.594  0.629  1527440  1.943  2.871  3.784   -80   -12    -4     4
 10 22  129.061  1.378  2.023  2.630  189475079  1.433  1.444  1.433  1468110  1.976  2.922  3.769  -197   -13    36    20
 10 22  128.178  1.470  1.922  2.267  189475079  1.322  1.508  1.637  1478210  1.943  2.898  3.711  -197   -17    -5    12
 11 22   32.770  1.497  2.167  4.287   53385651  1.319  1.266  0.825  1629080  1.974  2.745  3.537    28     0   -28   -20
 11 22   32.610  2.570  4.916  4.592   53385651  0.749  0.551  0.754  1637110  1.925  2.709  3.462    28   -12   -20     4
 12 24   80.374  4.560  5.561  9.606  131564762  0.426  0.504  0.367  1636900  1.943  2.801  3.530    36   -16     0   -20
 12 24   80.653  4.368  8.391  4.335  131564762  0.451  0.335  0.845  1631230  1.969  2.812  3.661    36   -16   -20    -8
 13 23   42.463  3.542  3.536  4.275   71044174  0.547  0.777  0.835  1673070  1.938  2.746  3.569    56    -4   -16   -28
 13 23   42.263  3.077  4.590  6.276   71044174  0.646  0.603  0.543  1681000  1.988  2.769  3.406    56    -4   -20   -20
 14 23   27.547  2.744  3.277  4.763   46889051  0.686  0.840  0.731  1702130  1.881  2.752  3.484    16   -16   -16   -16
 14 23   27.465  2.219  3.832  3.561   46889051  0.876  0.713  0.953  1707230  1.943  2.734  3.394    16     4   -16   -16
 15 23   13.247  2.703  2.587  1.929   22961913  0.710  1.058  1.846  1733370  1.918  2.737  3.562     0     0     0     0
 15 23   13.338  2.027  4.029  5.206   22961913  0.976  0.710  0.683  1721490  1.978  2.860  3.557     0     0     0     0
 16 24   30.549  2.264  1.811  2.867   48876007  0.901  1.585  1.290  1599920  2.040  2.870  3.698     0     0     0     0
 16 24   30.497  2.738  4.028  2.696   48876007  0.720  0.708  1.436  1602670  1.971  2.852  3.871     0     0     0     0
 17 25   36.655  1.660  2.928  4.672   64055314  1.216  1.006  0.797  1747530  2.019  2.946  3.726     0     0     0     0
 17 25   36.532  2.352  3.326  5.703   64055314  0.853  0.855  0.632  1753410  2.005  2.844  3.603     0     0     0     0
 18 24   12.552  2.043  3.239  3.670   23243766  0.938  0.844  0.956  1851760  1.916  2.734  3.510     0     0     0     0
 18 24   12.599  2.157  3.052  3.400   23243766  0.907  0.916  1.032  1844910  1.956  2.795  3.508     0     0     0     0
 19 23    7.955  2.496  2.525  3.289   15303973  0.783  1.082  1.054  1923720  1.954  2.733  3.465     0     0     0     0
 19 23    7.914  2.706  2.704  3.004   15303973  0.721  1.004  1.133  1933740  1.950  2.715  3.403     0     0     0     0
 20 25  134.136  5.992  7.861  3.606  279594461  0.324  0.350  1.091  2084410  1.941  2.754  3.935   169  -101   -60   -68
 20 25  134.407  2.176  3.575  3.740  279594461  0.932  0.842  1.052  2080210  2.028  3.011  3.934   169   -56   -85   -93
 21 23   25.198  1.934  1.590  1.592   52342243  1.100  1.891  2.483  2077210  2.127  3.007  3.954    80    -4   -12    16
 21 23   25.120  1.000  1.782  0.964   52342243  1.945  1.737  3.997  2083660  1.945  3.095  3.852    80    73     8    16
 22 22   86.892  1.457  4.170  6.568  193558186  1.357  0.681  0.544  2227570  1.977  2.842  3.572   165    -4   -16     8
 22 22   87.157  2.872  3.413  7.397  193558186  0.682  0.834  0.490  2220790  1.959  2.848  3.628   165   -52     4   -40
 23 22  100.212  1.810  8.213  8.999  221910499  1.088  0.350  0.401  2214410  1.970  2.877  3.607   165    28   -36    -8
 23 22  100.290  8.050  4.065  6.013  221910499  0.244  0.708  0.616  2212690  1.968  2.876  3.704   165   -16     8   -12
 24 23  136.094  1.470  6.975  8.292  302994454  1.333  0.409  0.435  2226360  1.958  2.851  3.609   319   -41  -182   -89
 24 23  136.530  2.821  2.938  5.227  302994454  0.701  0.988  0.689  2219250  1.976  2.901  3.599   319   -93    -8   -73
avg      62.914  2.517  3.719  4.333  108793593  0.920  0.922  1.066  1704078  1.964  2.838  3.637

I'm not sure what conclusions can be drawn from these tests, but it at least appears that it will not be as simple as I thought to measure the performance of the multi-threaded search in my chess engine.

[mcostalba]

Code: Select all

pos  d     time   spd2   spd3   spd4      nodes     n2     n3     n4      nps   nps2   nps3   nps4 score   ds2   ds3   ds4
avg      62.914  2.517  3.719  4.333  108793593  0.920  0.922  1.066  1704078  1.964  2.838  3.637

Thanks, very interesting results.

While was somehow expected that with increasing threads the nps does not scale linearly and the efficiency is not 100%, but 1.964 2.838 3.637 instead of theoretical max 2 3 4, I was surprised by spdx results.

Instead of 2 3 4 here we get 2.517 3.719 4.333, so it means time to depth of single thread case is more than the double of when using 2 threads and more than the triple of when using 3 threads and, finally, more than 4 times of when using 4 threads.

It is like adding threads helps to reach time to depth faster, much faster than what you can expect by the number of threads running.

This is an interesting phenomenon, it is like with more threads you have more probability to find a cut-off earlier, and so proceed with depth faster. This is of course clear, what is a surprise is that you find it even earlier than what you can expect from the number of threads running.....it is perhaps due to the fact that cut-off are more common at the beginning of a move list, so if you have 4 threads working of 4 different move list you can expect to find a cut-off, on average, more than 4 times earlier than a single threads that sequentially goes across all the 4 move lists.

IOW if you have 4 move lists of 40 moves each and the cut-off move is the tenth move of the second list in single thread case you will find it after trying 50 moves, in case of 4 threads working in parallel, but all starting from the beginning of each list you find it after trying 40 moves !

[Adam Hair]

Miguel and I have been doing a similar study over the past 3 weeks. The process I use to generate, extract, and process the data is definitely more arduous

There are two things I would like to share:

We are currently studying how the speed up from 1 core to 4 cores changes as depth increases. Miguel has a model for this behavior that is based on Amdahl's law and Gaviota's SMP implementation. As it turns out, his model fitted very well to my data (which was for 1500 positions from depth 6 to depth 17).



I am currently trying to generate new data to study this behavior at higher depths (though I have had to start over twice due to motherboard troubles). But it is clear that the speed up from 1 to n cores is dependent on depth.

Also, the distribution of the speed up from 1 to n cores over multiple positions is positively skewed for the engines I have studied (most likely the consequence of the speed up being a positive ratio). So, the median or geometric mean would be a better description of the typical speed up than the arithmetic mean. The following is a histogram of Gaviota's speed up at depth 16 for 1500 positions (other engines have a similar behavior):

[Sven]

Hi Peter,

are these average values weighted, e.g. by the number of nodes, or simple arithmetic averages?

Sven

[petero2]

Hi Peter,

are these average values weighted, e.g. by the number of nodes, or simple arithmetic averages?

Hi Sven. They are not weighted. They are just the unweighted arithmetic mean of the values above in the same column. I think it is hard to draw conclusions based on these averages when the individual values vary so much. I think you need a lot more positions to be able to say something with statistical significance.

[Joerg Oster]

Code: Select all

pos  d     time   spd2   spd3   spd4      nodes     n2     n3     n4      nps   nps2   nps3   nps4 score   ds2   ds3   ds4
avg      62.914  2.517  3.719  4.333  108793593  0.920  0.922  1.066  1704078  1.964  2.838  3.637

Thanks, very interesting results.

While was somehow expected that with increasing threads the nps does not scale linearly and the efficiency is not 100%, but 1.964 2.838 3.637 instead of theoretical max 2 3 4, I was surprised by spdx results.

Instead of 2 3 4 here we get 2.517 3.719 4.333, so it means time to depth of single thread case is more than the double of when using 2 threads and more than the triple of when using 3 threads and, finally, more than 4 times of when using 4 threads.

It is like adding threads helps to reach time to depth faster, much faster than what you can expect by the number of threads running.

This is an interesting phenomenon, it is like with more threads you have more probability to find a cut-off earlier, and so proceed with depth faster. This is of course clear, what is a surprise is that you find it even earlier than what you can expect from the number of threads running.....it is perhaps due to the fact that cut-off are more common at the beginning of a move list, so if you have 4 threads working of 4 different move list you can expect to find a cut-off, on average, more than 4 times earlier than a single threads that sequentially goes across all the 4 move lists.

IOW if you have 4 move lists of 40 moves each and the cut-off move is the tenth move of the second list in single thread case you will find it after trying 50 moves, in case of 4 threads working in parallel, but all starting from the beginning of each list you find it after trying 40 moves !

Marco, please be aware that not all positions have been searched up to the same depth. Some positions to 21, others to 22, 23, etc. This might explain these somewhat suspicious numbers...
I think all positions should be searched to the same depth, and at least 4 x, to get reliable numbers.

[Joerg Oster]

Take a look here http://www.talkchess.com/forum/viewtopi ... 18&t=48503
These are more reasonable time-to-depth ratios, don't you agree?

[Laskos]

Very interesting, Adam. I have no possibility to check at very shallow depths 1->4 cores speedup, as the granularity of what I get is 1 second, nevertheless I did it for Houdini 3 for depth from 14 to 21, and fitted to a shifted logistic. What you fitted the data with? Simple Amdahl's a*x/(b + x) doesn't work well. The last point (depth 21) I got in 3 hours, 30 positions repeated 5 times.


Are you sure that the limiting value is 4 and not nps(4 cores)/nps(1 core)? Very good observation that TTD is dependent on depth.

[Macintosh]

Very nice results, indeed.

Regarding the speedup: My guts tell me, there might be a transition from the typical PVS-like depth-first search to more of a best-first search with every additional thread working on ALL-nodes.

Extending this idea, it might turn out to be more efficient for a one-thread search performing a mix of a depth-first and best-first approach. But how to realize that? Just a thought I could not keep to myself.

Does this make any sense?

Regards


Marcus

[Adam Hair]

Very interesting, Adam. I have no possibility to check at very shallow depths 1->4 cores speedup, as the granularity of what I get is 1 second, nevertheless I did it for Houdini 3 for depth from 14 to 21, and fitted to a shifted logistic. What you fitted the data with? Simple Amdahl's a*x/(b + x) doesn't work well. The last point (depth 21) I got in 3 hours, 30 positions repeated 5 times.


Are you sure that the limiting value is 4 and not nps(4 cores)/nps(1 core)? Very good observation that TTD is dependent on depth.

Kai, both of my motherboards have died in the past 3 days, so I am forced to use my phone until I can replace my computers. I can partially answer your questions, and perhaps Miguel can answer in more detail.

Miguel determined equations for nodes(n cores) and nodes(1 core) as functions of depth and then inserted them into Amdahl's law. For his model with 4 cores, speedup -> 4 as depth -> infinite. As for myself, like you I also found a shifted logistic that fit my data very well. My logistic only uses 3 parameters, where Miguel's uses 4. However, Miguel's model is derived from knowledge about Gaviota and Amdahl's law, so I think it should be studied in greater detail. I was in the process of doing that when my computer problems began. As soon as I can, I am going to resume the research. I just do not know when that will be.