Use TimingUtil.h for all time measurement,

and make TimingUtil.h Windows-compatible
This commit is contained in:
alex85k 2014-06-04 19:52:34 +06:00
parent 11459d38d0
commit 75dabb75e2
7 changed files with 91 additions and 113 deletions

View File

@ -273,10 +273,10 @@ void EdgeBasedGraphFactory::Run(const std::string &original_edge_data_filename,
m_geometry_compressor.SerializeInternalVector(geometry_filename);
SimpleLogger().Write() << "Timing statistics for edge-expanded graph:";
SimpleLogger().Write() << "Geometry compression: " << TIMER_MSEC(geometry)*0.001 << "s";
SimpleLogger().Write() << "Renumbering edges: " << TIMER_MSEC(renumber)*0.001 << "s";
SimpleLogger().Write() << "Generating nodes: " << TIMER_MSEC(generate_nodes)*0.001 << "s";
SimpleLogger().Write() << "Generating edges: " << TIMER_MSEC(generate_edges)*0.001 << "s";
SimpleLogger().Write() << "Geometry compression: " << TIMER_SEC(geometry) << "s";
SimpleLogger().Write() << "Renumbering edges: " << TIMER_SEC(renumber) << "s";
SimpleLogger().Write() << "Generating nodes: " << TIMER_SEC(generate_nodes) << "s";
SimpleLogger().Write() << "Generating edges: " << TIMER_SEC(generate_edges) << "s";
}
void EdgeBasedGraphFactory::CompressGeometry()

View File

@ -424,7 +424,7 @@ class StaticRTree
tree_node_file.close();
TIMER_STOP(construction);
SimpleLogger().Write() << "finished r-tree construction in " << TIMER_MSEC(construction)/1000. << " seconds";
SimpleLogger().Write() << "finished r-tree construction in " << TIMER_SEC(construction) << " seconds";
}
// Read-only operation for queries

View File

