A logging facility

Discussion of chess software programming and technical issues.

Moderators: hgm, Rebel, chrisw

Jan Brouwer
Posts: 201
Joined: Thu Mar 22, 2007 7:12 pm
Location: Netherlands

Re: A logging facility

Post by Jan Brouwer »

diep wrote:It's silly to even start an engine in C++, as you need to be hell of a C++ programmer to even 'make' it to the same speed in nps as a much worse programmer can do in C.
I have to disagree. There is nothing magical going on in C++ classes if you refrain from using polymorphism. Last year I ported the low level parts of my engine from C to C++, introducing classes for Piece, Move, and Board, carefully watching for performance regression. There were none, until I replaced some low level macro's with inline functions. I accepted those as I wanted to get rid of the macro's. The performance dropped a small percentage (I don't remember what, but it was less than 5%). Probably even these could have been avoided by watching the generate assembly, I suspect there were some casting operations added under water.
bob
Posts: 20943
Joined: Mon Feb 27, 2006 7:30 pm
Location: Birmingham, AL

Re: A logging facility

Post by bob »

Jan Brouwer wrote:
diep wrote:It's silly to even start an engine in C++, as you need to be hell of a C++ programmer to even 'make' it to the same speed in nps as a much worse programmer can do in C.
I have to disagree. There is nothing magical going on in C++ classes if you refrain from using polymorphism. Last year I ported the low level parts of my engine from C to C++, introducing classes for Piece, Move, and Board, carefully watching for performance regression. There were none, until I replaced some low level macro's with inline functions. I accepted those as I wanted to get rid of the macro's. The performance dropped a small percentage (I don't remember what, but it was less than 5%). Probably even these could have been avoided by watching the generate assembly, I suspect there were some casting operations added under water.
Here's the key issue, however. Why use a specific language if you intentionally avoid the features that make it unique? Simply because instead of this:

MakeMove(board, move)

you can write it as

board.MakeMove(move)?

whoop-de-do. :)

If you like C++, use it. If you like C, it works just as well. And there is less risk of using features that are not exactly conducive to efficiency. Templates come to mind. AKA "code bloat". It's a matter of personal taste.

Here's the Print() function from Crafty:

void Print(int vb, char *fmt, ...) {
va_list ap;

va_start(ap, fmt);
if (vb & display_options)
vprintf(fmt, ap);
fflush(stdout);
if (time_limit > -99 || tc_time_remaining[root_wtm] > 6000 || vb == 4095) {
va_start(ap, fmt);
if (log_file)
vfprintf(log_file, fmt, ap);
if (log_file)
fflush(log_file);
}
va_end(ap);
}

only reason it is so long are (a) using the va_arg stuff since this is a function that can have a variable number of arguments, just like the real printf() function. (b) I also avoid writing to the log file if the target time gets very small, (c) as well as add a check to see whether something should be sent to stdout, or just to the log-file, controlled with the "display command" inside Crafty. THis has not changed in 15 years now. And likely never will.

I don't see anything any more clever in stockfish than what I am doing here when it gets to the level of "efficiency" which was mentioned in the original post. Couldn't do that in Cray Blitz since fortran didn't support it, so I ended up duplicating every output statement, one for the console, one for the log file.
bob
Posts: 20943
Joined: Mon Feb 27, 2006 7:30 pm
Location: Birmingham, AL

Re: A logging facility

Post by bob »

Rein Halbersma wrote:
mcostalba wrote:
bob wrote: I even wrote a Print() function
The point is doing it _without_ writing a custom Print() function or whatever else. And without changing any existing line and with zero overhead (your Print() function is something added above the standard functions). Please don't take it personally, but I think you have not understood the topic, but believe me it is a very interesting piece of code otherwise I would had not dedicated a specific post here.
I think Boost.Iostreams offers similar functionality, but also takes care of all the buffering stuff for you. E.g. tee_device
http://www.boost.org/doc/libs/1_47_0/li ... s/tee.html

What is really nice in your code is that your Logger class can toggle this behavior at runtime and *from the outside*, as you point out.
Ditto for mine if you look at the code. What you log and what you don't can be altered during a game trivially. And when the target time drops way down, mine automatically disables logging since any I/O has associated overhead that becomes significant when you want to search with a couple of milliseconds as the target time.
Daniel Shawul
Posts: 4185
Joined: Tue Mar 14, 2006 11:34 am
Location: Ethiopia

Re: A logging facility

Post by Daniel Shawul »

You can do it from shell

Code: Select all

./scorpio 2>&1 | tee -a log.txt
But most of the time what I log is different from what I print to gui/screen so I prefer the other solution mentioned in this thread.
Jan Brouwer
Posts: 201
Joined: Thu Mar 22, 2007 7:12 pm
Location: Netherlands

Re: A logging facility

Post by Jan Brouwer »

bob wrote: Here's the key issue, however. Why use a specific language if you intentionally avoid the features that make it unique? Simply because instead of this:

MakeMove(board, move)

you can write it as

board.MakeMove(move)?

whoop-de-do. :)
Exactly, board.MakeMove(move) is much more pleasing to the eye!

And

MakeMovePrivateHelper(move)

is even better than

MakeMovePrivateHelper(board, move) ;)
If you like C++, use it. If you like C, it works just as well. And there is less risk of using features that are not exactly conducive to efficiency. Templates come to mind. AKA "code bloat". It's a matter of personal taste.
Agreed.

Turning the C code into C++ forced more structure on the program, there was all kind of arbitrary coupling that had to be resolved.
I like how the code reads much better now.
mcostalba
Posts: 2684
Joined: Sat Jun 14, 2008 9:17 pm

