split io benchmark into two parts. also fixed things on Linux
This commit is contained in:
		
							parent
							
								
									0f94fb9d6d
								
							
						
					
					
						commit
						3089231476
					
				| @ -27,8 +27,14 @@ or see http://www.gnu.org/licenses/agpl.txt. | |||||||
| #include <boost/ref.hpp> | #include <boost/ref.hpp> | ||||||
| 
 | 
 | ||||||
| #include <cmath> | #include <cmath> | ||||||
| 
 | #include <cstdio> | ||||||
|  | #include <cstdlib> | ||||||
|  | #include <fcntl.h> | ||||||
|  | #ifdef __linux__ | ||||||
|  | #include <malloc.h> | ||||||
|  | #endif | ||||||
| #include <algorithm> | #include <algorithm> | ||||||
|  | #include <iomanip> | ||||||
| #include <numeric> | #include <numeric> | ||||||
| #include <vector> | #include <vector> | ||||||
| 
 | 
 | ||||||
| @ -75,131 +81,236 @@ int main (int argc, char * argv[]) { | |||||||
|     SimpleLogger().Write(logDEBUG) << "temporary file: " << test_path.string(); |     SimpleLogger().Write(logDEBUG) << "temporary file: " << test_path.string(); | ||||||
| 
 | 
 | ||||||
|     try { |     try { | ||||||
|  |         //create files for testing
 | ||||||
|  |         if( 2 == argc) { | ||||||
|             //create file to test
 |             //create file to test
 | ||||||
|             if( boost::filesystem::exists(test_path) ) { |             if( boost::filesystem::exists(test_path) ) { | ||||||
|             boost::filesystem::remove(test_path); |                 throw OSRMException("Data file already exists"); | ||||||
|             SimpleLogger().Write() << "removing previous files"; |  | ||||||
|             } |             } | ||||||
| 
 | 
 | ||||||
|         SimpleLogger().Write(logDEBUG) << "allocating 2GB in RAM"; |             double time1, time2; | ||||||
|         std::vector<unsigned> primary_vector(number_of_elements, 0); |             int * random_array = new int[number_of_elements]; | ||||||
| 
 |             std::generate (random_array, random_array+number_of_elements, std::rand); | ||||||
|         SimpleLogger().Write(logDEBUG) << "fill primary vector with data"; | #ifdef __APPLE__ | ||||||
|         std::srand ( 37337 ); |             FILE * fd = fopen(test_path.string().c_str(), "w"); | ||||||
|         std::generate (primary_vector.begin(), primary_vector.end(), std::rand); |             fcntl(fileno(fd), F_NOCACHE, 1); | ||||||
| 
 |             fcntl(fileno(fd), F_RDAHEAD, 0); | ||||||
|         SimpleLogger().Write(logDEBUG) << |  | ||||||
|             "writing " << number_of_elements*sizeof(unsigned) << " bytes"; |  | ||||||
|         //write 1GB to random filename, time everything
 |  | ||||||
|         boost::filesystem::ofstream test_stream(test_path, std::ios::binary); |  | ||||||
|         double time1 = get_timestamp(); |  | ||||||
|         test_stream.write( |  | ||||||
|             (char *)&primary_vector[0], |  | ||||||
|             number_of_elements*sizeof(unsigned) |  | ||||||
|         ); |  | ||||||
|         test_stream.flush(); |  | ||||||
|         test_stream.close(); |  | ||||||
|         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
 |  | ||||||
|         std::vector<unsigned> secondary_vector(number_of_elements, 0); |  | ||||||
|         boost::filesystem::ifstream read_stream( test_path, std::ios::binary ); |  | ||||||
|             time1 = get_timestamp(); |             time1 = get_timestamp(); | ||||||
|         read_stream.read( |             write(fileno(fd), (char*)random_array, number_of_elements*sizeof(unsigned)); | ||||||
|             (char *)&secondary_vector[0], |             time2 = get_timestamp(); | ||||||
|  |             fclose(fd); | ||||||
|  | #endif | ||||||
|  | #ifdef __linux__ | ||||||
|  |             int f = open( | ||||||
|  |                 test_path.string().c_str(), | ||||||
|  |                 O_CREAT|O_TRUNC|O_WRONLY|O_SYNC, | ||||||
|  |                 S_IRWXU | ||||||
|  |             ); | ||||||
|  |             time1 = get_timestamp(); | ||||||
|  |             int ret = write( | ||||||
|  |                 f, | ||||||
|  |                 random_array, | ||||||
|                 number_of_elements*sizeof(unsigned) |                 number_of_elements*sizeof(unsigned) | ||||||
|             ); |             ); | ||||||
|         read_stream.sync(); |             if(-1 == ret) { | ||||||
|         read_stream.close(); |                 throw OSRMException("could not write random data file"); | ||||||
|  |             } | ||||||
|             time2 = get_timestamp(); |             time2 = get_timestamp(); | ||||||
|  |             close(f); | ||||||
|  | #endif | ||||||
|  |             delete[] random_array; | ||||||
|  |             SimpleLogger().Write(logDEBUG) << | ||||||
|  |                 "writing raw 1GB took " << (time2-time1)*1000 << "ms"; | ||||||
|  |             SimpleLogger().Write() << "raw write performance: " << | ||||||
|  |                 std::setprecision(5) << std::fixed << | ||||||
|  |                 1024*1024/((time2-time1)*1000) << "MB/sec"; | ||||||
| 
 | 
 | ||||||
|             SimpleLogger().Write(logDEBUG) << |             SimpleLogger().Write(logDEBUG) << | ||||||
|             "reading 1GB took " << (time2-time1)*1000 << "ms"; |                 "finished creation of random data. Flush disk cache now!"; | ||||||
|         SimpleLogger().Write() << "Read performance: " << |  | ||||||
|             1024*1024/((time2-time1)*1000) << "MB/sec"; |  | ||||||
|         SimpleLogger().Write(logDEBUG) << "checking data for correctness"; |  | ||||||
| 
 | 
 | ||||||
|         if(!std::equal( |         } else { | ||||||
|                 primary_vector.begin(), | 
 | ||||||
|                 primary_vector.end(), |             //
 | ||||||
|                 secondary_vector.begin() |             // Run Non-Cached I/O benchmarks
 | ||||||
|             ) |             //
 | ||||||
|         ) { | 
 | ||||||
|             throw OSRMException("data file is corrupted"); |             if( !boost::filesystem::exists(test_path) ) { | ||||||
|  |                 throw OSRMException("data file does not exist"); | ||||||
|             } |             } | ||||||
| 
 | 
 | ||||||
|         //removing any temporary data
 |             double time1, time2; | ||||||
|         std::vector<unsigned>().swap(primary_vector); |             //volatiles do not get optimized
 | ||||||
|         std::vector<unsigned>().swap(secondary_vector); |             Statistics stats; | ||||||
| 
 | 
 | ||||||
|         //reopening read stream
 | #ifdef __APPLE__ | ||||||
|         read_stream.open(test_path, std::ios::binary); |             volatile unsigned temp_array[1024]; | ||||||
| 
 |  | ||||||
|         SimpleLogger().Write(logDEBUG) << "running 1000+/-1 gapped I/Os of 4B"; |  | ||||||
|         std::vector<double> timing_results_gapped; |  | ||||||
|             volatile unsigned single_element = 0; |             volatile unsigned single_element = 0; | ||||||
|         //read every 268435'th byte, time each I/O seperately
 |             char * raw_array = new char[number_of_elements*sizeof(unsigned)]; | ||||||
|         for( |             FILE * fd = fopen(test_path.string().c_str(), "r"); | ||||||
|             int i = number_of_elements; |             fcntl(fileno(fd), F_NOCACHE, 1); | ||||||
|             i > 0 ; |             fcntl(fileno(fd), F_RDAHEAD, 0); | ||||||
|             i-=(number_of_elements/1000) | #endif | ||||||
|         ) { | #ifdef __linux__ | ||||||
|  |             char * temp_array = (char*) memalign( | ||||||
|  |                 512, | ||||||
|  |                 1024*sizeof(unsigned) | ||||||
|  |             ); | ||||||
|  |             char * single_block = (char*) memalign( | ||||||
|  |                 512, | ||||||
|  |                 512 | ||||||
|  |             ); | ||||||
|  | 
 | ||||||
|  |             int f = open(test_path.string().c_str(), O_RDONLY|O_DIRECT|O_SYNC); | ||||||
|  |             SimpleLogger().Write(logDEBUG) << "opened, error: " << strerror(errno); | ||||||
|  |             char * raw_array = (char*) memalign( | ||||||
|  |                 512, | ||||||
|  |                 number_of_elements*sizeof(unsigned) | ||||||
|  |             ); | ||||||
|  | #endif | ||||||
|             time1 = get_timestamp(); |             time1 = get_timestamp(); | ||||||
|             read_stream.seekg(i*sizeof(unsigned)); | #ifdef __APPLE__ | ||||||
|             read_stream.read( (char*)&single_element, sizeof(unsigned)); |             read(fileno(fd), raw_array, number_of_elements*sizeof(unsigned)); | ||||||
|  |             close(fileno(fd)); | ||||||
|  |             fd = fopen(test_path.string().c_str(), "r"); | ||||||
|  | #endif | ||||||
|  | #ifdef __linux__ | ||||||
|  |             int ret = read(f, raw_array, number_of_elements*sizeof(unsigned)); | ||||||
|  |             SimpleLogger().Write(logDEBUG) << | ||||||
|  |                 "read " << ret << " bytes, error: " << strerror(errno); | ||||||
|  |             close(f); | ||||||
|  |             f = open(test_path.string().c_str(), O_RDONLY|O_DIRECT|O_SYNC); | ||||||
|  |             SimpleLogger().Write(logDEBUG) << | ||||||
|  |                 "opened, error: " << strerror(errno); | ||||||
|  | #endif | ||||||
|             time2 = get_timestamp(); |             time2 = get_timestamp(); | ||||||
|             timing_results_gapped.push_back((time2-time1)); | 
 | ||||||
|  |             SimpleLogger().Write(logDEBUG) << | ||||||
|  |                 "reading raw 1GB took " << (time2-time1)*1000 << "ms"; | ||||||
|  |             SimpleLogger().Write() << "raw read performance: " << | ||||||
|  |                 std::setprecision(5) << std::fixed << | ||||||
|  |                 1024*1024/((time2-time1)*1000) << "MB/sec"; | ||||||
|  | 
 | ||||||
|  |             std::vector<double> timing_results_raw_random; | ||||||
|  |             SimpleLogger().Write(logDEBUG) << "running 1000 random I/Os of 4KB"; | ||||||
|  | 
 | ||||||
|  | #ifdef __APPLE__ | ||||||
|  |             fseek(fd, 0, SEEK_SET); | ||||||
|  | #endif | ||||||
|  | #ifdef __linux__ | ||||||
|  |             lseek(f, 0, SEEK_SET); | ||||||
|  | #endif | ||||||
|  |             //make 1000 random access, time each I/O seperately
 | ||||||
|  |             unsigned number_of_blocks = ((number_of_elements*sizeof(unsigned))-4096)/512; | ||||||
|  |             for(unsigned i = 0; i < 1000; ++i) { | ||||||
|  |                 unsigned block_to_read = std::rand()%number_of_blocks; | ||||||
|  |                 off_t current_offset = block_to_read*512; | ||||||
|  |                 time1 = get_timestamp(); | ||||||
|  | #ifdef __APPLE__ | ||||||
|  |                 int ret1 = fseek(fd, current_offset, SEEK_SET); | ||||||
|  |                 int ret2 = read(fileno(fd), (char*)&temp_array[0], 1024*sizeof(unsigned)); | ||||||
|  | #endif | ||||||
|  | #ifdef __linux__ | ||||||
|  |                 int ret1 = lseek(f, current_offset, SEEK_SET); | ||||||
|  |                 int ret2 = read(f, (char*)temp_array, 1024*sizeof(unsigned)); | ||||||
|  | #endif | ||||||
|  |                 time2 = get_timestamp(); | ||||||
|  |                 if( ((off_t)-1) == ret1) { | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "offset: " << current_offset; | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "seek error " << strerror(errno); | ||||||
|  |                     throw OSRMException("seek error"); | ||||||
|  |                 } | ||||||
|  |                  if(-1 == ret2) { | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "offset: " << current_offset; | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "read error " << strerror(errno); | ||||||
|  |                     throw OSRMException("read error"); | ||||||
|  |                 } | ||||||
|  |                timing_results_raw_random.push_back((time2-time1)); | ||||||
|             } |             } | ||||||
| 
 | 
 | ||||||
|  |             // Do statistics
 | ||||||
|  |             SimpleLogger().Write(logDEBUG) << "running raw random I/O statistics"; | ||||||
|  |             RunStatistics(timing_results_raw_random, stats); | ||||||
|  | 
 | ||||||
|  |             SimpleLogger().Write() << "raw random I/O: "  << | ||||||
|  |                 std::setprecision(5) << std::fixed << | ||||||
|  |                 "min: "  << stats.min*1000.  << "ms, " << | ||||||
|  |                 "mean: " << stats.mean*1000. << "ms, " << | ||||||
|  |                 "med: "  << stats.med*1000.  << "ms, " << | ||||||
|  |                 "max: "  << stats.max*1000.  << "ms, " << | ||||||
|  |                 "dev: "  << stats.dev*1000.  << "ms"; | ||||||
|  | 
 | ||||||
|  |             std::vector<double> timing_results_raw_gapped; | ||||||
|  | #ifdef __APPLE__ | ||||||
|  |             fseek(fd, 0, SEEK_SET); | ||||||
|  | #endif | ||||||
|  | #ifdef __linux__ | ||||||
|  |             lseek(f, 0, SEEK_SET); | ||||||
|  | #endif | ||||||
|  | 
 | ||||||
|  |             //read every 100th block
 | ||||||
|  |             for( | ||||||
|  |                 unsigned i = 0; | ||||||
|  |                 i < number_of_blocks; | ||||||
|  |                 i += 1024 | ||||||
|  |             ) { | ||||||
|  |                 off_t current_offset = i*512; | ||||||
|  |                 time1 = get_timestamp(); | ||||||
|  |     #ifdef __APPLE__ | ||||||
|  |                 int ret1 = fseek(fd, current_offset, SEEK_SET); | ||||||
|  |                 int ret2 = read(fileno(fd), (char*)&single_element, 512); | ||||||
|  |     #endif | ||||||
|  |     #ifdef __linux__ | ||||||
|  |                 int ret1 = lseek(f, current_offset, SEEK_SET); | ||||||
|  | 
 | ||||||
|  |                 int ret2 = read(f, (char*)single_block, 512); | ||||||
|  |     #endif | ||||||
|  |                 time2 = get_timestamp(); | ||||||
|  |                 if( ((off_t)-1) == ret1) { | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "offset: " << current_offset; | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "seek error " << strerror(errno); | ||||||
|  |                     throw OSRMException("seek error"); | ||||||
|  |                 } | ||||||
|  |                  if(-1 == ret2) { | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "offset: " << current_offset; | ||||||
|  |                     SimpleLogger().Write(logWARNING) | ||||||
|  |                         << "read error " << strerror(errno); | ||||||
|  |                     throw OSRMException("read error"); | ||||||
|  |                 } | ||||||
|  |                timing_results_raw_gapped.push_back((time2-time1)); | ||||||
|  |             } | ||||||
|  |     #ifdef __APPLE__ | ||||||
|  |             fclose(fd); | ||||||
|  |             // free(single_element);
 | ||||||
|  |             free(raw_array); | ||||||
|  |             // free(temp_array);
 | ||||||
|  |     #endif | ||||||
|  |     #ifdef __linux__ | ||||||
|  |             close(f); | ||||||
|  |     #endif | ||||||
|             //Do statistics
 |             //Do statistics
 | ||||||
|             SimpleLogger().Write(logDEBUG) << "running gapped I/O statistics"; |             SimpleLogger().Write(logDEBUG) << "running gapped I/O statistics"; | ||||||
|             //print simple statistics: min, max, median, variance
 |             //print simple statistics: min, max, median, variance
 | ||||||
|         Statistics primary_stats; |             RunStatistics(timing_results_raw_gapped, stats); | ||||||
|         RunStatistics(timing_results_gapped, primary_stats); |             SimpleLogger().Write() << "raw gapped I/O: " << | ||||||
|         SimpleLogger().Write() << "gapped I/O: " << |                 std::setprecision(5) << std::fixed << | ||||||
|             "min: "  << primary_stats.min*1000  << "ms, " << |                 "min: "  << stats.min*1000.  << "ms, " << | ||||||
|             "mean: " << primary_stats.mean*1000 << "ms, " << |                 "mean: " << stats.mean*1000. << "ms, " << | ||||||
|             "med: "  << primary_stats.med*1000  << "ms, " << |                 "med: "  << stats.med*1000.  << "ms, " << | ||||||
|             "max: "  << primary_stats.max*1000  << "ms, " << |                 "max: "  << stats.max*1000.  << "ms, " << | ||||||
|             "dev: "  << primary_stats.dev*1000  << "ms"; |                 "dev: "  << stats.dev*1000.  << "ms"; | ||||||
| 
 |  | ||||||
|         std::vector<double> timing_results_random; |  | ||||||
|         volatile unsigned temp_array[1024]; //compilers dont optimize volatiles
 |  | ||||||
|         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(); |  | ||||||
|             read_stream.seekg(element_to_read*sizeof(unsigned)); |  | ||||||
|             read_stream.read( (char*)&temp_array[0], 1024*sizeof(unsigned)); |  | ||||||
|             time2 = get_timestamp(); |  | ||||||
|             timing_results_random.push_back((time2-time1)); |  | ||||||
|         } |  | ||||||
|         read_stream.close(); |  | ||||||
| 
 |  | ||||||
|         // Do statistics
 |  | ||||||
|         SimpleLogger().Write(logDEBUG) << "running random I/O statistics"; |  | ||||||
|         Statistics secondary_stats; |  | ||||||
|         RunStatistics(timing_results_random, secondary_stats); |  | ||||||
| 
 |  | ||||||
|         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"; |  | ||||||
| 
 | 
 | ||||||
|             if( boost::filesystem::exists(test_path) ) { |             if( boost::filesystem::exists(test_path) ) { | ||||||
|                 boost::filesystem::remove(test_path); |                 boost::filesystem::remove(test_path); | ||||||
|                 SimpleLogger().Write(logDEBUG) << "removing temporary files"; |                 SimpleLogger().Write(logDEBUG) << "removing temporary files"; | ||||||
|             } |             } | ||||||
|  |         } | ||||||
|     } catch ( const std::exception & e ) { |     } catch ( const std::exception & e ) { | ||||||
|         SimpleLogger().Write(logWARNING) << "caught exception: " << e.what(); |         SimpleLogger().Write(logWARNING) << "caught exception: " << e.what(); | ||||||
|         SimpleLogger().Write(logWARNING) << "cleaning up, and exiting"; |         SimpleLogger().Write(logWARNING) << "cleaning up, and exiting"; | ||||||
|  | |||||||
		Loading…
	
		Reference in New Issue
	
	Block a user