From 161c6b025e763d6bcc8339a614be312f2b173437 Mon Sep 17 00:00:00 2001 From: Marco Costalba Date: Sat, 3 Mar 2012 09:35:56 +0100 Subject: [PATCH] Rewrite time measurement code Introduce and use a new Time class designed after QTime, from Qt framework. Should be a more clear and self documented code. As an added benefit we now use 64 bits internally to get millisecs from system time. This avoids to wrap around to 0 every 2^32 milliseconds, which is 49.71 days. No functional change. Signed-off-by: Marco Costalba --- src/benchmark.cpp | 9 ++++----- src/book.cpp | 2 +- src/misc.cpp | 26 +++----------------------- src/misc.h | 15 ++++++++++++++- src/search.cpp | 42 ++++++++++++++---------------------------- src/types.h | 15 +++++++++++++++ src/uci.cpp | 10 +++++----- 7 files changed, 56 insertions(+), 63 deletions(-) diff --git a/src/benchmark.cpp b/src/benchmark.cpp index ba05ac7f..4735729a 100644 --- a/src/benchmark.cpp +++ b/src/benchmark.cpp @@ -61,7 +61,6 @@ void benchmark(int argc, char* argv[]) { vector fens; Search::LimitsType limits; - int time; int64_t nodes = 0; // Assign default values to missing arguments @@ -104,7 +103,7 @@ void benchmark(int argc, char* argv[]) { else fens.assign(Defaults, Defaults + 16); - time = system_time(); + Time time = Time::current_time(); for (size_t i = 0; i < fens.size(); i++) { @@ -125,10 +124,10 @@ void benchmark(int argc, char* argv[]) { } } - time = system_time() - time; + int e = time.elapsed(); cerr << "\n===========================" - << "\nTotal time (ms) : " << time + << "\nTotal time (ms) : " << e << "\nNodes searched : " << nodes - << "\nNodes/second : " << int(nodes / (time / 1000.0)) << endl; + << "\nNodes/second : " << int(nodes / (e / 1000.0)) << endl; } diff --git a/src/book.cpp b/src/book.cpp index 1dd5aa6d..1baafbba 100644 --- a/src/book.cpp +++ b/src/book.cpp @@ -342,7 +342,7 @@ namespace { Book::Book() : size(0) { - for (int i = abs(system_time() % 10000); i > 0; i--) + for (int i = Time::current_time().msec() % 10000; i > 0; i--) RKiss.rand(); // Make random number generation less deterministic } diff --git a/src/misc.cpp b/src/misc.cpp index a3b1b032..99deedcc 100644 --- a/src/misc.cpp +++ b/src/misc.cpp @@ -19,15 +19,11 @@ #if defined(_WIN32) || defined(_WIN64) -#define _CRT_SECURE_NO_DEPRECATE #define NOMINMAX // disable macros min() and max() #include -#include #else -# include -# include # include # if defined(__hpux) # include @@ -77,12 +73,12 @@ const string engine_info(bool to_uci) { s << "Stockfish " << Tag << setfill('0') << " " << year.substr(2) << setw(2) << (1 + months.find(month) / 4) - << setw(2) << day << cpu64 << popcnt; + << setw(2) << day; } else - s << "Stockfish " << Version << cpu64 << popcnt; + s << "Stockfish " << Version; - s << (to_uci ? "\nid author ": " by ") + s << cpu64 << popcnt << (to_uci ? "\nid author ": " by ") << "Tord Romstad, Marco Costalba and Joona Kiiski"; return s.str(); @@ -109,22 +105,6 @@ void dbg_print() { } -/// system_time() returns the current system time, measured in milliseconds - -int system_time() { - -#if defined(_WIN32) || defined(_WIN64) - struct _timeb t; - _ftime(&t); - return int(t.time * 1000 + t.millitm); -#else - struct timeval t; - gettimeofday(&t, NULL); - return t.tv_sec * 1000 + t.tv_usec / 1000; -#endif -} - - /// cpu_count() tries to detect the number of CPU cores int cpu_count() { diff --git a/src/misc.h b/src/misc.h index 0569e468..cda0ef59 100644 --- a/src/misc.h +++ b/src/misc.h @@ -27,7 +27,6 @@ #include "types.h" extern const std::string engine_info(bool to_uci = false); -extern int system_time(); extern int cpu_count(); extern void timed_wait(WaitCondition&, Lock&, int); extern void prefetch(char* addr); @@ -42,9 +41,23 @@ extern Move move_from_uci(const Position& pos, const std::string& str); extern const std::string move_to_uci(Move m, bool chess960); extern const std::string move_to_san(Position& pos, Move m); + struct Log : public std::ofstream { Log(const std::string& f = "log.txt") : std::ofstream(f.c_str(), std::ios::out | std::ios::app) {} ~Log() { if (is_open()) close(); } }; + +class Time { +public: + void restart() { system_time(&t); } + uint64_t msec() const { return time_to_msec(t); } + int elapsed() const { return int(current_time().msec() - time_to_msec(t)); } + + static Time current_time() { Time t; t.restart(); return t; } + +private: + my_time_t t; +}; + #endif // !defined(MISC_H_INCLUDED) diff --git a/src/search.cpp b/src/search.cpp index 40f14a50..f71b54bc 100644 --- a/src/search.cpp +++ b/src/search.cpp @@ -117,6 +117,7 @@ namespace { size_t MultiPV, UCIMultiPV, PVIdx; TimeManager TimeMgr; + Time SearchTime; int BestMoveChanges; int SkillLevel; bool SkillLevelEnabled, Chess960; @@ -138,7 +139,6 @@ namespace { bool connected_threat(const Position& pos, Move m, Move threat); Value refine_eval(const TTEntry* tte, Value defaultEval, int ply); Move do_skill_level(); - int elapsed_time(bool reset = false); string score_to_uci(Value v, Value alpha = -VALUE_INFINITE, Value beta = VALUE_INFINITE); void pv_info_to_log(Position& pos, int depth, Value score, int time, Move pv[]); void pv_info_to_uci(const Position& pos, int depth, Value alpha, Value beta); @@ -251,7 +251,7 @@ void Search::think() { Position& pos = RootPosition; Chess960 = pos.is_chess960(); - elapsed_time(true); + SearchTime.restart(); TimeMgr.init(Limits, pos.startpos_ply_counter()); TT.new_search(); H.clear(); @@ -325,7 +325,7 @@ void Search::think() { if (Options["Use Search Log"]) { - int e = elapsed_time(); + int e = SearchTime.elapsed(); Log log(Options["Search Log Filename"]); log << "Nodes: " << pos.nodes_searched() @@ -433,7 +433,7 @@ namespace { // Send full PV info to GUI if we are going to leave the loop or // if we have a fail high/low and we are deep in the search. - if ((bestValue > alpha && bestValue < beta) || elapsed_time() > 2000) + if ((bestValue > alpha && bestValue < beta) || SearchTime.elapsed() > 2000) pv_info_to_uci(pos, depth, alpha, beta); // In case of failing high/low increase aspiration window and @@ -464,7 +464,7 @@ namespace { skillBest = do_skill_level(); if (!Signals.stop && Options["Use Search Log"]) - pv_info_to_log(pos, depth, bestValue, elapsed_time(), &RootMoves[0].pv[0]); + pv_info_to_log(pos, depth, bestValue, SearchTime.elapsed(), &RootMoves[0].pv[0]); // Filter out startup noise when monitoring best move stability if (depth > 2 && BestMoveChanges) @@ -482,14 +482,14 @@ namespace { // Stop search if most of available time is already consumed. We // probably don't have enough time to search the first move at the // next iteration anyway. - if (elapsed_time() > (TimeMgr.available_time() * 62) / 100) + if (SearchTime.elapsed() > (TimeMgr.available_time() * 62) / 100) stop = true; // Stop search early if one move seems to be much better than others if ( depth >= 12 && !stop && ( (bestMoveNeverChanged && pos.captured_piece_type()) - || elapsed_time() > (TimeMgr.available_time() * 40) / 100)) + || SearchTime.elapsed() > (TimeMgr.available_time() * 40) / 100)) { Value rBeta = bestValue - EasyMoveMargin; (ss+1)->excludedMove = RootMoves[0].pv[0]; @@ -858,7 +858,7 @@ split_point_start: // At split points actual search starts from here { Signals.firstRootMove = (moveCount == 1); - if (pos.thread() == 0 && elapsed_time() > 2000) + if (pos.thread() == 0 && SearchTime.elapsed() > 2000) cout << "info depth " << depth / ONE_PLY << " currmove " << move_to_uci(move, Chess960) << " currmovenumber " << moveCount + PVIdx << endl; @@ -1524,20 +1524,6 @@ split_point_start: // At split points actual search starts from here } - // current_search_time() returns the number of milliseconds which have passed - // since the beginning of the current search. - - int elapsed_time(bool reset) { - - static int searchStartTime; - - if (reset) - searchStartTime = system_time(); - - return system_time() - searchStartTime; - } - - // score_to_uci() converts a value to a string suitable for use with the UCI // protocol specifications: // @@ -1566,7 +1552,7 @@ split_point_start: // At split points actual search starts from here void pv_info_to_uci(const Position& pos, int depth, Value alpha, Value beta) { - int t = elapsed_time(); + int t = SearchTime.elapsed(); int selDepth = 0; for (int i = 0; i < Threads.size(); i++) @@ -1698,7 +1684,7 @@ split_point_start: // At split points actual search starts from here static RKISS rk; // PRNG sequence should be not deterministic - for (int i = abs(system_time() % 50); i > 0; i--) + for (int i = Time::current_time().msec() % 50; i > 0; i--) rk.rand(); // RootMoves are already sorted by score in descending order @@ -1902,18 +1888,18 @@ void Thread::idle_loop(SplitPoint* sp_master) { void check_time() { - static int lastInfoTime; - int e = elapsed_time(); + static Time lastInfoTime = Time::current_time(); - if (system_time() - lastInfoTime >= 1000 || !lastInfoTime) + if (lastInfoTime.elapsed() >= 1000) { - lastInfoTime = system_time(); + lastInfoTime.restart(); dbg_print(); } if (Limits.ponder) return; + int e = SearchTime.elapsed(); bool stillAtFirstMove = Signals.firstRootMove && !Signals.failedLowAtRoot && e > TimeMgr.available_time(); diff --git a/src/types.h b/src/types.h index 6c9c425e..d907006c 100644 --- a/src/types.h +++ b/src/types.h @@ -44,6 +44,7 @@ #pragma warning(disable: 4127) // Conditional expression is constant #pragma warning(disable: 4146) // Unary minus operator applied to unsigned type #pragma warning(disable: 4800) // Forcing value to bool 'true' or 'false' +#pragma warning(disable: 4996) // Function _ftime() may be unsafe // MSVC does not support typedef signed __int8 int8_t; @@ -59,6 +60,20 @@ typedef unsigned __int64 uint64_t; # include #endif +#if defined(_WIN32) || defined(_WIN64) +# include +typedef _timeb my_time_t; + +inline void system_time(my_time_t* t) { _ftime(t); } +inline uint64_t time_to_msec(const my_time_t& t) { return t.time * 1000 + t.millitm; } +#else +# include +typedef timeval my_time_t; + +inline void system_time(my_time_t* t) { gettimeofday(t, NULL); } +inline uint64_t time_to_msec(const my_time_t& t) { return t.tv_sec * 1000 + t.tv_usec / 1000; } +#endif + #if defined(_WIN64) # include // MSVC popcnt and bsfq instrinsics # define IS_64BIT diff --git a/src/uci.cpp b/src/uci.cpp index c44c23fa..3a42ac5f 100644 --- a/src/uci.cpp +++ b/src/uci.cpp @@ -243,19 +243,19 @@ namespace { void perft(Position& pos, istringstream& is) { - int depth, time; + int depth; if (!(is >> depth)) return; - time = system_time(); + Time time = Time::current_time(); int64_t n = Search::perft(pos, depth * ONE_PLY); - time = system_time() - time; + int e = time.elapsed(); std::cout << "\nNodes " << n - << "\nTime (ms) " << time - << "\nNodes/second " << int(n / (time / 1000.0)) << std::endl; + << "\nTime (ms) " << e + << "\nNodes/second " << int(n / (e / 1000.0)) << std::endl; } } -- 2.39.2