@ -29,6 +29,7 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
#include "ExtractionWay.h"
#include "../Util/OSRMException.h"
#include "../Util/SimpleLogger.h"
#include "../Util/TimingUtil.h"
#include <boost/assert.hpp>
#include <boost/filesystem.hpp>
@ -63,49 +64,45 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
{
unsigned number_of_used_nodes = 0;
unsigned number_of_used_edges = 0;
std::chrono::time_point<std::chrono::steady_clock> time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] Sorting used nodes ... " << std::flush;
TIMER_START(sorting_used_nodes);
stxxl::sort(used_node_id_list.begin(), used_node_id_list.end(), Cmp(), stxxl_memory);
std::chrono::time_point<std::chrono::steady_clock> time2 = std::chrono::steady_clock::now();
std::chrono::duration<double> elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(sorting_used_nodes);
std::cout << "ok, after " << TIMER_SEC(sorting_used_nodes) << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] Erasing duplicate nodes ... " << std::flush;
TIMER_START(erasing_dups);
auto new_end = std::unique(used_node_id_list.begin(), used_node_id_list.end());
used_node_id_list.resize(new_end - used_node_id_list.begin());
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(erasing_dups);
std::cout << "ok, after " << TIMER_SEC(erasing_dups) << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] Sorting all nodes ... " << std::flush;
TIMER_START(sorting_nodes);
stxxl::sort(all_nodes_list.begin(), all_nodes_list.end(), CmpNodeByID(), stxxl_memory);
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(sorting_nodes);
std::cout << "ok, after " << TIMER_SEC(sorting_nodes) << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] Sorting used ways ... " << std::flush;
TIMER_START(sort_ways);
stxxl::sort(
way_start_end_id_list.begin(), way_start_end_id_list.end(), CmpWayByID(), stxxl_memory);
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(sort_ways);
std::cout << "ok, after " << TIMER_SEC(sort_ways) << "s" << std::endl;
std::cout << "[extractor] Sorting restrictions. by from... " << std::flush;
TIMER_START(sort_restrictions);
stxxl::sort(restrictions_list.begin(),
restrictions_list.end(),
CmpRestrictionContainerByFrom(),
stxxl_memory);
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(sort_restrictions);
std::cout << "ok, after " << TIMER_SEC(sort_restrictions) << "s" << std::endl;
std::cout << "[extractor] Fixing restriction starts ... " << std::flush;
TIMER_START(fix_restriction_starts);
auto restrictions_iterator = restrictions_list.begin();
auto way_start_and_end_iterator = way_start_end_id_list.begin();
@ -149,24 +146,21 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
++restrictions_iterator;
}
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
TIMER_STOP(fix_restriction_starts);
std::cout << "ok, after " << TIMER_SEC(fix_restriction_starts) << "s" << std::endl;
std::cout << "[extractor] Sorting restrictions. by to ... " << std::flush;
TIMER_START(sort_restrictions_to);
stxxl::sort(restrictions_list.begin(),
restrictions_list.end(),
CmpRestrictionContainerByTo(),
stxxl_memory);
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(sort_restrictions_to);
std::cout << "ok, after " << TIMER_SEC(sort_restrictions_to) << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
unsigned number_of_useable_restrictions = 0;
std::cout << "[extractor] Fixing restriction ends ... " << std::flush;
TIMER_START(fix_restriction_ends);
restrictions_iterator = restrictions_list.begin();
way_start_and_end_iterator = way_start_end_id_list.begin();
while (way_start_and_end_iterator != way_start_end_id_list.end() &&
@ -207,9 +201,8 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
}
++restrictions_iterator;
}
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(fix_restriction_ends);
std::cout << "ok, after " << TIMER_SEC(fix_restriction_ends) << "s" << std::endl;
SimpleLogger().Write() << "usable restrictions: " << number_of_useable_restrictions;
// serialize restrictions
@ -235,9 +228,8 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
file_out_stream.open(output_file_name.c_str(), std::ios::binary);
file_out_stream.write((char *)&uuid, sizeof(UUID));
file_out_stream.write((char *)&number_of_used_nodes, sizeof(unsigned));
time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] Confirming/Writing used nodes ... " << std::flush;
TIMER_START(write_nodes);
// identify all used nodes by a merging step of two sorted lists
auto node_iterator = all_nodes_list.begin();
auto node_id_iterator = used_node_id_list.begin();
@ -262,9 +254,8 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
++node_iterator;
}
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(write_nodes);
std::cout << "ok, after " << TIMER_SEC(write_nodes) << "s" << std::endl;
std::cout << "[extractor] setting number of nodes ... " << std::flush;
std::ios::pos_type previous_file_position = file_out_stream.tellp();
@ -273,18 +264,17 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
file_out_stream.seekp(previous_file_position);
std::cout << "ok" << std::endl;
time1 = std::chrono::steady_clock::now();
// Sort edges by start.
std::cout << "[extractor] Sorting edges by start ... " << std::flush;
TIMER_START(sort_edges_by_start);
stxxl::sort(all_edges_list.begin(), all_edges_list.end(), CmpEdgeByStartID(), stxxl_memory);
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(sort_edges_by_start);
std::cout << "ok, after " << TIMER_SEC(sort_edges_by_start) << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] Setting start coords ... " << std::flush;
TIMER_START(set_start_coords);
file_out_stream.write((char *)&number_of_used_edges, sizeof(unsigned));
// Traverse list of edges and nodes in parallel and set start coord
node_iterator = all_nodes_list.begin();
@ -307,20 +297,18 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
edge_iterator->source_coordinate.lon = node_iterator->lon;
++edge_iterator;
}
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(set_start_coords);
std::cout << "ok, after " << TIMER_SEC(set_start_coords) << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
// Sort Edges by target
std::cout << "[extractor] Sorting edges by target ... " << std::flush;
TIMER_START(sort_edges_by_target);
stxxl::sort(all_edges_list.begin(), all_edges_list.end(), CmpEdgeByTargetID(), stxxl_memory);
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(sort_edges_by_target);
std::cout << "ok, after " << TIMER_SEC(sort_edges_by_target) << "s" << std::endl;
time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] Setting target coords ... " << std::flush;
TIMER_START(set_target_coords);
// Traverse list of edges and nodes in parallel and set target coord
node_iterator = all_nodes_list.begin();
edge_iterator = all_edges_list.begin();
@ -394,9 +382,8 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
}
++edge_iterator;
}
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(set_target_coords);
std::cout << "ok, after " << TIMER_SEC(set_target_coords) << "s" << std::endl;
std::cout << "[extractor] setting number of edges ... " << std::flush;
@ -404,9 +391,9 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
file_out_stream.write((char *)&number_of_used_edges, sizeof(unsigned));
file_out_stream.close();
std::cout << "ok" << std::endl;
time1 = std::chrono::steady_clock::now();
std::cout << "[extractor] writing street name index ... " << std::flush;
TIMER_START(write_name_index);
std::string name_file_streamName = (output_file_name + ".names");
boost::filesystem::ofstream name_file_stream(name_file_streamName, std::ios::binary);
@ -440,9 +427,8 @@ void ExtractionContainers::PrepareData(const std::string &output_file_name,
}
name_file_stream.close();
time2 = std::chrono::steady_clock::now();
elapsed_seconds = time2 - time1;
std::cout << "ok, after " << elapsed_seconds.count() << "s" << std::endl;
TIMER_STOP(write_name_index);
std::cout << "ok, after " << TIMER_SEC(write_name_index) << "s" << std::endl;
SimpleLogger().Write() << "Processed " << number_of_used_nodes << " nodes and "
<< number_of_used_edges << " edges";

