Commit f5989479 authored by Sonja Happ's avatar Sonja Happ

- add more time measurements for processes

- fix a bug with result file names of ranks
- sync all el. links in backward sweep instead of only Backward edges
parent 25440552
......@@ -69,7 +69,7 @@ public:
double * param, int profile_id1, int profile_id2, double Vnom, bool _ict_connected);
/*public methods used during model execution*/
void synchronize(std::string agent_set);
void synchronize(const std::string agent_set);
void step();
void forward_backward_sweep();
void process_agent_messages();
......
......@@ -73,12 +73,15 @@ public:
/*logging time values*/
Time_measurement* tm; /*!< Time measurement for complete simulation time */
Time_measurement* tm_sync; /*!< Time measurement for synchronize() function */
Time_measurement* tm_sync_el; /*!< Time measurement for synchronize() function called for el connections*/
Time_measurement* tm_sync_mr; /*!< Time measurement for synchronize() function called for MR agents*/
Time_measurement* tm_tick; /*!< Time measurement for duration of one simulation tick*/
Time_measurement* tm_rt_tick; /*!< Time measurement for duration of one simulation tick*/
Time_measurement* tm_step; /*!< Time measurement for step() function */
Time_measurement* tm_fb_sweep; /*!< Time measurement for forward_backward_sweep() function */
Time_measurement* tm_msg_proc;/*!< Time measurement for process_agent_messages() function */
Time_measurement* tm_msg_proc_internal;/*!< Time measurement for delivering process internal messages */
Time_measurement* tm_msg_proc_external;/*!< Time measurement for delivering messages from other processes */
Time_measurement* tm_behaviors; /*!< Time measurement for computation of agent behaviors */
Time_measurement* tm_calculate_components;/*!< Time measurement for calculate_components() function */
Time_measurement* tm_backward_sweep;/*!< Time measurement for do_backward_sweep() function */
Time_measurement* tm_forward_sweep; /*!< Time measurement for do_forward_sweep() function */
......
......@@ -60,11 +60,12 @@ Model::Model(std::string &propsFile, int argc, char** argv, boost::mpi::communic
#endif
props = new repast::Properties(propsFile, argc, argv, comm);
rank = repast::RepastProcess::instance()->rank();
world_size = repast::RepastProcess::instance()->worldSize();
read_model_props();
rank = repast::RepastProcess::instance()->rank();
world_size = repast::RepastProcess::instance()->worldSize();
IO = new ModelIO(props,rank,world_size,profile_dir, d_props);
......@@ -256,10 +257,10 @@ void Model::init() {
/* initialize the agent behaviors*/
this->init_agent_behaviors();
IO->stop_time_measurement(IO->tm_init);
MPI_Barrier(MPI_COMM_WORLD);
IO->stop_time_measurement(IO->tm_init);
// RepastHPC Copy-Update here to make sure that initial values set during agent
// behavior init are shared with agent copies
synchronize_el_connections();
......@@ -573,7 +574,6 @@ void Model::create_agents() {
// std::cout << "---> Creator in DF not needed because non-intelligent case is simulated." << std::endl;
//}
}
IO->stop_time_measurement(IO->tm_distribute_agents);
// [DB] Add agentcount
IO->addMetaEntry(rank, "agents_on_rank", "agents", std::to_string(agent_count));
......@@ -586,6 +586,8 @@ void Model::create_agents() {
if(rank == 0){
std::cout << "Done." << std::endl;
}
IO->stop_time_measurement(IO->tm_distribute_agents);
}
/*! \brief Connect agents electrically according to content of scenario files
......@@ -1386,9 +1388,14 @@ void Model::start_tick_time_measurement() {
/*! \brief Synchronize copies of non-local agents with their origins using RepastHPC methods
* \param agent_set Name of the set of non-local agents to be updated
* */
void Model::synchronize(std::string agent_set) {
void Model::synchronize(const std::string agent_set) {
if (agent_set == SET_FORWARD_SWEEP || agent_set == SET_BACKWARD_SWEEP){
IO->start_time_measurement(IO->tm_sync_el);
} else {
IO->start_time_measurement(IO->tm_sync_mr);
}
IO->start_time_measurement(IO->tm_sync);
try {
repast::RepastProcess::instance()->synchronizeAgentStates<AgentPackage, AgentPackageProvider, AgentPackageReceiver>(
*provider, *receiver, agent_set);
......@@ -1403,7 +1410,13 @@ void Model::synchronize(std::string agent_set) {
<< err.what() << std::endl;
MPI_Abort(MPI_COMM_WORLD, -1);
}
IO->stop_time_measurement(IO->tm_sync);
if (agent_set == SET_FORWARD_SWEEP || agent_set == SET_BACKWARD_SWEEP){
IO->stop_time_measurement(IO->tm_sync_el);
} else {
IO->stop_time_measurement(IO->tm_sync_mr);
}
}
......@@ -1580,18 +1593,14 @@ void Model::do_backward_sweep() {
counter++;
IO->stop_time_measurement(IO->tm_backward_sweep);
//synchronize changes
// in backward sweep only info about next nodes are required
// that is why here only backward sweep set is synchronized
synchronize(SET_BACKWARD_SWEEP);
synchronize_el_connections();
IO->start_time_measurement(IO->tm_backward_sweep);
IO->flush_log();
}
// at the end of each backward sweep, status info needs to be updated also for forward sweep set
IO->stop_time_measurement(IO->tm_backward_sweep);
synchronize(SET_FORWARD_SWEEP);
IO->start_time_measurement(IO->tm_backward_sweep);
IO->log_info("backward sweep took " + std::to_string(counter) + " iterations.");
backward_sweep_finished=false;
IO->stop_time_measurement(IO->tm_backward_sweep);
......@@ -1652,27 +1661,31 @@ void Model::do_forward_sweep() {
* As a result, the agents determine their control behavior
* */
void Model::process_agent_messages() {
IO->start_time_measurement(IO->tm_msg_proc);
IO->start_time_measurement(IO->tm_msg_proc_internal);
IO->log_info("####### now calculating communication interactions #######");
/*route messages of last step*/
MR_agent->route_outgoing_agent_messages_own(agent_network_MR);
IO->stop_time_measurement(IO->tm_msg_proc);
IO->stop_time_measurement(IO->tm_msg_proc_internal);
//Send messages between processes' Message Routers via MPI
this->synchronize(SET_MESSAGE_ROUTERS);
IO->start_time_measurement(IO->tm_msg_proc);
IO->start_time_measurement(IO->tm_msg_proc_external);
MR_agent->route_outgoing_agent_messages_other(agent_network_MR);
IO->stop_time_measurement(IO->tm_msg_proc_external);
/*make agents process messages*/
IO->start_time_measurement(IO->tm_behaviors);
IO->log_info("####### local agents process incoming messages #######");
for(auto i : local_agents){
IO->log_info("###### for agent " + IO->id2str(i->getId()));
i->process_incoming_messages();
}
IO->stop_time_measurement(IO->tm_behaviors);
IO->log_info("####### calculating communication interactions finished #######");
IO->stop_time_measurement(IO->tm_msg_proc);
}
/*! \brief exit the simulation (called in error case)
......
......@@ -42,12 +42,15 @@ props(_props), rank(_rank), world_size(_world_size), profile_dir(_profile_dir)
tm = new Time_measurement("simulation-time", rank);
tm->start();
tm_sync = new Time_measurement("synctime",rank);
tm_sync_el = new Time_measurement("synctime_el",rank);
tm_sync_mr = new Time_measurement("synctime_mr",rank);
tm_step = new Time_measurement("steptime",rank);
tm_tick = new Time_measurement("ticktime",rank);
tm_rt_tick = new Time_measurement("realtimeticktime",rank);
tm_fb_sweep = new Time_measurement("gridcalculationtime",rank);
tm_msg_proc = new Time_measurement("msgproctime",rank);
tm_msg_proc_internal = new Time_measurement("msgproctime_internal",rank);
tm_msg_proc_external = new Time_measurement("msgproctime_external",rank);
tm_behaviors = new Time_measurement("behaviors",rank);
tm_calculate_components = new Time_measurement("calculatecomponents",rank);
tm_backward_sweep = new Time_measurement("backward_sweep",rank);
tm_forward_sweep = new Time_measurement("forward_sweep",rank);
......@@ -144,14 +147,20 @@ void ModelIO::init_db() {
//initial typedeclarations
if (rank == 0) {
// register timeMeasurements
d_props.result.dbconn->addTimeMeasurementType("synctime", "Time for syncing Agents in us");
d_props.result.dbconn->addTimeMeasurementType("synctime_el", "Time for syncing el connections of Agents in us");
d_props.result.dbconn->addTimeMeasurementType("synctime_mr", "Time for syncing MR Agents in us");
d_props.result.dbconn->addTimeMeasurementType("steptime", "Time for step in us");
d_props.result.dbconn->addTimeMeasurementType("ticktime","duration of a simulation tick in us");
d_props.result.dbconn->addTimeMeasurementType("realtimeticktime","duration of a realtime simulation tick in us");
d_props.result.dbconn->addTimeMeasurementType("msgproctime_internal", "Time for deliverin process internal messages in us");
d_props.result.dbconn->addTimeMeasurementType("msgproctime_external", "Time for delivering process external messages in us");
d_props.result.dbconn->addTimeMeasurementType("behaviors", "Time for agent behavior computation in us");
d_props.result.dbconn->addTimeMeasurementType("gridcalculationtime", "Time for calculating grid in us");
d_props.result.dbconn->addTimeMeasurementType("msgproctime", "Time for message processing in us");
d_props.result.dbconn->addTimeMeasurementType("calculatecomponents","Time for calculating components in us");
d_props.result.dbconn->addTimeMeasurementType("backward_sweep","Time for backward sweeping in us");
d_props.result.dbconn->addTimeMeasurementType("ticktime","duration of a simulation tick in us");
d_props.result.dbconn->addTimeMeasurementType("realtimeticktime","duration of a realtime simulation tick in us");
d_props.result.dbconn->addTimeMeasurementType("forward_sweep","Time for forward sweeping in us");
......@@ -227,12 +236,15 @@ void ModelIO::finish_time_measurements(unsigned long &stop_at){
}
delete tm;
delete tm_sync;
delete tm_sync_el;
delete tm_sync_mr;
delete tm_tick;
delete tm_rt_tick;
delete tm_step;
delete tm_fb_sweep;
delete tm_msg_proc;
delete tm_msg_proc_internal;
delete tm_msg_proc_external;
delete tm_behaviors;
delete tm_calculate_components;
delete tm_backward_sweep;
delete tm_forward_sweep;
......@@ -270,13 +282,16 @@ void ModelIO::addMetaEntry(int _rank, std::string _metatype, std::string _key, s
void ModelIO::log_results_for_tick() {
log_result_csv( std::to_string((int) repast::RepastProcess::instance()->getScheduleRunner().currentTick()) +
"," + std::to_string(tm_tick->get_duration() / 1000000.0) + //us to s
"," + std::to_string(tm_sync->get_duration() / 1000000.0) + //us to s
"," + std::to_string(tm_sync_el->get_duration() / 1000000.0) + //us to s
"," + std::to_string(tm_sync_mr->get_duration() / 1000000.0) + //us to s
"," + std::to_string(tm_step->get_duration() / 1000000.0) +
"," + std::to_string(tm_fb_sweep->get_duration() / 1000000.0) +
"," + std::to_string(tm_calculate_components->get_duration() / 1000000.0) +
"," + std::to_string(tm_forward_sweep->get_duration() / 1000000.0) +
"," + std::to_string(tm_backward_sweep->get_duration() / 1000000.0) +
"," + std::to_string(tm_msg_proc->get_duration() / 1000000.0) +
"," + std::to_string(tm_msg_proc_internal->get_duration() / 1000000.0) +
"," + std::to_string(tm_msg_proc_external->get_duration() / 1000000.0) +
"," + std::to_string(tm_behaviors->get_duration() / 1000000.0) +
"," + std::to_string(number_of_fbs_sweeps) +
"," + std::to_string(tm_rt_tick->get_duration() / 1000000.0)
......@@ -286,8 +301,10 @@ void ModelIO::log_results_for_tick() {
if(d_props.result.db_results){
auto tick = repast::RepastProcess::instance()->getScheduleRunner().currentTick();
try {
d_props.result.dbconn->addTimeMeasurement(tm_sync->get_time_measurement_type(), tm_sync->getId(), tm_sync->get_duration(),
d_props.result.dbconn->addTimeMeasurement(tm_sync_el->get_time_measurement_type(), tm_sync_el->getId(), tm_sync_el->get_duration(),
tick);
d_props.result.dbconn->addTimeMeasurement(tm_sync_mr->get_time_measurement_type(), tm_sync_mr->getId(), tm_sync_mr->get_duration(),
tick);
d_props.result.dbconn->addTimeMeasurement(tm_tick->get_time_measurement_type(), tm_tick->getId(), tm_tick->get_duration(),
tick);
d_props.result.dbconn->addTimeMeasurement(tm_step->get_time_measurement_type(), tm_step->getId(), tm_step->get_duration(),
......@@ -301,8 +318,12 @@ void ModelIO::log_results_for_tick() {
tm_forward_sweep->get_duration(), tick);
d_props.result.dbconn->addTimeMeasurement(tm_backward_sweep->get_time_measurement_type(), tm_backward_sweep->getId(),
tm_backward_sweep->get_duration(), tick);
d_props.result.dbconn->addTimeMeasurement(tm_msg_proc->get_time_measurement_type(), tm_msg_proc->getId(),
tm_msg_proc->get_duration(), tick);
d_props.result.dbconn->addTimeMeasurement(tm_msg_proc_internal->get_time_measurement_type(), tm_msg_proc_internal->getId(),
tm_msg_proc_internal->get_duration(), tick);
d_props.result.dbconn->addTimeMeasurement(tm_msg_proc_external->get_time_measurement_type(), tm_msg_proc_external->getId(),
tm_msg_proc_external->get_duration(), tick);
d_props.result.dbconn->addTimeMeasurement(tm_behaviors->get_time_measurement_type(), tm_behaviors->getId(),
tm_behaviors->get_duration(), tick);
d_props.result.dbconn->addTimeMeasurement(tm_rt_tick->get_time_measurement_type(), tm_rt_tick->getId(),
tm_rt_tick->get_duration(), tick);
}
......@@ -330,7 +351,8 @@ void ModelIO::log_results_for_tick() {
void ModelIO::reset_time_measurements() {
//reset all time measurements for the next tick
tm_sync->reset();
tm_sync_el->reset();
tm_sync_mr->reset();
tm_tick->reset();
tm_rt_tick->reset();
tm_step->reset();
......@@ -338,12 +360,14 @@ void ModelIO::reset_time_measurements() {
tm_calculate_components->reset();
tm_forward_sweep->reset();
tm_backward_sweep->reset();
tm_msg_proc->reset();
tm_msg_proc_internal->reset();
tm_msg_proc_external->reset();
tm_behaviors->reset();
}
void ModelIO::set_result_file_header() {
result_stream << "tick,tick time [s],sync time [s],step time [s],forward backward sweep time [s],calculate components [s],forward sweep [s],backward sweep [s],msg proc time [s],number of FBS sweeps,real time tick time [s]" << std::endl;
result_stream << "tick,tick time [s],sync time el [s],sync time MR [s],step time [s],forward backward sweep time [s],calculate components [s],forward sweep [s],backward sweep [s],msg proc time internal [s],msg proc time external [s],behavior calculation time [s],number of FBS sweeps,real time tick time [s]" << std::endl;
}
/*! \brief Log one line in csv file
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment