diff --git a/Tools/io-benchmark.cpp b/Tools/io-benchmark.cpp index 87d5f5b36..90ba1874f 100644 --- a/Tools/io-benchmark.cpp +++ b/Tools/io-benchmark.cpp @@ -24,14 +24,9 @@ or see http://www.gnu.org/licenses/agpl.txt. #include #include - -#include -#include - #include #include -#include #include #include @@ -39,38 +34,60 @@ or see http://www.gnu.org/licenses/agpl.txt. const unsigned number_of_elements = 268435456; +struct Statistics { double min, max, med, mean, dev; }; + +void RunStatistics(std::vector & timings_vector, Statistics & stats) { + std::sort(timings_vector.begin(), timings_vector.end()); + stats.min = timings_vector.front(); + stats.max = timings_vector.back(); + stats.med = timings_vector[timings_vector.size()/2]; + double primary_sum = std::accumulate( + timings_vector.begin(), + timings_vector.end(), + 0.0 + ); + stats.mean = primary_sum / timings_vector.size(); + + double primary_sq_sum = std::inner_product( timings_vector.begin(), + timings_vector.end(), + timings_vector.begin(), + 0.0 + ); + stats.dev = std::sqrt( + primary_sq_sum / timings_vector.size() - (stats.mean * stats.mean) + ); +} + int main (int argc, char * argv[]) { LogPolicy::GetInstance().Unmute(); + + SimpleLogger().Write(logDEBUG) << "starting up engines, compiled at " << + __DATE__ << ", " __TIME__; + + if( 1 == argc ) { + SimpleLogger().Write(logWARNING) << + "usage: " << argv[0] << " /path/on/device"; + return -1; + } + + boost::filesystem::path test_path = boost::filesystem::path(argv[1]); + test_path /= "osrm.tst"; + SimpleLogger().Write(logDEBUG) << "temporary file: " << test_path.string(); + try { - SimpleLogger().Write(logDEBUG) << "starting up engines, compiled at " << - __DATE__ << ", " __TIME__; - - if( 1 == argc ) { - SimpleLogger().Write(logWARNING) << - "usage: " << argv[0] << " /path/on/device"; - return -1; - } - //create file to test - boost::filesystem::path test_path = boost::filesystem::path(argv[1]); - test_path /= "osrm.tst"; - SimpleLogger().Write(logDEBUG) << - "temporary file: " << test_path.string(); if( boost::filesystem::exists(test_path) ) { boost::filesystem::remove(test_path); SimpleLogger().Write() << "removing previous files"; } - SimpleLogger().Write(logDEBUG) << "Allocating 2GB in RAM"; + SimpleLogger().Write(logDEBUG) << "allocating 2GB in RAM"; std::vector primary_vector(number_of_elements, 0); - std::vector secondary_vector(number_of_elements, 0); SimpleLogger().Write(logDEBUG) << "fill primary vector with data"; std::srand ( 37337 ); std::generate (primary_vector.begin(), primary_vector.end(), std::rand); - std::vector timing_results_1013; - SimpleLogger().Write(logDEBUG) << "writing " << number_of_elements*sizeof(unsigned) << " bytes"; //write 1GB to random filename, time everything @@ -85,87 +102,78 @@ int main (int argc, char * argv[]) { double time2 = get_timestamp(); SimpleLogger().Write(logDEBUG) << "writing 1GB took " << (time2-time1)*1000 << "ms"; - SimpleLogger().Write() << "Write performance: " << 1024*1024/((time2-time1)*1000) << "MB/sec"; - SimpleLogger().Write(logDEBUG) << "reading " << number_of_elements*sizeof(unsigned) << " bytes"; + //read and check 1GB of random data, time everything - boost::filesystem::ifstream read_stream(test_path, std::ios::binary); + std::vector secondary_vector(number_of_elements, 0); + boost::filesystem::ifstream read_stream( test_path, std::ios::binary ); time1 = get_timestamp(); read_stream.read( (char *)&secondary_vector[0], number_of_elements*sizeof(unsigned) ); + read_stream.sync(); + read_stream.close(); time2 = get_timestamp(); + SimpleLogger().Write(logDEBUG) << "reading 1GB took " << (time2-time1)*1000 << "ms"; SimpleLogger().Write() << "Read performance: " << 1024*1024/((time2-time1)*1000) << "MB/sec"; - SimpleLogger().Write(logDEBUG) << "checking data for correctness"; + if(!std::equal( primary_vector.begin(), primary_vector.end(), secondary_vector.begin() ) ) { - throw OSRMException("reading data failed"); + throw OSRMException("data file is corrupted"); } //removing any temporary data std::vector().swap(primary_vector); std::vector().swap(secondary_vector); - SimpleLogger().Write(logDEBUG) << "performing 1000+/-1 gapped I/Os"; - unsigned single_element = 0; + //reopening read stream + read_stream.open(test_path, std::ios::binary); + + SimpleLogger().Write(logDEBUG) << "running 1000+/-1 gapped I/Os of 4B"; + std::vector timing_results_gapped; + volatile unsigned single_element = 0; //read every 268435'th byte, time each I/O seperately - for(unsigned i = 0; i < number_of_elements; i+=(number_of_elements/1000)) { + for( + int i = number_of_elements; + i > 0 ; + i-=(number_of_elements/1000) + ) { time1 = get_timestamp(); read_stream.seekg(i*sizeof(unsigned)); read_stream.read( (char*)&single_element, sizeof(unsigned)); time2 = get_timestamp(); - timing_results_1013.push_back((time2-time1)); + timing_results_gapped.push_back((time2-time1)); } //Do statistics - SimpleLogger().Write(logDEBUG) << "Performing gapped I/O statistics"; + SimpleLogger().Write(logDEBUG) << "running gapped I/O statistics"; //print simple statistics: min, max, median, variance - std::sort(timing_results_1013.begin(), timing_results_1013.end()); - double primary_min = timing_results_1013.front(); - double primary_max = timing_results_1013.back(); - double primary_med = timing_results_1013[timing_results_1013.size()/2]; - double primary_sum = std::accumulate( - timing_results_1013.begin(), - timing_results_1013.end(), - 0.0 - ); - double primary_mean = primary_sum / timing_results_1013.size(); - - double primary_sq_sum = std::inner_product( - timing_results_1013.begin(), - timing_results_1013.end(), - timing_results_1013.begin(), - 0.0 - ); - double primary_dev = std::sqrt( - primary_sq_sum / timing_results_1013.size() - - (primary_mean * primary_mean) - ); - + Statistics primary_stats; + RunStatistics(timing_results_gapped, primary_stats); SimpleLogger().Write() << "gapped I/O: " << - "min: " << primary_min*1000 << "ms, " << - "mean: " << primary_mean*1000 << "ms, " << - "med: " << primary_med*1000 << "ms, " << - "max: " << primary_max*1000 << "ms, " << - "dev: " << primary_dev*1000 << "ms"; + "min: " << primary_stats.min*1000 << "ms, " << + "mean: " << primary_stats.mean*1000 << "ms, " << + "med: " << primary_stats.med*1000 << "ms, " << + "max: " << primary_stats.max*1000 << "ms, " << + "dev: " << primary_stats.dev*1000 << "ms"; std::vector timing_results_random; volatile unsigned temp_array[1024]; //compilers dont optimize volatiles - SimpleLogger().Write(logDEBUG) << "performing 1000 random I/Os"; - //make 1000 random access, time each I/O seperately + SimpleLogger().Write(logDEBUG) << "running 1000 random I/Os of 4KB"; + //make 1000 random access, time each I/O seperately for(unsigned i = 0; i < 1000; ++i) { unsigned element_to_read = std::rand()%(number_of_elements-1024); time1 = get_timestamp(); @@ -177,35 +185,17 @@ int main (int argc, char * argv[]) { read_stream.close(); // Do statistics - SimpleLogger().Write(logDEBUG) << "Performing random I/O statistics"; - std::sort(timing_results_random.begin(), timing_results_random.end()); - double secondary_min = timing_results_random.front(); - double secondary_max = timing_results_random.back(); - double secondary_med = timing_results_random[timing_results_random.size()/2]; - double secondary_sum = std::accumulate( - timing_results_random.begin(), - timing_results_random.end(), - 0.0 - ); - double secondary_mean = secondary_sum / timing_results_random.size(); + SimpleLogger().Write(logDEBUG) << "running random I/O statistics"; + Statistics secondary_stats; + RunStatistics(timing_results_random, secondary_stats); - double secondary_sq_sum = std::inner_product( - timing_results_random.begin(), - timing_results_random.end(), - timing_results_random.begin(), - 0.0 - ); - double secondary_stdev = std::sqrt( - secondary_sq_sum / timing_results_random.size() - - (secondary_mean * secondary_mean) - ); + SimpleLogger().Write() << "random I/O: " << + "min: " << secondary_stats.min*1000 << "ms, " << + "mean: " << secondary_stats.mean*1000 << "ms, " << + "med: " << secondary_stats.med*1000 << "ms, " << + "max: " << secondary_stats.max*1000 << "ms, " << + "dev: " << secondary_stats.dev*1000 << "ms"; - SimpleLogger().Write() << "random I/O: " << - "min: " << secondary_min*1000 << "ms, " << - "mean: " << secondary_mean*1000 << "ms, " << - "med: " << secondary_med*1000 << "ms, " << - "max: " << secondary_max*1000 << "ms, " << - "dev: " << secondary_stdev*1000 << "ms"; if( boost::filesystem::exists(test_path) ) { boost::filesystem::remove(test_path); SimpleLogger().Write(logDEBUG) << "removing temporary files"; @@ -213,8 +203,6 @@ int main (int argc, char * argv[]) { } catch ( const std::exception & e ) { SimpleLogger().Write(logWARNING) << "caught exception: " << e.what(); SimpleLogger().Write(logWARNING) << "cleaning up, and exiting"; - boost::filesystem::path test_path = boost::filesystem::path(argv[1]); - test_path /= "osrm.tst"; if(boost::filesystem::exists(test_path)) { boost::filesystem::remove(test_path); SimpleLogger().Write(logWARNING) << "removing temporary files";