View File

@ -28,6 +28,7 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
#include "../Util/GitDescription.h"
#include "../Util/OSRMException.h"
#include "../Util/SimpleLogger.h"
#include "../Util/TimingUtil.h"
#include <boost/filesystem.hpp>
#include <boost/filesystem/fstream.hpp>
@ -100,17 +101,15 @@ int main(int argc, char *argv[])
throw OSRMException("Data file already exists");
}
std::chrono::time_point<std::chrono::steady_clock> time1, time2;
int *random_array = new int[number_of_elements];
std::generate(random_array, random_array + number_of_elements, std::rand);
#ifdef __APPLE__
FILE *fd = fopen(test_path.string().c_str(), "w");
fcntl(fileno(fd), F_NOCACHE, 1);
fcntl(fileno(fd), F_RDAHEAD, 0);
time1 = std::chrono::steady_clock::now();
TIMER_START(write_1gb);
write(fileno(fd), (char *)random_array, number_of_elements * sizeof(unsigned));
time2 = std::chrono::steady_clock::now();
;
TIMER_STOP(write_1gb);
fclose(fd);
#endif
#ifdef __linux__
@ -120,21 +119,20 @@ int main(int argc, char *argv[])
{
throw OSRMException("Could not open random data file");
}
time1 = std::chrono::steady_clock::now();
TIMER_START(write_1gb);
int ret = write(f, random_array, number_of_elements * sizeof(unsigned));
if (0 > ret)
{
throw OSRMException("could not write random data file");
}
time2 = std::chrono::steady_clock::now();
TIMER_STOP(write_1gb);
close(f);
#endif
std::chrono::duration<double> elapsed_seconds = time2 - time1;
delete[] random_array;
SimpleLogger().Write(logDEBUG) << "writing raw 1GB took " << elapsed_seconds.count()
<< "ms";
SimpleLogger().Write(logDEBUG) << "writing raw 1GB took " << TIMER_SEC(write_1gb)
<< "s";
SimpleLogger().Write() << "raw write performance: " << std::setprecision(5)
<< std::fixed << 1024 * 1024 / (elapsed_seconds.count())
<< std::fixed << 1024 * 1024 / TIMER_SEC(write_1gb)
<< "MB/sec";
SimpleLogger().Write(logDEBUG)
@ -148,7 +146,6 @@ int main(int argc, char *argv[])
throw OSRMException("data file does not exist");
}
std::chrono::time_point<std::chrono::steady_clock> time1, time2;
// volatiles do not get optimized
Statistics stats;
@ -170,7 +167,7 @@ int main(int argc, char *argv[])
}
char *raw_array = (char *)memalign(512, number_of_elements * sizeof(unsigned));
#endif
time1 = std::chrono::steady_clock::now();
TIMER_START(read_1gb);
#ifdef __APPLE__
read(fileno(fd), raw_array, number_of_elements * sizeof(unsigned));
close(fileno(fd));
@ -184,13 +181,12 @@ int main(int argc, char *argv[])
f = open(test_path.string().c_str(), O_RDONLY | O_DIRECT | O_SYNC);
SimpleLogger().Write(logDEBUG) << "opened, error: " << strerror(errno);
#endif
time2 = std::chrono::steady_clock::now();
TIMER_STOP(read_1gb);
std::chrono::duration<double> elapsed_seconds = time2 - time1;
SimpleLogger().Write(logDEBUG) << "reading raw 1GB took " << elapsed_seconds.count()
<< "ms";
SimpleLogger().Write(logDEBUG) << "reading raw 1GB took " << TIMER_SEC(read_1gb)
<< "s";
SimpleLogger().Write() << "raw read performance: " << std::setprecision(5) << std::fixed
<< 1024 * 1024 / (elapsed_seconds.count()) << "MB/sec";
<< 1024 * 1024 / TIMER_SEC(read_1gb) << "MB/sec";
std::vector<double> timing_results_raw_random;
SimpleLogger().Write(logDEBUG) << "running 1000 random I/Os of 4KB";
@ -207,7 +203,7 @@ int main(int argc, char *argv[])
{
unsigned block_to_read = std::rand() % number_of_blocks;
off_t current_offset = block_to_read * 4096;
time1 = std::chrono::steady_clock::now();
TIMER_START(random_access);
#ifdef __APPLE__
int ret1 = fseek(fd, current_offset, SEEK_SET);
int ret2 = read(fileno(fd), (char *)&single_block[0], 4096);
@ -222,7 +218,7 @@ int main(int argc, char *argv[])
int ret1 = lseek(f, current_offset, SEEK_SET);
int ret2 = read(f, (char *)single_block, 4096);
#endif
time2 = std::chrono::steady_clock::now();
TIMER_STOP(random_access);
if (((off_t) - 1) == ret1)
{
SimpleLogger().Write(logWARNING) << "offset: " << current_offset;
@ -235,7 +231,7 @@ int main(int argc, char *argv[])
SimpleLogger().Write(logWARNING) << "read error " << strerror(errno);
throw OSRMException("read error");
}
timing_results_raw_random.push_back(elapsed_seconds.count());
timing_results_raw_random.push_back(TIMER_SEC(random_access));
}
// Do statistics
@ -267,7 +263,7 @@ int main(int argc, char *argv[])
for (unsigned i = 0; i < 1000; ++i)
{
off_t current_offset = i * 4096;
time1 = std::chrono::steady_clock::now();
TIMER_START(read_every_100);
#ifdef __APPLE__
int ret1 = fseek(fd, current_offset, SEEK_SET);
int ret2 = read(fileno(fd), (char *)&single_block, 4096);
@ -283,7 +279,7 @@ int main(int argc, char *argv[])
int ret2 = read(f, (char *)single_block, 4096);
#endif
time2 = std::chrono::steady_clock::now();
TIMER_STOP(read_every_100);
if (((off_t) - 1) == ret1)
{
SimpleLogger().Write(logWARNING) << "offset: " << current_offset;
@ -296,7 +292,7 @@ int main(int argc, char *argv[])
SimpleLogger().Write(logWARNING) << "read error " << strerror(errno);
throw OSRMException("read error");
}
timing_results_raw_seq.push_back(elapsed_seconds.count());
timing_results_raw_seq.push_back(TIMER_SEC(read_every_100));
}
#ifdef __APPLE__
fclose(fd);

