1 /* Copyright (c) 2010-2017. The SimGrid Team.
2 * All rights reserved. */
4 /* This program is free software; you can redistribute it and/or modify it
5 * under the terms of the license (GNU LGPL) which comes with this package. */
7 #include "simgrid/sg_config.h"
8 #include "src/instr/instr_private.hpp"
9 #include "src/instr/instr_smpi.hpp"
10 #include "src/smpi/include/private.hpp"
12 #include "xbt/virtu.h" /* sg_cmdline */
15 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(instr_paje_trace, instr, "tracing event system");
17 static std::stringstream stream;
18 FILE *tracing_file = nullptr;
20 std::map<container_t, FILE*> tracing_files; // TI specific
22 std::vector<simgrid::instr::PajeEvent*> buffer;
23 void buffer_debug(std::vector<simgrid::instr::PajeEvent*>* buf);
25 void dump_comment(std::string comment)
29 fprintf(tracing_file, "# %s\n", comment.c_str());
32 void dump_comment_file(std::string filename)
36 std::ifstream* fs = new std::ifstream();
37 fs->open(filename.c_str(), std::ifstream::in);
40 THROWF(system_error, 1, "Comment file %s could not be opened for reading.", filename.c_str());
42 while (not fs->eof()) {
44 fprintf (tracing_file, "# ");
45 std::getline(*fs, line);
46 fprintf(tracing_file, "%s", line.c_str());
51 double TRACE_last_timestamp_to_dump = 0;
52 //dumps the trace file until the timestamp TRACE_last_timestamp_to_dump
53 void TRACE_paje_dump_buffer(bool force)
55 if (not TRACE_is_enabled())
57 XBT_DEBUG("%s: dump until %f. starts", __FUNCTION__, TRACE_last_timestamp_to_dump);
59 for (auto const& event : buffer) {
65 std::vector<simgrid::instr::PajeEvent*>::iterator i = buffer.begin();
66 for (auto const& event : buffer) {
67 double head_timestamp = event->timestamp_;
68 if (head_timestamp > TRACE_last_timestamp_to_dump)
74 buffer.erase(buffer.begin(), i);
76 XBT_DEBUG("%s: ends", __FUNCTION__);
79 void buffer_debug(std::vector<simgrid::instr::PajeEvent*>* buf)
82 XBT_DEBUG(">>>>>> Dump the state of the buffer. %zu events", buf->size());
83 for (auto const& event : *buf) {
85 XBT_DEBUG("%p %s", event, stream.str().c_str());
92 static void print_row() {
94 fprintf(tracing_file, "%s", stream.str().c_str());
95 XBT_DEBUG("Dump %s", stream.str().c_str());
100 static void print_timestamp(simgrid::instr::PajeEvent* event)
103 /* prevent 0.0000 in the trace - this was the behavior before the transition to c++ */
104 if (event->timestamp_ < 1e-12)
107 stream << event->timestamp_;
110 /* internal do the instrumentation module */
111 void simgrid::instr::PajeEvent::insertIntoBuffer()
113 if (not TRACE_buffer()) {
118 buffer_debug(&buffer);
120 XBT_DEBUG("%s: insert event_type=%d, timestamp=%f, buffersize=%zu)", __FUNCTION__, static_cast<int>(eventType_),
121 timestamp_, buffer.size());
122 std::vector<simgrid::instr::PajeEvent*>::reverse_iterator i;
123 for (i = buffer.rbegin(); i != buffer.rend(); ++i) {
124 simgrid::instr::PajeEvent* e1 = *i;
125 XBT_DEBUG("compare to %p is of type %d; timestamp:%f", e1, static_cast<int>(e1->eventType_), e1->timestamp_);
126 if (e1->timestamp_ <= timestamp_)
129 if (i == buffer.rend())
130 XBT_DEBUG("%s: inserted at beginning", __FUNCTION__);
131 else if (i == buffer.rbegin())
132 XBT_DEBUG("%s: inserted at end", __FUNCTION__);
134 XBT_DEBUG("%s: inserted at pos= %zd from its end", __FUNCTION__, std::distance(buffer.rbegin(), i));
135 buffer.insert(i.base(), this);
137 buffer_debug(&buffer);
140 simgrid::instr::PajeEvent::~PajeEvent()
142 XBT_DEBUG("%s not implemented for %p: event_type=%d, timestamp=%f", __FUNCTION__, this, (int)eventType_, timestamp_);
145 void TRACE_paje_start() {
146 char *filename = TRACE_get_filename();
147 tracing_file = fopen(filename, "w");
148 if (tracing_file == nullptr){
149 THROWF (system_error, 1, "Tracefile %s could not be opened for writing.", filename);
152 XBT_DEBUG("Filename %s is open for writing", filename);
154 /* output generator version */
155 fprintf (tracing_file, "#This file was generated using SimGrid-%d.%d.%d\n",
156 SIMGRID_VERSION_MAJOR, SIMGRID_VERSION_MINOR, SIMGRID_VERSION_PATCH);
157 fprintf (tracing_file, "#[");
160 xbt_dynar_foreach (xbt_cmdline, cpt, str){
161 fprintf(tracing_file, "%s ",str);
163 fprintf (tracing_file, "]\n");
165 /* output one line comment */
166 dump_comment (TRACE_get_comment());
168 /* output comment file */
169 dump_comment_file (TRACE_get_comment_file());
172 TRACE_header(TRACE_basic(),TRACE_display_sizes());
175 void TRACE_paje_end() {
176 fclose(tracing_file);
177 char *filename = TRACE_get_filename();
178 XBT_DEBUG("Filename %s is closed", filename);
181 void simgrid::instr::Value::print()
183 XBT_DEBUG("%s: event_type=%d", __FUNCTION__, simgrid::instr::PAJE_DefineEntityValue);
185 if (instr_fmt_type == instr_fmt_paje) {
186 stream << std::fixed << std::setprecision(TRACE_precision());
187 stream << simgrid::instr::PAJE_DefineEntityValue;
188 stream << " " << id_ << " " << father_->getId() << " " << name_;
190 stream << " \"" << color_ << "\"";
192 } else if (instr_fmt_type == instr_fmt_TI) {
199 simgrid::instr::SetVariableEvent::SetVariableEvent(double timestamp, container_t container, Type* type, double value)
200 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_SetVariable), value(value)
202 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
206 void simgrid::instr::SetVariableEvent::print()
208 if (instr_fmt_type == instr_fmt_paje) {
209 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
210 stream << std::fixed << std::setprecision(TRACE_precision());
211 stream << (int)this->eventType_;
212 print_timestamp(this);
213 stream << " " << type->getId() << " " << container->getId() << " " << value;
215 } else if (instr_fmt_type == instr_fmt_TI) {
222 simgrid::instr::AddVariableEvent::AddVariableEvent(double timestamp, container_t container, simgrid::instr::Type* type,
224 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_AddVariable), value(value)
226 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
230 void simgrid::instr::AddVariableEvent::print()
232 if (instr_fmt_type == instr_fmt_paje) {
233 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
234 stream << std::fixed << std::setprecision(TRACE_precision());
235 stream << (int)this->eventType_;
236 print_timestamp(this);
237 stream << " " << type->getId() << " " << container->getId() << " " << value;
239 } else if (instr_fmt_type == instr_fmt_TI) {
246 simgrid::instr::SubVariableEvent::SubVariableEvent(double timestamp, container_t container, Type* type, double value)
247 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_SubVariable), value(value)
249 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
253 void simgrid::instr::SubVariableEvent::print()
255 if (instr_fmt_type == instr_fmt_paje) {
256 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
257 stream << std::fixed << std::setprecision(TRACE_precision());
258 stream << (int)this->eventType_;
259 print_timestamp(this);
260 stream << " " << type->getId() << " " << container->getId() << " " << value;
262 } else if (instr_fmt_type == instr_fmt_TI) {
269 simgrid::instr::SetStateEvent::SetStateEvent(double timestamp, container_t container, Type* type, Value* value)
270 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_SetState), value(value)
273 if (xbt_cfg_get_boolean("smpi/trace-call-location")) {
274 smpi_trace_call_location_t* loc = smpi_trace_get_call_location();
275 filename = loc->filename;
276 linenumber = loc->linenumber;
280 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
284 void simgrid::instr::SetStateEvent::print()
286 if (instr_fmt_type == instr_fmt_paje) {
287 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
288 stream << std::fixed << std::setprecision(TRACE_precision());
289 stream << (int)this->eventType_;
290 print_timestamp(this);
291 stream << " " << type->getId() << " " << container->getId();
292 stream << " " << value->getId();
294 if (xbt_cfg_get_boolean("smpi/trace-call-location")) {
295 stream << " \"" << filename << "\" " << linenumber;
299 } else if (instr_fmt_type == instr_fmt_TI) {
306 simgrid::instr::PushStateEvent::PushStateEvent(double timestamp, container_t container, Type* type, Value* value,
308 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_PushState), value(value), extra_(extra)
311 if (xbt_cfg_get_boolean("smpi/trace-call-location")) {
312 smpi_trace_call_location_t* loc = smpi_trace_get_call_location();
313 filename = loc->filename;
314 linenumber = loc->linenumber;
318 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
323 simgrid::instr::PushStateEvent::PushStateEvent(double timestamp, container_t container, Type* type, Value* val)
324 : PushStateEvent(timestamp, container, type, val, nullptr)
327 void simgrid::instr::PushStateEvent::print()
329 if (instr_fmt_type == instr_fmt_paje) {
330 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
331 stream << std::fixed << std::setprecision(TRACE_precision());
332 stream << (int)this->eventType_;
333 print_timestamp(this);
334 stream << " " << type->getId() << " " << container->getId();
335 stream << " " << value->getId();
337 if (TRACE_display_sizes()) {
339 if (extra_ != nullptr) {
340 stream << static_cast<instr_extra_data>(extra_)->send_size;
346 if (xbt_cfg_get_boolean("smpi/trace-call-location")) {
347 stream << " \"" << filename << "\" " << linenumber;
352 if (extra_ != nullptr) {
353 if (static_cast<instr_extra_data>(extra_)->sendcounts != nullptr)
354 xbt_free(static_cast<instr_extra_data>(extra_)->sendcounts);
355 if (static_cast<instr_extra_data>(extra_)->recvcounts != nullptr)
356 xbt_free(static_cast<instr_extra_data>(extra_)->recvcounts);
359 } else if (instr_fmt_type == instr_fmt_TI) {
360 if (extra_ == nullptr)
362 instr_extra_data extra = (instr_extra_data)extra_;
364 char* process_id = nullptr;
365 // FIXME: dirty extract "rank-" from the name, as we want the bare process id here
366 if (container->getName().find("rank-") != 0)
367 process_id = xbt_strdup(container->getCname());
369 process_id = xbt_strdup(container->getCname() + 5);
371 FILE* trace_file = tracing_files.at(container);
373 switch (extra->type) {
375 fprintf(trace_file, "%s init\n", process_id);
377 case TRACING_FINALIZE:
378 fprintf(trace_file, "%s finalize\n", process_id);
381 fprintf(trace_file, "%s send %d %d %s\n", process_id, extra->dst, extra->send_size, extra->datatype1);
384 fprintf(trace_file, "%s Isend %d %d %s\n", process_id, extra->dst, extra->send_size, extra->datatype1);
387 fprintf(trace_file, "%s recv %d %d %s\n", process_id, extra->src, extra->send_size, extra->datatype1);
390 fprintf(trace_file, "%s Irecv %d %d %s\n", process_id, extra->src, extra->send_size, extra->datatype1);
393 fprintf(trace_file, "%s test\n", process_id);
396 fprintf(trace_file, "%s wait\n", process_id);
398 case TRACING_WAITALL:
399 fprintf(trace_file, "%s waitAll\n", process_id);
401 case TRACING_BARRIER:
402 fprintf(trace_file, "%s barrier\n", process_id);
404 case TRACING_BCAST: // rank bcast size (root) (datatype)
405 fprintf(trace_file, "%s bcast %d ", process_id, extra->send_size);
406 if (extra->root != 0 || (extra->datatype1 && strcmp(extra->datatype1, "")))
407 fprintf(trace_file, "%d %s", extra->root, extra->datatype1);
408 fprintf(trace_file, "\n");
410 case TRACING_REDUCE: // rank reduce comm_size comp_size (root) (datatype)
411 fprintf(trace_file, "%s reduce %d %f ", process_id, extra->send_size, extra->comp_size);
412 if (extra->root != 0 || (extra->datatype1 && strcmp(extra->datatype1, "")))
413 fprintf(trace_file, "%d %s", extra->root, extra->datatype1);
414 fprintf(trace_file, "\n");
416 case TRACING_ALLREDUCE: // rank allreduce comm_size comp_size (datatype)
417 fprintf(trace_file, "%s allReduce %d %f %s\n", process_id, extra->send_size, extra->comp_size,
420 case TRACING_ALLTOALL: // rank alltoall send_size recv_size (sendtype) (recvtype)
421 fprintf(trace_file, "%s allToAll %d %d %s %s\n", process_id, extra->send_size, extra->recv_size,
422 extra->datatype1, extra->datatype2);
424 case TRACING_ALLTOALLV: // rank alltoallv send_size [sendcounts] recv_size [recvcounts] (sendtype) (recvtype)
425 fprintf(trace_file, "%s allToAllV %d ", process_id, extra->send_size);
426 for (int i = 0; i < extra->num_processes; i++)
427 fprintf(trace_file, "%d ", extra->sendcounts[i]);
428 fprintf(trace_file, "%d ", extra->recv_size);
429 for (int i = 0; i < extra->num_processes; i++)
430 fprintf(trace_file, "%d ", extra->recvcounts[i]);
431 fprintf(trace_file, "%s %s \n", extra->datatype1, extra->datatype2);
433 case TRACING_GATHER: // rank gather send_size recv_size root (sendtype) (recvtype)
434 fprintf(trace_file, "%s gather %d %d %d %s %s\n", process_id, extra->send_size, extra->recv_size, extra->root,
435 extra->datatype1, extra->datatype2);
437 case TRACING_ALLGATHERV: // rank allgatherv send_size [recvcounts] (sendtype) (recvtype)
438 fprintf(trace_file, "%s allGatherV %d ", process_id, extra->send_size);
439 for (int i = 0; i < extra->num_processes; i++)
440 fprintf(trace_file, "%d ", extra->recvcounts[i]);
441 fprintf(trace_file, "%s %s \n", extra->datatype1, extra->datatype2);
443 case TRACING_REDUCE_SCATTER: // rank reducescatter [recvcounts] comp_size (sendtype)
444 fprintf(trace_file, "%s reduceScatter ", process_id);
445 for (int i = 0; i < extra->num_processes; i++)
446 fprintf(trace_file, "%d ", extra->recvcounts[i]);
447 fprintf(trace_file, "%f %s\n", extra->comp_size, extra->datatype1);
449 case TRACING_COMPUTING:
450 fprintf(trace_file, "%s compute %f\n", process_id, extra->comp_size);
452 case TRACING_SLEEPING:
453 fprintf(trace_file, "%s sleep %f\n", process_id, extra->sleep_duration);
455 case TRACING_GATHERV: // rank gatherv send_size [recvcounts] root (sendtype) (recvtype)
456 fprintf(trace_file, "%s gatherV %d ", process_id, extra->send_size);
457 for (int i = 0; i < extra->num_processes; i++)
458 fprintf(trace_file, "%d ", extra->recvcounts[i]);
459 fprintf(trace_file, "%d %s %s\n", extra->root, extra->datatype1, extra->datatype2);
461 case TRACING_ALLGATHER: // rank allgather sendcount recvcounts (sendtype) (recvtype)
462 fprintf(trace_file, "%s allGather %d %d %s %s", process_id, extra->send_size, extra->recv_size,
463 extra->datatype1, extra->datatype2);
465 case TRACING_WAITANY:
466 case TRACING_SENDRECV:
467 case TRACING_SCATTER:
468 case TRACING_SCATTERV:
471 case TRACING_COMM_SIZE:
472 case TRACING_COMM_SPLIT:
473 case TRACING_COMM_DUP:
477 XBT_WARN("Call from %s impossible to translate into replay command : Not implemented (yet)", value->getCname());
481 if (extra->recvcounts != nullptr)
482 xbt_free(extra->recvcounts);
483 if (extra->sendcounts != nullptr)
484 xbt_free(extra->sendcounts);
485 xbt_free(process_id);
493 simgrid::instr::PopStateEvent::PopStateEvent(double timestamp, container_t container, Type* type)
494 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_PopState)
496 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
500 void simgrid::instr::PopStateEvent::print()
502 if (instr_fmt_type == instr_fmt_paje) {
503 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
504 stream << std::fixed << std::setprecision(TRACE_precision());
505 stream << (int)this->eventType_;
506 print_timestamp(this);
507 stream << " " << type->getId() << " " << container->getId();
509 } else if (instr_fmt_type == instr_fmt_TI) {
516 simgrid::instr::ResetStateEvent::ResetStateEvent(double timestamp, container_t container, Type* type)
517 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_ResetState)
519 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
524 void simgrid::instr::ResetStateEvent::print()
526 if (instr_fmt_type == instr_fmt_paje) {
527 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
528 stream << std::fixed << std::setprecision(TRACE_precision());
529 stream << (int)this->eventType_;
530 print_timestamp(this);
531 stream << " " << type->getId() << " " << container->getId();
533 } else if (instr_fmt_type == instr_fmt_TI) {
540 simgrid::instr::StartLinkEvent::StartLinkEvent(double timestamp, container_t container, Type* type,
541 container_t sourceContainer, std::string value, std::string key)
542 : StartLinkEvent(timestamp, container, type, sourceContainer, value, key, -1)
545 simgrid::instr::StartLinkEvent::StartLinkEvent(double timestamp, container_t container, Type* type,
546 container_t sourceContainer, std::string value, std::string key,
548 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_StartLink)
549 , sourceContainer_(sourceContainer)
554 XBT_DEBUG("%s: event_type=%d, timestamp=%f, value:%s", __FUNCTION__, (int)eventType_, this->timestamp_, this->value_.c_str());
558 void simgrid::instr::StartLinkEvent::print()
560 if (instr_fmt_type == instr_fmt_paje) {
561 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
562 stream << std::fixed << std::setprecision(TRACE_precision());
563 stream << (int)this->eventType_;
564 print_timestamp(this);
565 stream << " " << type->getId() << " " << container->getId() << " " << value_;
566 stream << " " << sourceContainer_->getId() << " " << key_;
568 if (TRACE_display_sizes()) {
569 stream << " " << size_;
572 } else if (instr_fmt_type == instr_fmt_TI) {
579 simgrid::instr::EndLinkEvent::EndLinkEvent(double timestamp, container_t container, Type* type,
580 container_t destContainer, std::string value, std::string key)
581 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_EndLink)
582 , destContainer(destContainer)
586 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
590 void simgrid::instr::EndLinkEvent::print()
592 if (instr_fmt_type == instr_fmt_paje) {
593 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
594 stream << std::fixed << std::setprecision(TRACE_precision());
595 stream << (int)this->eventType_;
596 print_timestamp(this);
597 stream << " " << type->getId() << " " << container->getId() << " " << value;
598 stream << " " << destContainer->getId() << " " << key;
600 } else if (instr_fmt_type == instr_fmt_TI) {
607 simgrid::instr::NewEvent::NewEvent(double timestamp, container_t container, Type* type, Value* val)
608 : simgrid::instr::PajeEvent::PajeEvent(container, type, timestamp, PAJE_NewEvent)
612 XBT_DEBUG("%s: event_type=%d, timestamp=%f", __FUNCTION__, (int)eventType_, this->timestamp_);
617 void simgrid::instr::NewEvent::print()
619 if (instr_fmt_type == instr_fmt_paje) {
620 XBT_DEBUG("%s: event_type=%d, timestamp=%.*f", __FUNCTION__, (int)eventType_, TRACE_precision(), timestamp_);
621 stream << std::fixed << std::setprecision(TRACE_precision());
622 stream << (int)this->eventType_;
623 print_timestamp(this);
624 stream << " " << type->getId() << " " << container->getId() << " " << val->getId();
626 } else if (instr_fmt_type == instr_fmt_TI) {
633 void TRACE_TI_start()
635 char *filename = TRACE_get_filename();
636 tracing_file = fopen(filename, "w");
637 if (tracing_file == nullptr)
638 THROWF(system_error, 1, "Tracefile %s could not be opened for writing.", filename);
640 XBT_DEBUG("Filename %s is open for writing", filename);
642 /* output one line comment */
643 dump_comment(TRACE_get_comment());
645 /* output comment file */
646 dump_comment_file(TRACE_get_comment_file());
651 fclose(tracing_file);
652 char *filename = TRACE_get_filename();
653 XBT_DEBUG("Filename %s is closed", filename);