Automatic sanity-testing: PASSED, see http://jenkins.bluematt.me/pull-tester/49f4d1d7ab71531d4552a7d1b5b79dfc99883d49 for binaries and test log.

Example output:

 - Connect 688 transactions: 758.16ms (1.102ms/tx, 0.623ms/txin)
 - Connect: 770.16ms
 - Flush 1455 transactions: 2.30ms (0.0016ms/tx)

Automatic sanity-testing: PASSED, see http://jenkins.bluematt.me/pull-tester/c79fdf173098cb8ebdd9ab4f2a2b8e4fca1042ce for binaries and test log.

Automatic sanity-testing: PASSED, see http://jenkins.bluematt.me/pull-tester/c222ef6d830d884e2075864029668884e3da9459 for binaries and test log.

Should all used printfs honor the fBenchmark flag? And shouldn't microseconds use µs instead of ms?

@Diapolo I've changed the code to always report in ms, but sometimes with some decimals. Avoids the necessity for a mu symbol, and is more readable. All timing printfs should honor the fBenchmark yes - should be the case now.

@sipa Thanks, I'm fine with that benchmark stuff then.

Edit: Seems the Make SetBestChain() atomic sneaked in here ^^.

@Diapolo Yes, since they touch the same code, I didn't bother writing them separately (I even mentioned it on the pullreq summart!). If there's an issue with the other pullreq, I'll rebase this one, and if the other gets NAK'ed or delayed, I'll separate them.

@sipa I think your smaller pulls should make it much faster into master, so I have no problem with what I noted above :).

@Diapolo Feel like testing this? I'd like to know what kind of output you get on Windows.

ACK

@sipa Yeah, will do that today :).
Do I need to start an IBD or are you fine with just any occurance of that messages from the log?

ACK

@sipa Here are a few examples with current master + some mods to block file pre-alloc and CAutoFile (dunno if these are related for the benches).

12/06/12 07:57:25 - Connect 293 transactions: 2776.80ms (9.477ms/tx, 3.644ms/txin)
12/06/12 07:57:25 - Connect: 2870.41ms
12/06/12 07:57:25 - Flush 976 transactions: 0.00ms (0.0000ms/tx)

12/06/12 07:57:25 - Connect 108 transactions: 686.40ms (6.356ms/tx, 3.556ms/txin)
12/06/12 07:57:25 - Connect: 702.00ms
12/06/12 07:57:25 - Flush 271 transactions: 0.00ms (0.0000ms/tx)

12/06/12 07:57:26 - Connect 106 transactions: 748.80ms (7.064ms/tx, 3.404ms/txin)
12/06/12 07:57:26 - Connect: 748.80ms
12/06/12 07:57:26 - Flush 283 transactions: 0.00ms (0.0000ms/tx)

12/06/12 07:57:38 - Connect 409 transactions: 3291.61ms (8.048ms/tx, 3.275ms/txin)
12/06/12 07:57:38 - Connect: 3322.81ms
12/06/12 07:57:38 - Flush 1209 transactions: 0.00ms (0.0000ms/tx)

Is this a benchmark for LevelDB access and performance?

Automatic sanity-testing: PASSED, see http://jenkins.bluematt.me/pull-tester/8a28bb6deee2df7dac3288c1bc6db6221e5e43b6 for binaries and test log.

Some values during IBD:

12/07/12 08:08:31 - Connect 60 transactions: 15.60ms (0.260ms/tx, 0.153ms/txin)
12/07/12 08:08:31 - Connect: 15.60ms
12/07/12 08:08:31 - Flush 146 transactions: 0.00ms (0.0000ms/tx)

12/07/12 08:08:32 - Connect 165 transactions: 31.20ms (0.189ms/tx, 0.092ms/txin)
12/07/12 08:08:32 - Connect: 46.80ms
12/07/12 08:08:32 - Flush 409 transactions: 0.00ms (0.0000ms/tx)

12/07/12 08:08:32 - Connect 240 transactions: 0.00ms (0.000ms/tx, 0.000ms/txin)
12/07/12 08:08:32 - Connect: 15.60ms
12/07/12 08:08:32 - Flush 530 transactions: 0.00ms (0.0000ms/tx)

Btw. ACK

@Diapolo Seems microsecond_clock on your system has a resolution of 15.6ms - what I assume to be 1/64 of a second. That makes the numbers -benchmark would report quite useless...

@sipa I didn't even take a close look at the numbers, but your assumption makes sense, if I look at the numbers. Any idea for a working code-path for Win32 then? I could try with GetTimeMillis() instead and see if that numbers make more sense, as at least a ms timer-resolution should be possible (and not a 15.6ms res).

@Diapolo GetTimeMillis uses the same boost function to get the actual time, so I doubt that will make any difference. Up to you to find something that gives an accurate clock in Windows :)

@sipa I had read some stuff a few days ago on that issue and it seems ... well hard to do it portable. Any the native WIN32 APIs for time stuff is a thing I've never used ^^. I'll take another look.

Edit: Note that the existence of the higher resolution classes (eg: nanoseconds) depends on the installation of the library. See Build-Compiler Information for more information. Any idea if that means we need to link against the boost_date_time library?

Edit 2: I tested, which timer resolution is available via:

secs = boost::posix_time::time_duration::num_fractional_digits();
printf("DEBUG: %u digits timer resolution available\n", secs);

DEBUG: 6 digits timer resolution available

So it seems Boost is believing it's able to use microsecond resolution... which IS not true as we saw from the results ;).

Edit 3:
12/07/12 13:06:13 - Connect 70 transactions: 444.03ms (6.343ms/tx, 3.442ms/txin)
12/07/12 13:06:13 DEBUG: 6 digits timer resolution available
12/07/12 13:06:13 - Connect: 451.03ms
12/07/12 13:06:13 - Flush 181 transactions: 1.00ms (0.0055ms/tx)

Next weird thing is I now have such results in the debug.log...