View File

@ -30,10 +30,10 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
#include <chrono>
#define TIMER_START(_X) std::chrono::time_point<std::chrono::steady_clock> _X##_start, _X##_stop; _X##_start = std::chrono::steady_clock::now()
#define TIMER_START(_X) auto _X##_start = std::chrono::steady_clock::now(), _X##_stop = _X##_start
#define TIMER_STOP(_X) _X##_stop = std::chrono::steady_clock::now()
#define TIMER_MSEC(_X) std::chrono::duration_cast<std::chrono::milliseconds>(_X##_stop - _X##_start).count()
#define TIMER_SEC(_X) std::chrono::duration_cast<std::chrono::seconds>(_X##_stop - _X##_start).count()
#define TIMER_SEC(_X) (0.001*std::chrono::duration_cast<std::chrono::milliseconds>(_X##_stop - _X##_start).count())
#define TIMER_MIN(_X) std::chrono::duration_cast<std::chrono::minutes>(_X##_stop - _X##_start).count()
#endif // TIMINGUTIL_H

View File

@ -36,6 +36,7 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
#include "Util/ProgramOptions.h"
#include "Util/SimpleLogger.h"
#include "Util/StringUtil.h"
#include "Util/TimingUtil.h"
#include "Util/UUID.h"
#include "typedefs.h"
@ -58,8 +59,8 @@ int main(int argc, char *argv[])
try
{
LogPolicy::GetInstance().Unmute();
std::chrono::time_point<std::chrono::steady_clock> startup_time =
std::chrono::steady_clock::now();
TIMER_START(extracting);
boost::filesystem::path config_file_path, input_path, profile_path;
unsigned requested_num_threads;
@ -240,16 +241,14 @@ int main(int argc, char *argv[])
throw OSRMException("Parser not initialized!");
}
SimpleLogger().Write() << "Parsing in progress..";
std::chrono::time_point<std::chrono::steady_clock> parsing_start_time =
std::chrono::steady_clock::now();
TIMER_START(parsing);
parser->Parse();
delete parser;
delete extractor_callbacks;
std::chrono::duration<double> parsing_duration =
std::chrono::steady_clock::now() - parsing_start_time;
SimpleLogger().Write() << "Parsing finished after " << parsing_duration.count()
TIMER_STOP(parsing);
SimpleLogger().Write() << "Parsing finished after " << TIMER_SEC(parsing)
<< " seconds";
if (extraction_containers.all_edges_list.empty())
@ -260,9 +259,8 @@ int main(int argc, char *argv[])
extraction_containers.PrepareData(output_file_name, restriction_fileName);
std::chrono::duration<double> extraction_duration =
std::chrono::steady_clock::now() - startup_time;
SimpleLogger().Write() << "extraction finished after " << extraction_duration.count()
TIMER_STOP(extracting);
SimpleLogger().Write() << "extraction finished after " << TIMER_SEC(extracting)
<< "s";
SimpleLogger().Write() << "To prepare the data for routing, run: "
<< "./osrm-prepare " << output_file_name << std::endl;