Re: A logging facility

Post by mcostalba »

The ony thing missing by my fancy logging facility is that it only logs std::cout, but not the commands sent by the gui, aka std::cin.

Now this limitation is no more: :-)

https://github.com/mcostalba/Stockfish/ ... bc77175f07


It took me a couple of hours to understand how to do it because this time there was no code to copy ;-) but this makes the effort even more rewarding.....
Daniel Shawul
Posts: 4185
Joined: Tue Mar 14, 2006 11:34 am
Location: Ethiopia

Re: A logging facility

Post by Daniel Shawul »

Great you renamed your toy class to Tee... without giving me credit 8-)
At least mention there is an easier alternative to what now seems a self-serving QUESTION/ANSWER.
mcostalba
Posts: 2684
Joined: Sat Jun 14, 2008 9:17 pm

Re: A logging facility

Post by mcostalba »

Ok, this is the final version, cleaned up a lot and with added direction indicators (">>" and "<<") so to easily understand from the log file which are the commands sent by GUI and which are the lines sent by engine. The Logger class is fully self contained, it doesn't need any external code, you can simply cut 'n paste the following whenever you want, as long as is a GPL code :-)

Code: Select all

class Logger &#123;

  Logger&#40;) &#58; in&#40;cin.rdbuf&#40;), file&#41;, out&#40;cout.rdbuf&#40;), file&#41; &#123;&#125;
  ~Logger&#40;) &#123; start&#40;false&#41;; &#125;

  struct Tie&#58; public streambuf &#123; // MSVC requires splitted streambuf for cin and cout

    Tie&#40;streambuf* b, ofstream& f&#41; &#58; buf&#40;b&#41;, file&#40;f&#41; &#123;&#125;

    int sync&#40;) &#123; return file.rdbuf&#40;)->pubsync&#40;), buf->pubsync&#40;); &#125;
    int overflow&#40;int c&#41; &#123; return log&#40;buf->sputc&#40;&#40;char&#41;c&#41;, "<< "); &#125;
    int underflow&#40;) &#123; return buf->sgetc&#40;); &#125;
    int uflow&#40;) &#123; return log&#40;buf->sbumpc&#40;), ">> "); &#125;

    int log&#40;int c, const char* prefix&#41; &#123;

      static int last = '\n';

      if &#40;last == '\n')
          file.rdbuf&#40;)->sputn&#40;prefix, 3&#41;;

      return last = file.rdbuf&#40;)->sputc&#40;&#40;char&#41;c&#41;;
    &#125;

    streambuf* buf;
    ofstream& file;
  &#125;;

  ofstream file;
  Tie in, out;

public&#58;
  static void start&#40;bool b&#41; &#123;

    static Logger l;

    if &#40;b && !l.file.is_open&#40;))
    &#123;
        l.file.open&#40;"io_log.txt", ifstream&#58;&#58;out | ifstream&#58;&#58;app&#41;;
        cin.rdbuf&#40;&l.in&#41;;
        cout.rdbuf&#40;&l.out&#41;;
    &#125;
    else if (!b && l.file.is_open&#40;))
    &#123;
        cout.rdbuf&#40;l.out.buf&#41;;
        cin.rdbuf&#40;l.in.buf&#41;;
        l.file.close&#40;);
    &#125;
  &#125;
&#125;;
To start / stop logging of your engine you just need:

Code: Select all

Logger&#58;&#58;start&#40;true&#41;; // To start logging

....

Logger&#58;&#58;start&#40;false&#41;; // To stop logging
As you can see Logger::start() is static method so you even don't need to instantiate the class. Tested on both MSVC and gcc.


P.S: This code is GPL, the original code is not but this version is completely different and substantially enhanced, totally written by me and added to Stockfish.
bob
Posts: 20943
Joined: Mon Feb 27, 2006 7:30 pm
Location: Birmingham, AL

Re: A logging facility

Post by bob »

Daniel Shawul wrote:You can do it from shell

Code: Select all

./scorpio 2>&1 | tee -a log.txt
But most of the time what I log is different from what I print to gui/screen so I prefer the other solution mentioned in this thread.
I used to do that many years ago. But I used a few ANSI sequences to highlight a move and such, and I also use \r to overwrite a line over and over as I display each root move searched. That's all ugly stuff to log, because when you vi the file, it looks horrible. Hence my Print() function that decides what doesn't need to be logged vs what does...
bhlangonijr
Posts: 482
Joined: Thu Oct 16, 2008 4:23 am
Location: Milky Way

Re: A logging facility

Post by bhlangonijr »

bob wrote:And there is less risk of using features that are not exactly conducive to efficiency. Templates come to mind. AKA "code bloat". It's a matter of personal taste.
oh my... don't you guys get tired of this kind of language wars? :)
This is a very known pattern:

Assembly guys bashing C language -->
C guys bashing C++ (vide Linus Torvalds vs some random c++ dude famous thread in the internet) -->
C++ guys bashing Java -->
Java guys bashing Scala, Python, Erlang, ....

I'd very much prefer get my ass off the couch and try learning something new..

But I'd say this:

Code: Select all

x = std&#58;&#58;abs&#40;y&#41;;
is definitely much better than

Code: Select all

 
x = labs&#40;y&#41;; // or
x = cabs&#40;y&#41;; // or
x = labs&#40;y&#41;; // whatever ....
...
This is not a matter of "personal taste". I suppose this is the natural evolution of computer languages. ;-)