From b6cf6f757d42fe10a870a6d41002c9c397a376e5 Mon Sep 17 00:00:00 2001 From: Byeonggil Jun Date: Tue, 19 Dec 2023 14:46:12 +0900 Subject: [PATCH 1/8] Add an option to the trace visualization tool for specifying the target time interval --- util/tracing/trace_to_csv.c | 329 +++++++++++++++------------- util/tracing/visualization/fedsd.py | 25 ++- 2 files changed, 193 insertions(+), 161 deletions(-) diff --git a/util/tracing/trace_to_csv.c b/util/tracing/trace_to_csv.c index 9f237adb4..1060f07b4 100644 --- a/util/tracing/trace_to_csv.c +++ b/util/tracing/trace_to_csv.c @@ -100,7 +100,7 @@ instant_t latest_time = 0LL; * Read a trace in the trace_file and write it to the output_file as CSV. * @return The number of records read or 0 upon seeing an EOF. */ -size_t read_and_write_trace() { +size_t read_and_write_trace(instant_t trace_start_time, instant_t trace_end_time) { int trace_length = read_trace(); if (trace_length == 0) return 0; // Write each line. @@ -116,156 +116,161 @@ size_t read_and_write_trace() { if (trigger_name == NULL) { trigger_name = "NO TRIGGER"; } - fprintf(output_file, "%s, %s, %d, %d, %lld, %d, %lld, %s, %lld\n", - trace_event_names[trace[i].event_type], - reactor_name, - trace[i].src_id, - trace[i].dst_id, - trace[i].logical_time - start_time, - trace[i].microstep, - trace[i].physical_time - start_time, - trigger_name, - trace[i].extra_delay - ); - // Update summary statistics. - if (trace[i].physical_time > latest_time) { - latest_time = trace[i].physical_time; - } - if (object_instance >= 0 && summary_stats[NUM_EVENT_TYPES + object_instance] == NULL) { - summary_stats[NUM_EVENT_TYPES + object_instance] = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); - } - if (trigger_instance >= 0 && summary_stats[NUM_EVENT_TYPES + trigger_instance] == NULL) { - summary_stats[NUM_EVENT_TYPES + trigger_instance] = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); - } + if ((trace[i].logical_time - start_time) >= trace_start_time + && (trace[i].logical_time - start_time) < trace_end_time) { + fprintf(output_file, "%s, %s, %d, %d, %lld, %d, %lld, %s, %lld\n", + trace_event_names[trace[i].event_type], + reactor_name, + trace[i].src_id, + trace[i].dst_id, + trace[i].logical_time - start_time, + trace[i].microstep, + trace[i].physical_time - start_time, + trigger_name, + trace[i].extra_delay + ); + // Update summary statistics. + if (trace[i].physical_time > latest_time) { + latest_time = trace[i].physical_time; + } + if (object_instance >= 0 && summary_stats[NUM_EVENT_TYPES + object_instance] == NULL) { + summary_stats[NUM_EVENT_TYPES + object_instance] = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); + } + if (trigger_instance >= 0 && summary_stats[NUM_EVENT_TYPES + trigger_instance] == NULL) { + summary_stats[NUM_EVENT_TYPES + trigger_instance] = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); + } - summary_stats_t* stats = NULL; - interval_t exec_time; - reaction_stats_t* rstats; - int index; + summary_stats_t* stats = NULL; + interval_t exec_time; + reaction_stats_t* rstats; + int index; - // Count of event type. - if (summary_stats[trace[i].event_type] == NULL) { - summary_stats[trace[i].event_type] = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); - } - summary_stats[trace[i].event_type]->event_type = trace[i].event_type; - summary_stats[trace[i].event_type]->description = trace_event_names[trace[i].event_type]; - summary_stats[trace[i].event_type]->occurrences++; - - switch(trace[i].event_type) { - case reaction_starts: - case reaction_ends: - // This code relies on the mutual exclusion of reactions in a reactor - // and the ordering of reaction_starts and reaction_ends events. - if (trace[i].dst_id >= MAX_NUM_REACTIONS) { - fprintf(stderr, "WARNING: Too many reactions. Not all will be shown in summary file.\n"); - continue; - } - stats = summary_stats[NUM_EVENT_TYPES + object_instance]; - stats->description = reactor_name; - if (trace[i].dst_id >= stats->num_reactions_seen) { - stats->num_reactions_seen = trace[i].dst_id + 1; - } - rstats = &stats->reactions[trace[i].dst_id]; - if (trace[i].event_type == reaction_starts) { - rstats->latest_start_time = trace[i].physical_time; - } else { - rstats->occurrences++; - exec_time = trace[i].physical_time - rstats->latest_start_time; - rstats->latest_start_time = 0LL; - rstats->total_exec_time += exec_time; - if (exec_time > rstats->max_exec_time) { - rstats->max_exec_time = exec_time; + // Count of event type. + if (summary_stats[trace[i].event_type] == NULL) { + summary_stats[trace[i].event_type] = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); + } + summary_stats[trace[i].event_type]->event_type = trace[i].event_type; + summary_stats[trace[i].event_type]->description = trace_event_names[trace[i].event_type]; + summary_stats[trace[i].event_type]->occurrences++; + + switch(trace[i].event_type) { + case reaction_starts: + case reaction_ends: + // This code relies on the mutual exclusion of reactions in a reactor + // and the ordering of reaction_starts and reaction_ends events. + if (trace[i].dst_id >= MAX_NUM_REACTIONS) { + fprintf(stderr, "WARNING: Too many reactions. Not all will be shown in summary file.\n"); + continue; } - if (exec_time < rstats->min_exec_time || rstats->min_exec_time == 0LL) { - rstats->min_exec_time = exec_time; + stats = summary_stats[NUM_EVENT_TYPES + object_instance]; + stats->description = reactor_name; + if (trace[i].dst_id >= stats->num_reactions_seen) { + stats->num_reactions_seen = trace[i].dst_id + 1; } - } - break; - case schedule_called: - if (trigger_instance < 0) { - // No trigger. Do not report. - continue; - } - stats = summary_stats[NUM_EVENT_TYPES + trigger_instance]; - stats->description = trigger_name; - break; - case user_event: - // Although these are not exec times and not reactions, - // commandeer the first entry in the reactions array to track values. - stats = summary_stats[NUM_EVENT_TYPES + object_instance]; - stats->description = reactor_name; - break; - case user_value: - // Although these are not exec times and not reactions, - // commandeer the first entry in the reactions array to track values. - stats = summary_stats[NUM_EVENT_TYPES + object_instance]; - stats->description = reactor_name; - rstats = &stats->reactions[0]; - rstats->occurrences++; - // User values are stored in the "extra_delay" field, which is an interval_t. - interval_t value = trace[i].extra_delay; - rstats->total_exec_time += value; - if (value > rstats->max_exec_time) { - rstats->max_exec_time = value; - } - if (value < rstats->min_exec_time || rstats->min_exec_time == 0LL) { - rstats->min_exec_time = value; - } - break; - case worker_wait_starts: - case worker_wait_ends: - case scheduler_advancing_time_starts: - case scheduler_advancing_time_ends: - // Use the reactions array to store data. - // There will be two entries per worker, one for waits on the - // reaction queue and one for waits while advancing time. - index = trace[i].src_id * 2; - // Even numbered indices are used for waits on reaction queue. - // Odd numbered indices for waits for time advancement. - if (trace[i].event_type == scheduler_advancing_time_starts - || trace[i].event_type == scheduler_advancing_time_ends) { - index++; - } - if (object_table_size + index >= table_size) { - fprintf(stderr, "WARNING: Too many workers. Not all will be shown in summary file.\n"); - continue; - } - stats = summary_stats[NUM_EVENT_TYPES + object_table_size + index]; - if (stats == NULL) { - stats = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); - summary_stats[NUM_EVENT_TYPES + object_table_size + index] = stats; - } - // num_reactions_seen here will be used to store the number of - // entries in the reactions array, which is twice the number of workers. - if (index >= stats->num_reactions_seen) { - stats->num_reactions_seen = index; - } - rstats = &stats->reactions[index]; - if (trace[i].event_type == worker_wait_starts - || trace[i].event_type == scheduler_advancing_time_starts - ) { - rstats->latest_start_time = trace[i].physical_time; - } else { + rstats = &stats->reactions[trace[i].dst_id]; + if (trace[i].event_type == reaction_starts) { + rstats->latest_start_time = trace[i].physical_time; + } else { + rstats->occurrences++; + exec_time = trace[i].physical_time - rstats->latest_start_time; + rstats->latest_start_time = 0LL; + rstats->total_exec_time += exec_time; + if (exec_time > rstats->max_exec_time) { + rstats->max_exec_time = exec_time; + } + if (exec_time < rstats->min_exec_time || rstats->min_exec_time == 0LL) { + rstats->min_exec_time = exec_time; + } + } + break; + case schedule_called: + if (trigger_instance < 0) { + // No trigger. Do not report. + continue; + } + stats = summary_stats[NUM_EVENT_TYPES + trigger_instance]; + stats->description = trigger_name; + break; + case user_event: + // Although these are not exec times and not reactions, + // commandeer the first entry in the reactions array to track values. + stats = summary_stats[NUM_EVENT_TYPES + object_instance]; + stats->description = reactor_name; + break; + case user_value: + // Although these are not exec times and not reactions, + // commandeer the first entry in the reactions array to track values. + stats = summary_stats[NUM_EVENT_TYPES + object_instance]; + stats->description = reactor_name; + rstats = &stats->reactions[0]; rstats->occurrences++; - exec_time = trace[i].physical_time - rstats->latest_start_time; - rstats->latest_start_time = 0LL; - rstats->total_exec_time += exec_time; - if (exec_time > rstats->max_exec_time) { - rstats->max_exec_time = exec_time; + // User values are stored in the "extra_delay" field, which is an interval_t. + interval_t value = trace[i].extra_delay; + rstats->total_exec_time += value; + if (value > rstats->max_exec_time) { + rstats->max_exec_time = value; } - if (exec_time < rstats->min_exec_time || rstats->min_exec_time == 0LL) { - rstats->min_exec_time = exec_time; + if (value < rstats->min_exec_time || rstats->min_exec_time == 0LL) { + rstats->min_exec_time = value; } - } - break; - default: - // No special summary statistics for the rest. - break; - } - // Common stats across event types. - if (stats != NULL) { - stats->occurrences++; - stats->event_type = trace[i].event_type; + break; + case worker_wait_starts: + case worker_wait_ends: + case scheduler_advancing_time_starts: + case scheduler_advancing_time_ends: + // Use the reactions array to store data. + // There will be two entries per worker, one for waits on the + // reaction queue and one for waits while advancing time. + index = trace[i].src_id * 2; + // Even numbered indices are used for waits on reaction queue. + // Odd numbered indices for waits for time advancement. + if (trace[i].event_type == scheduler_advancing_time_starts + || trace[i].event_type == scheduler_advancing_time_ends) { + index++; + } + if (object_table_size + index >= table_size) { + fprintf(stderr, "WARNING: Too many workers. Not all will be shown in summary file.\n"); + continue; + } + stats = summary_stats[NUM_EVENT_TYPES + object_table_size + index]; + if (stats == NULL) { + stats = (summary_stats_t*)calloc(1, sizeof(summary_stats_t)); + summary_stats[NUM_EVENT_TYPES + object_table_size + index] = stats; + } + // num_reactions_seen here will be used to store the number of + // entries in the reactions array, which is twice the number of workers. + if (index >= stats->num_reactions_seen) { + stats->num_reactions_seen = index; + } + rstats = &stats->reactions[index]; + if (trace[i].event_type == worker_wait_starts + || trace[i].event_type == scheduler_advancing_time_starts + ) { + rstats->latest_start_time = trace[i].physical_time; + } else { + rstats->occurrences++; + exec_time = trace[i].physical_time - rstats->latest_start_time; + rstats->latest_start_time = 0LL; + rstats->total_exec_time += exec_time; + if (exec_time > rstats->max_exec_time) { + rstats->max_exec_time = exec_time; + } + if (exec_time < rstats->min_exec_time || rstats->min_exec_time == 0LL) { + rstats->min_exec_time = exec_time; + } + } + break; + default: + // No special summary statistics for the rest. + break; + } + // Common stats across event types. + if (stats != NULL) { + stats->occurrences++; + stats->event_type = trace[i].event_type; + } + } else { + // Out of scope. } } return trace_length; @@ -394,17 +399,33 @@ void write_summary_file() { } } -int main(int argc, char* argv[]) { - if (argc != 2) { - usage(); - exit(0); +int process_args(int argc, const char* argv[], char** root, instant_t* start_time, instant_t* end_time) { + for (int i = 1; i < argc; i++) { + if (strcmp(strrchr(argv[i], '\0') - 4, ".lft") == 0) { + // Open the trace file. + trace_file = open_file(argv[i], "r"); + if (trace_file == NULL) exit(1); + *root = root_name(argv[i]); + } else if (strcmp(argv[i], "-s") == 0) { + sscanf(argv[++i], "%ld", start_time); + } else if (strcmp(argv[i], "-e") == 0) { + sscanf(argv[++i], "%ld", end_time); + } else { + usage(); + exit(0); + } } - // Open the trace file. - trace_file = open_file(argv[1], "r"); - if (trace_file == NULL) exit(1); + return 0; +} + +int main(int argc, const char* argv[]) { + instant_t trace_start_time = NEVER; + instant_t trace_end_time = FOREVER; + char* root; + + process_args(argc, argv, &root, &trace_start_time, &trace_end_time); // Construct the name of the csv output file and open it. - char* root = root_name(argv[1]); char csv_filename[strlen(root) + 5]; strcpy(csv_filename, root); strcat(csv_filename, ".csv"); @@ -427,10 +448,10 @@ int main(int argc, char* argv[]) { // Write a header line into the CSV file. fprintf(output_file, "Event, Reactor, Source, Destination, Elapsed Logical Time, Microstep, Elapsed Physical Time, Trigger, Extra Delay\n"); - while (read_and_write_trace() != 0) {}; + while (read_and_write_trace(trace_start_time, trace_end_time) != 0) {}; write_summary_file(); // File closing is handled by termination function. } -} +} \ No newline at end of file diff --git a/util/tracing/visualization/fedsd.py b/util/tracing/visualization/fedsd.py index d9d44253b..b03f6e0ca 100644 --- a/util/tracing/visualization/fedsd.py +++ b/util/tracing/visualization/fedsd.py @@ -100,6 +100,10 @@ help='RTI\'s lft trace file.') parser.add_argument('-f','--federates', nargs='+', help='List of the federates\' lft trace files.') +parser.add_argument('-s', '--start', type=str, + help='Elapsed logical time (nsec) to start visualization') +parser.add_argument('-e', '--end', type=str, + help='Elapsed logical time (nsec) to end visualization') # Events matching at the sender and receiver ends depend on whether they are tagged # (the elapsed logical time and microstep have to be the same) or not. @@ -372,7 +376,7 @@ def command_is_in_path(command): return True return False -def convert_lft_file_to_csv(lft_file): +def convert_lft_file_to_csv(lft_file, start_time, end_time): ''' Call trace_to_csv command to convert the given binary lft trace file to csv format. @@ -382,7 +386,14 @@ def convert_lft_file_to_csv(lft_file): * File: the converted csv file, if the conversion succeeds, and empty string otherwise. * String: the error message, in case the conversion did not succeed, and empty string otherwise. ''' - convert_process = subprocess.run(['trace_to_csv', lft_file], stdout=subprocess.DEVNULL) + + subprocess_args = ['trace_to_csv', lft_file] + if (start_time != None): + subprocess_args.extend(['-s', start_time]) + if (end_time != None): + subprocess_args.extend(['-e', end_time]) + + convert_process = subprocess.run(subprocess_args, stdout=subprocess.DEVNULL) if (convert_process.returncode == 0): csv_file = os.path.splitext(lft_file)[0] + '.csv' @@ -390,7 +401,7 @@ def convert_lft_file_to_csv(lft_file): else: return '', str(convert_process.stderr) -def get_and_convert_lft_files(rti_lft_file, federates_lft_files): +def get_and_convert_lft_files(rti_lft_file, federates_lft_files, start_time, end_time): ''' Check if the passed arguments are valid, in the sense that the files do exist. If not arguments were passed, then look up the local lft files. @@ -428,7 +439,7 @@ def get_and_convert_lft_files(rti_lft_file, federates_lft_files): # Now, convert lft files to csv if (rti_lft_file): - rti_csv_file, error = convert_lft_file_to_csv(rti_lft_file) + rti_csv_file, error = convert_lft_file_to_csv(rti_lft_file, start_time, end_time) if (not rti_csv_file): print('Fedsf: Error converting the RTI\'s lft file: ' + error) else: @@ -436,7 +447,7 @@ def get_and_convert_lft_files(rti_lft_file, federates_lft_files): federates_csv_files = [] for file in federates_lft_files: - fed_csv_file, error = convert_lft_file_to_csv(file) + fed_csv_file, error = convert_lft_file_to_csv(file, start_time, end_time) if (not fed_csv_file): print('Fedsf: Error converting the federate lft file ' + file + ': ' + error) else: @@ -459,7 +470,7 @@ def get_and_convert_lft_files(rti_lft_file, federates_lft_files): # Look up the lft files and transform them to csv files - rti_csv_file, federates_csv_files = get_and_convert_lft_files(args.rti, args.federates) + rti_csv_file, federates_csv_files = get_and_convert_lft_files(args.rti, args.federates, args.start, args.end) # The RTI and each of the federates have a fixed x coordinate. They will be # saved in a dict @@ -696,4 +707,4 @@ def get_and_convert_lft_files(rti_lft_file, federates_lft_files): # Write to a csv file, just to double check trace_df.to_csv('all.csv', index=True) - print('Fedsd: Successfully generated the sequence diagram in trace_svg.html.') + print('Fedsd: Successfully generated the sequence diagram in trace_svg.html.') \ No newline at end of file From 4463fb0b0cdf5e9a65e3c9a95476266a5bb9c00d Mon Sep 17 00:00:00 2001 From: Byeonggil Jun <78055940+byeong-gil@users.noreply.github.com> Date: Tue, 19 Dec 2023 15:14:01 +0900 Subject: [PATCH 2/8] Update README.md --- util/tracing/visualization/README.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/util/tracing/visualization/README.md b/util/tracing/visualization/README.md index c3ca6ad1a..4b8de0ed8 100644 --- a/util/tracing/visualization/README.md +++ b/util/tracing/visualization/README.md @@ -38,4 +38,10 @@ It is also possible to operate on specific files. In such a case, run `fedsd` wi fedsd -r -f ``` +If the trace is too long, the target time interval can be specified. Running `fedsd` with `-s ` will show the messages with the tag later than or equal to the start time and with `-e ` will show the messages with the tag strictly earlier than the end_time. Here, the time unit of `start_time` and `end_time` is `nsec`. + +```bash +fedsd -s -e +``` + The output is an html file named `trace_svg.html` (in the current directory) that contains the sequence of interactions between the federates and the RTI. From b3cc60a00d3b643bc407e0db8a05404917006355 Mon Sep 17 00:00:00 2001 From: Byeonggil Jun Date: Wed, 10 Jan 2024 16:26:10 -0700 Subject: [PATCH 3/8] Align the usage message with the real usage --- util/tracing/trace_to_csv.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/util/tracing/trace_to_csv.c b/util/tracing/trace_to_csv.c index 1060f07b4..2ed4e45bd 100644 --- a/util/tracing/trace_to_csv.c +++ b/util/tracing/trace_to_csv.c @@ -55,7 +55,7 @@ int table_size; * Print a usage message. */ void usage() { - printf("\nUsage: trace_to_csv [options] trace_file_root (without .lft extension)\n\n"); + printf("\nUsage: trace_to_csv [options] trace_file_root (with .lft extension)\n\n"); /* No options yet: printf("\nOptions: \n\n"); printf(" -f, --fast [true | false]\n"); From 22431ba453d0aee85001ee53cb213a3f6fb25636 Mon Sep 17 00:00:00 2001 From: Byeonggil Jun Date: Wed, 10 Jan 2024 17:18:35 -0700 Subject: [PATCH 4/8] Take time value and unit to specify the start and end time for tracing --- util/tracing/trace_to_csv.c | 92 +++++++++++++++++++++++++++++++------ 1 file changed, 79 insertions(+), 13 deletions(-) diff --git a/util/tracing/trace_to_csv.c b/util/tracing/trace_to_csv.c index 2ed4e45bd..6fdddc0bc 100644 --- a/util/tracing/trace_to_csv.c +++ b/util/tracing/trace_to_csv.c @@ -56,12 +56,14 @@ int table_size; */ void usage() { printf("\nUsage: trace_to_csv [options] trace_file_root (with .lft extension)\n\n"); - /* No options yet: printf("\nOptions: \n\n"); - printf(" -f, --fast [true | false]\n"); - printf(" Whether to wait for physical time to match logical time.\n\n"); + printf(" -s, --start [time_spec] [units]\n"); + printf(" The target time to begin tracing.\n\n"); + printf(" -e, --end [time_spec] [units]\n"); + printf(" The target time to stop tracing.\n\n"); + // printf(" -f, --fast [true | false]\n"); + // printf(" Whether to wait for physical time to match logical time.\n\n"); printf("\n\n"); - */ } /** @@ -399,17 +401,79 @@ void write_summary_file() { } } +instant_t string_to_instant(const char* time_spec, const char* units) { + instant_t duration; + #if defined(PLATFORM_ARDUINO) + duration = atol(time_spec); + #else + duration = atoll(time_spec); + #endif + // A parse error returns 0LL, so check to see whether that is what is meant. + if (duration == 0LL && strncmp(time_spec, "0", 1) != 0) { + // Parse error. + printf("Invalid time value: %s", time_spec); + return -1; + } + if (strncmp(units, "sec", 3) == 0) { + duration = SEC(duration); + } else if (strncmp(units, "msec", 4) == 0) { + duration = MSEC(duration); + } else if (strncmp(units, "usec", 4) == 0) { + duration = USEC(duration); + } else if (strncmp(units, "nsec", 4) == 0) { + duration = NSEC(duration); + } else if (strncmp(units, "min", 3) == 0) { + duration = MINUTE(duration); + } else if (strncmp(units, "hour", 4) == 0) { + duration = HOUR(duration); + } else if (strncmp(units, "day", 3) == 0) { + duration = DAY(duration); + } else if (strncmp(units, "week", 4) == 0) { + duration = WEEK(duration); + } else { + // Invalid units. + printf("Invalid time units: %s", units); + return -1; + } + return duration; +} + int process_args(int argc, const char* argv[], char** root, instant_t* start_time, instant_t* end_time) { - for (int i = 1; i < argc; i++) { - if (strcmp(strrchr(argv[i], '\0') - 4, ".lft") == 0) { + int i = 1; + while (i < argc){ + const char* arg = argv[i++]; + if (strcmp(strrchr(arg, '\0') - 4, ".lft") == 0) { // Open the trace file. - trace_file = open_file(argv[i], "r"); + trace_file = open_file(arg, "r"); if (trace_file == NULL) exit(1); - *root = root_name(argv[i]); - } else if (strcmp(argv[i], "-s") == 0) { - sscanf(argv[++i], "%ld", start_time); - } else if (strcmp(argv[i], "-e") == 0) { - sscanf(argv[++i], "%ld", end_time); + *root = root_name(arg); + } else if (strcmp(arg, "-s") == 0) { + // sscanf(argv[++i], "%ld", start_time); + if (argc < i + 2) { + printf("-s needs time and units."); + usage(argc, argv); + return -1; + } + const char* time_spec = argv[i++]; + const char* units = argv[i++]; + *start_time = string_to_instant(time_spec, units); + if (*start_time == -1) { + usage(argc, argv); + return -1; + } + } else if (strcmp(arg, "-e") == 0) { + if (argc < i + 2) { + printf("-e needs time and units."); + usage(argc, argv); + return -1; + } + const char* time_spec = argv[i++]; + const char* units = argv[i++]; + *end_time = string_to_instant(time_spec, units); + if (*end_time == -1) { + usage(argc, argv); + return -1; + } } else { usage(); exit(0); @@ -423,7 +487,9 @@ int main(int argc, const char* argv[]) { instant_t trace_end_time = FOREVER; char* root; - process_args(argc, argv, &root, &trace_start_time, &trace_end_time); + if (process_args(argc, argv, &root, &trace_start_time, &trace_end_time) != 0) { + return -1; + } // Construct the name of the csv output file and open it. char csv_filename[strlen(root) + 5]; From 37fe174cbba1fc3b11977735f1ef9631e750002c Mon Sep 17 00:00:00 2001 From: Byeonggil Jun Date: Thu, 11 Jan 2024 14:34:05 -0700 Subject: [PATCH 5/8] Make the python script to receive and process start and time properly --- util/tracing/trace_to_csv.c | 12 ++++++------ util/tracing/visualization/README.md | 2 +- util/tracing/visualization/fedsd.py | 12 ++++++------ 3 files changed, 13 insertions(+), 13 deletions(-) diff --git a/util/tracing/trace_to_csv.c b/util/tracing/trace_to_csv.c index 6fdddc0bc..2dee57935 100644 --- a/util/tracing/trace_to_csv.c +++ b/util/tracing/trace_to_csv.c @@ -450,28 +450,28 @@ int process_args(int argc, const char* argv[], char** root, instant_t* start_tim } else if (strcmp(arg, "-s") == 0) { // sscanf(argv[++i], "%ld", start_time); if (argc < i + 2) { - printf("-s needs time and units."); - usage(argc, argv); + printf("-s needs time value and unit."); + usage(); return -1; } const char* time_spec = argv[i++]; const char* units = argv[i++]; *start_time = string_to_instant(time_spec, units); if (*start_time == -1) { - usage(argc, argv); + usage(); return -1; } } else if (strcmp(arg, "-e") == 0) { if (argc < i + 2) { - printf("-e needs time and units."); - usage(argc, argv); + printf("-e needs time value and unit."); + usage(); return -1; } const char* time_spec = argv[i++]; const char* units = argv[i++]; *end_time = string_to_instant(time_spec, units); if (*end_time == -1) { - usage(argc, argv); + usage(); return -1; } } else { diff --git a/util/tracing/visualization/README.md b/util/tracing/visualization/README.md index 4b8de0ed8..cee3eb5a4 100644 --- a/util/tracing/visualization/README.md +++ b/util/tracing/visualization/README.md @@ -41,7 +41,7 @@ fedsd -r -f If the trace is too long, the target time interval can be specified. Running `fedsd` with `-s ` will show the messages with the tag later than or equal to the start time and with `-e ` will show the messages with the tag strictly earlier than the end_time. Here, the time unit of `start_time` and `end_time` is `nsec`. ```bash -fedsd -s -e +fedsd -s -e ``` The output is an html file named `trace_svg.html` (in the current directory) that contains the sequence of interactions between the federates and the RTI. diff --git a/util/tracing/visualization/fedsd.py b/util/tracing/visualization/fedsd.py index b03f6e0ca..34eeb1ad3 100644 --- a/util/tracing/visualization/fedsd.py +++ b/util/tracing/visualization/fedsd.py @@ -100,10 +100,10 @@ help='RTI\'s lft trace file.') parser.add_argument('-f','--federates', nargs='+', help='List of the federates\' lft trace files.') -parser.add_argument('-s', '--start', type=str, - help='Elapsed logical time (nsec) to start visualization') -parser.add_argument('-e', '--end', type=str, - help='Elapsed logical time (nsec) to end visualization') +parser.add_argument('-s', '--start', type=str, nargs=2, + help='Elapsed logical time that targets to start visualization. [time_value time_unit]') +parser.add_argument('-e', '--end', type=str, nargs=2, + help='Elapsed logical time that targets to end visualization. [time_value time_unit]') # Events matching at the sender and receiver ends depend on whether they are tagged # (the elapsed logical time and microstep have to be the same) or not. @@ -389,9 +389,9 @@ def convert_lft_file_to_csv(lft_file, start_time, end_time): subprocess_args = ['trace_to_csv', lft_file] if (start_time != None): - subprocess_args.extend(['-s', start_time]) + subprocess_args.extend(['-s', start_time[0], start_time[1]]) if (end_time != None): - subprocess_args.extend(['-e', end_time]) + subprocess_args.extend(['-e', end_time[0], end_time[1]]) convert_process = subprocess.run(subprocess_args, stdout=subprocess.DEVNULL) From bcb31937be04238acecb5cc48d91ea29216a6331 Mon Sep 17 00:00:00 2001 From: Byeonggil Jun Date: Thu, 11 Jan 2024 14:36:06 -0700 Subject: [PATCH 6/8] Update README.md --- util/tracing/visualization/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/util/tracing/visualization/README.md b/util/tracing/visualization/README.md index cee3eb5a4..61eee36ad 100644 --- a/util/tracing/visualization/README.md +++ b/util/tracing/visualization/README.md @@ -38,7 +38,7 @@ It is also possible to operate on specific files. In such a case, run `fedsd` wi fedsd -r -f ``` -If the trace is too long, the target time interval can be specified. Running `fedsd` with `-s ` will show the messages with the tag later than or equal to the start time and with `-e ` will show the messages with the tag strictly earlier than the end_time. Here, the time unit of `start_time` and `end_time` is `nsec`. +If the trace is too long, the target time interval can be specified. Running `fedsd` with `-s ` will show the messages with the tag later than or equal to the start time and with `-e ` will show the messages with the tag strictly earlier than the end_time. ```bash fedsd -s -e From 14ecd1c2e76936257403806efe3e378f347d189a Mon Sep 17 00:00:00 2001 From: Byeonggil Jun Date: Thu, 11 Jan 2024 15:31:44 -0700 Subject: [PATCH 7/8] Minor updates suggested by @hokeun --- util/tracing/trace_to_csv.c | 2 +- util/tracing/visualization/fedsd.py | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/util/tracing/trace_to_csv.c b/util/tracing/trace_to_csv.c index 2dee57935..7719864de 100644 --- a/util/tracing/trace_to_csv.c +++ b/util/tracing/trace_to_csv.c @@ -119,7 +119,7 @@ size_t read_and_write_trace(instant_t trace_start_time, instant_t trace_end_time trigger_name = "NO TRIGGER"; } if ((trace[i].logical_time - start_time) >= trace_start_time - && (trace[i].logical_time - start_time) < trace_end_time) { + && (trace[i].logical_time - start_time) < trace_end_time) { fprintf(output_file, "%s, %s, %d, %d, %lld, %d, %lld, %s, %lld\n", trace_event_names[trace[i].event_type], reactor_name, diff --git a/util/tracing/visualization/fedsd.py b/util/tracing/visualization/fedsd.py index 34eeb1ad3..ed4691bc2 100644 --- a/util/tracing/visualization/fedsd.py +++ b/util/tracing/visualization/fedsd.py @@ -101,9 +101,9 @@ parser.add_argument('-f','--federates', nargs='+', help='List of the federates\' lft trace files.') parser.add_argument('-s', '--start', type=str, nargs=2, - help='Elapsed logical time that targets to start visualization. [time_value time_unit]') + help='Start time of visualization in elapsed logical time. [time_value time_unit]') parser.add_argument('-e', '--end', type=str, nargs=2, - help='Elapsed logical time that targets to end visualization. [time_value time_unit]') + help='End time of visualization in elapsed logical time. [time_value time_unit]') # Events matching at the sender and receiver ends depend on whether they are tagged # (the elapsed logical time and microstep have to be the same) or not. From 6ce0e103dd6ce77ec3e7e3645525c68cd70f5a36 Mon Sep 17 00:00:00 2001 From: Byeonggil Jun Date: Thu, 11 Jan 2024 15:40:42 -0700 Subject: [PATCH 8/8] Remove an unnecessary comment --- util/tracing/trace_to_csv.c | 2 -- 1 file changed, 2 deletions(-) diff --git a/util/tracing/trace_to_csv.c b/util/tracing/trace_to_csv.c index 7719864de..d1002269b 100644 --- a/util/tracing/trace_to_csv.c +++ b/util/tracing/trace_to_csv.c @@ -61,8 +61,6 @@ void usage() { printf(" The target time to begin tracing.\n\n"); printf(" -e, --end [time_spec] [units]\n"); printf(" The target time to stop tracing.\n\n"); - // printf(" -f, --fast [true | false]\n"); - // printf(" Whether to wait for physical time to match logical time.\n\n"); printf("\n\n"); }