View File

@ -41,6 +41,7 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
#include "Util/SimpleLogger.h"
#include "Util/StringUtil.h"
#include "Util/TimingUtil.h"
#include "typedefs.h"
#include <boost/filesystem.hpp>
@ -72,8 +73,8 @@ int main(int argc, char *argv[])
try
{
LogPolicy::GetInstance().Unmute();
std::chrono::time_point<std::chrono::steady_clock> startup_time =
std::chrono::steady_clock::now();
TIMER_START(preparing);
TIMER_START(expansion);
boost::filesystem::path config_file_path, input_path, restrictions_path, profile_path;
unsigned int requested_num_threads;
@ -321,8 +322,7 @@ int main(int argc, char *argv[])
// TODO actually use scoping: Split this up in subfunctions
node_based_graph.reset();
std::chrono::duration<double> end_of_expansion_time =
std::chrono::steady_clock::now() - startup_time;
TIMER_STOP(expansion);
// Building grid-like nearest-neighbor data structure
SimpleLogger().Write() << "building r-tree ...";
@ -359,13 +359,12 @@ int main(int argc, char *argv[])
SimpleLogger().Write() << "initializing contractor";
Contractor *contractor = new Contractor(number_of_edge_based_nodes, edgeBasedEdgeList);
std::chrono::time_point<std::chrono::steady_clock> contraction_start_timestamp =
std::chrono::steady_clock::now();
TIMER_START(contraction);
contractor->Run();
std::chrono::duration<double> contraction_duration =
std::chrono::steady_clock::now() - contraction_start_timestamp;
SimpleLogger().Write() << "Contraction took " << contraction_duration.count() << " sec";
TIMER_STOP(contraction);
SimpleLogger().Write() << "Contraction took " << TIMER_SEC(contraction) << " sec";
DeallocatingVector<QueryEdge> contracted_edge_list;
contractor->GetEdges(contracted_edge_list);
@ -468,20 +467,19 @@ int main(int argc, char *argv[])
}
hsgr_output_stream.close();
std::chrono::duration<double> entire_duration =
std::chrono::steady_clock::now() - startup_time;
TIMER_STOP(preparing);
SimpleLogger().Write() << "Preprocessing : " << entire_duration.count() << " seconds";
SimpleLogger().Write() << "Preprocessing : " << TIMER_SEC(preparing) << " seconds";
SimpleLogger().Write() << "Expansion : "
<< (number_of_node_based_nodes / end_of_expansion_time.count())
<< (number_of_node_based_nodes / TIMER_SEC(expansion))
<< " nodes/sec and "
<< (number_of_edge_based_nodes / end_of_expansion_time.count())
<< (number_of_edge_based_nodes / TIMER_SEC(expansion))
<< " edges/sec";
SimpleLogger().Write() << "Contraction: "
<< (number_of_edge_based_nodes / contraction_duration.count())
<< (number_of_edge_based_nodes / TIMER_SEC(contraction))
<< " nodes/sec and "
<< number_of_used_edges / contraction_duration.count()
<< number_of_used_edges / TIMER_SEC(contraction)
<< " edges/sec";
node_array.clear();