diff --git a/include/recorder-utils.h b/include/recorder-utils.h index 19fbf03..1ccc10e 100644 --- a/include/recorder-utils.h +++ b/include/recorder-utils.h @@ -2,11 +2,13 @@ #define _RECORDER_UTILS_H_ #include +#include void utils_init(); void utils_finalize(); void* recorder_malloc(size_t size); void recorder_free(void* ptr, size_t size); +pthread_t recorder_gettid(void); long get_file_size(const char *filename); // return the size of a file int accept_filename(const char *filename); // if include the file in trace double recorder_wtime(void); // return the timestamp diff --git a/include/recorder.h b/include/recorder.h index 4d7f871..4062ebf 100644 --- a/include/recorder.h +++ b/include/recorder.h @@ -163,7 +163,7 @@ \ Record *record = recorder_malloc(sizeof(Record)); \ record->func_id = get_function_id_by_name(#func); \ - record->tid = pthread_self(); \ + record->tid = recorder_gettid(); \ logger_record_enter(record); \ record->tstart = recorder_wtime(); \ ret res = RECORDER_REAL_CALL(func) real_args ; \ diff --git a/lib/recorder-cuda-profiler.c b/lib/recorder-cuda-profiler.c index 8de84b1..03a17f0 100644 --- a/lib/recorder-cuda-profiler.c +++ b/lib/recorder-cuda-profiler.c @@ -134,7 +134,7 @@ Record* create_recorder_record(CUpti_ActivityKernel5 *kernel) { Record *record = recorder_malloc(sizeof(Record)); record->func_id = RECORDER_USER_FUNCTION; record->level = 0; - record->tid = pthread_self(); + record->tid = recorder_gettid(); record->tstart = (kernel->start - startTimestamp)/10e9; record->tstart = (kernel->end - startTimestamp)/10e9; record->arg_count = 2; diff --git a/lib/recorder-function-profiler.c b/lib/recorder-function-profiler.c index 02712ad..6bb18dc 100644 --- a/lib/recorder-function-profiler.c +++ b/lib/recorder-function-profiler.c @@ -25,7 +25,7 @@ func_hash_t* func_table; void* compose_func_hash_key(void* func, int *key_len) { - pthread_t tid = pthread_self(); + pthread_t tid = recorder_gettid(); *key_len = sizeof(pthread_t) + sizeof(void*); void* key = recorder_malloc(*key_len); memcpy(key, &tid, sizeof(pthread_t)); @@ -89,7 +89,7 @@ void __cyg_profile_func_exit (void *func, void *caller) Record *record = recorder_malloc(sizeof(Record)); record->func_id = RECORDER_USER_FUNCTION; record->level = 0; - record->tid = pthread_self(); + record->tid = recorder_gettid(); record->tstart = entry->tstart_head->tstart; record->tend = recorder_wtime(); record->arg_count = 2; diff --git a/lib/recorder-utils.c b/lib/recorder-utils.c index 9f4a060..d5f2bc0 100644 --- a/lib/recorder-utils.c +++ b/lib/recorder-utils.c @@ -1,13 +1,14 @@ #define _GNU_SOURCE +#include #include // for gettimeofday() #include // for va_list, va_start and va_end +#include // for SYS_gettid #include #include #include #include "recorder.h" #include "recorder-utils.h" - // Log pointer addresses in the trace file? static bool log_pointer = false; static size_t memory_usage = 0; @@ -169,6 +170,15 @@ inline int accept_filename(const char *filename) { return 1; } +inline pthread_t recorder_gettid(void) +{ +#ifdef SYS_gettid + return syscall(SYS_gettid); +#else + return pthread_self(); +#endif +} + inline long get_file_size(const char *filename) { struct stat sb; int res = stat(filename, &sb); // careful here, make sure stat() is not intercepted diff --git a/tools/reader.c b/tools/reader.c index 17e1e11..fb4714b 100644 --- a/tools/reader.c +++ b/tools/reader.c @@ -5,26 +5,36 @@ #include #include "./reader.h" -static int mpi_start_idx = -1; -static int hdf5_start_idx = -1; +void check_version(RecorderReader* reader) { + char version_file[1024]; + snprintf(version_file, sizeof(version_file), "%s/VERSION", reader->logs_dir); -static double prev_tstart = 0; - -void read_metadata(char* path, RecorderMetadata *metadata) { - FILE* fp = fopen(path, "rb"); + FILE* fp = fopen(version_file, "r"); assert(fp != NULL); - fread(metadata, sizeof(RecorderMetadata), 1, fp); + int major, minor, patch; + fscanf(fp, "%d.%d.%d", &major, &minor, &patch); + if(major != VERSION_MAJOR || minor != VERSION_MINOR) { + fprintf(stderr, "incompatible version: file=%d.%d.%d != reader=%d.%d.%d\n", + major, minor, patch, VERSION_MAJOR, VERSION_MINOR, VERSION_PATCH); + exit(1); + } fclose(fp); } -void read_func_list(char* path, RecorderReader *reader) { - FILE* fp = fopen(path, "rb"); +void read_metadata(RecorderReader* reader) { + char metadata_file[1024]; + snprintf(metadata_file, sizeof(metadata_file), "%s/recorder.mt", reader->logs_dir); + + FILE* fp = fopen(metadata_file, "rb"); + assert(fp != NULL); + fread(&reader->metadata, sizeof(reader->metadata), 1, fp); + long pos = ftell(fp); fseek(fp, 0, SEEK_END); - long fsize = ftell(fp) - sizeof(RecorderMetadata); + long fsize = ftell(fp) - pos; char buf[fsize]; - fseek(fp, sizeof(RecorderMetadata), SEEK_SET); // skip RecorderMetadata object + fseek(fp, pos, SEEK_SET); fread(buf, 1, fsize, fp); int start_pos = 0, end_pos = 0; @@ -35,14 +45,14 @@ void read_func_list(char* path, RecorderReader *reader) { memset(reader->func_list[func_id], 0, sizeof(reader->func_list[func_id])); memcpy(reader->func_list[func_id], buf+start_pos, end_pos-start_pos); start_pos = end_pos+1; - if((mpi_start_idx==-1) && + if((reader->mpi_start_idx==-1) && (NULL!=strstr(reader->func_list[func_id], "MPI"))) - mpi_start_idx = func_id; + reader->mpi_start_idx = func_id; - if((hdf5_start_idx==-1) && + if((reader->hdf5_start_idx==-1) && (NULL!=strstr(reader->func_list[func_id], "H5"))) - hdf5_start_idx = func_id; + reader->hdf5_start_idx = func_id; func_id++; } @@ -52,15 +62,23 @@ void read_func_list(char* path, RecorderReader *reader) { } void recorder_init_reader(const char* logs_dir, RecorderReader *reader) { - char metadata_file[1024]; + assert(logs_dir); + assert(reader); + + memset(reader, 0, sizeof(*reader)); strcpy(reader->logs_dir, logs_dir); + reader->mpi_start_idx = -1; + reader->hdf5_start_idx = -1; + reader->prev_tstart = 0.0; + + check_version(reader); - sprintf(metadata_file, "%s/recorder.mt", logs_dir); - read_metadata(metadata_file, &reader->metadata); - read_func_list(metadata_file, reader); + read_metadata(reader); } void recorder_free_reader(RecorderReader *reader) { + assert(reader); + memset(reader, 0, sizeof(*reader)); } const char* recorder_get_func_name(RecorderReader* reader, Record* record) { @@ -70,9 +88,9 @@ const char* recorder_get_func_name(RecorderReader* reader, Record* record) { } int recorder_get_func_type(RecorderReader* reader, Record* record) { - if(record->func_id < mpi_start_idx) + if(record->func_id < reader->mpi_start_idx) return RECORDER_POSIX; - if(record->func_id < hdf5_start_idx) { + if(record->func_id < reader->hdf5_start_idx) { const char* func_name = recorder_get_func_name(reader, record); if(strncmp(func_name, "MPI_File", 8) == 0) return RECORDER_MPIIO; @@ -239,9 +257,9 @@ void rule_application(RecorderReader* reader, RuleHash* rules, int rule_id, Call // Fill in timestamps uint32_t ts[2]; fread(ts, sizeof(uint32_t), 2, ts_file); - record->tstart = ts[0] * reader->metadata.time_resolution + prev_tstart; - record->tend = ts[1] * reader->metadata.time_resolution + prev_tstart; - prev_tstart = record->tstart; + record->tstart = ts[0] * reader->metadata.time_resolution + reader->prev_tstart; + record->tend = ts[1] * reader->metadata.time_resolution + reader->prev_tstart; + reader->prev_tstart = record->tstart; user_op(record, user_arg); @@ -263,7 +281,7 @@ void recorder_decode_records_core(RecorderReader *reader, CST *cst, CFG *cfg, assert(cst->rank == cfg->rank); - prev_tstart = 0; + reader->prev_tstart = 0.0; char ts_filename[1096] = {0}; sprintf(ts_filename, "%s/%d.ts", reader->logs_dir, cst->rank); diff --git a/tools/reader.h b/tools/reader.h index 6144d46..0f398ed 100644 --- a/tools/reader.h +++ b/tools/reader.h @@ -3,6 +3,11 @@ #include #include "recorder-logger.h" +// keep in sync with VERSION_STR in lib/recorder-logger.c +// equal (major, minor) is needed for compatibility +#define VERSION_MAJOR 2 +#define VERSION_MINOR 3 +#define VERSION_PATCH 3 #define POSIX_SEMANTICS 0 #define COMMIT_SEMANTICS 1 @@ -19,6 +24,11 @@ typedef struct RecorderReader_t { char func_list[256][64]; char logs_dir[1024]; + + int mpi_start_idx; + int hdf5_start_idx; + + double prev_tstart; } RecorderReader; typedef struct Interval_t { diff --git a/tools/recorder2timeline.cpp b/tools/recorder2timeline.cpp index 303b313..8677dc6 100644 --- a/tools/recorder2timeline.cpp +++ b/tools/recorder2timeline.cpp @@ -9,16 +9,51 @@ #include #include #include -static int do_mutex; -static pthread_mutex_t mut = PTHREAD_MUTEX_INITIALIZER; +#include +#include + RecorderReader reader; struct Writer{ std::ofstream outFile; - char* filename; + const char* sep; int rank, my_rank, total_ranks; }; +static const char* type_name(int type) { + switch (type) { + case RECORDER_POSIX: + return "POSIX"; + case RECORDER_MPIIO: + return "MPI I/O"; + case RECORDER_MPI: + return "MPI"; + case RECORDER_HDF5: + return "HDF5"; + case RECORDER_FTRACE: + return "USER"; + } +} + +struct timeline_ts{ + double value; +}; +std::ostream& +operator<<( std::ostream& out, + const timeline_ts& ts ) +{ + std::ios oldState(nullptr); + oldState.copyfmt(out); + + // Chrome traces are always in micro seconds and Recorder timestamps in + // seconds. No need to use the timer resolution from the trace to convert + // to microseconds. + out << std::fixed << std::setw(5) << std::setprecision(3) << (ts.value * 1e6); + out.copyfmt(oldState); + + return out; +} + void write_to_json(Record *record, void* arg) { int cat = recorder_get_func_type(&reader, record); @@ -29,77 +64,66 @@ void write_to_json(Record *record, void* arg) { if (user_func) func_name = record->args[0]; - uint64_t ts = uint64_t(record->tstart / reader.metadata.time_resolution); - int tid = record->tid; - uint64_t dur = uint64_t((record->tend - record->tstart) / reader.metadata.time_resolution); - if (dur <= 0) dur = 0; std::stringstream ss; - ss << "{\"pid\":" << writer->rank - << ",\"tid\":" << cat - << ",\"ts\":" << ts + ss << writer->sep + << "{\"pid\":" << writer->rank + << ",\"tid\":" << record->tid + << ",\"ts\":" << timeline_ts{record->tstart} << ",\"name\":\"" << func_name - << "\",\"cat\":\"" << cat; - ss << "\",\"ph\":\"X\""<< "" - << ",\"dur\":" << dur; - ss <<",\"args\":\""; - for (int arg_id = 0; !user_func && arg_id < record->arg_count; arg_id++) { - char *arg = record->args[arg_id]; - ss << " " << arg; + << "\",\"cat\":\"" << type_name(cat) + << "\",\"ph\":\"X\"" + << ",\"dur\":" << timeline_ts{record->tend - record->tstart} + << ",\"args\":{"; + if (!user_func) { + ss << "\"args\":["; + const char* sep = ""; + for (int arg_id = 0; arg_id < record->arg_count; arg_id++) { + char *arg = record->args[arg_id]; + ss << sep << "\"" << arg << "\""; + sep = ","; + } + ss << "],"; } - ss << " tend: "<< record->tend <<"\"},\n"; + ss << "\"tend\": \"" << record->tend << "\"}}"; writer->outFile << ss.rdbuf(); + writer->sep = ",\n"; } } int min(int a, int b) { return a < b ? a : b; } int max(int a, int b) { return a > b ? a : b; } -static void * execute(void * global_writer) { - Writer* writer = (Writer*)global_writer; - int n = max(reader.metadata.total_ranks/writer->total_ranks, 1); - int start_rank = n * writer->my_rank; - int end_rank = min(reader.metadata.total_ranks, n*(writer->my_rank+1)); - Writer local; - local.outFile.open(writer->filename,std::ofstream::out| std::ofstream::app); - for(int rank = start_rank; rank < end_rank; rank++) { - CST cst; - CFG cfg; - local.rank = rank; - recorder_read_cst(&reader, rank, &cst); - recorder_read_cfg(&reader, rank, &cfg); - recorder_decode_records(&reader, &cst, &cfg, write_to_json, &local); - printf("\r[Recorder] rank %d finished, unique call signatures: %d\n", rank, cst.entries); - recorder_free_cst(&cst); - recorder_free_cfg(&cfg); - } - local.outFile.close(); - return NULL; -} - int main(int argc, char **argv) { - char textfile_dir[256]; - char textfile_path[256]; - sprintf(textfile_dir, "%s/_chrome", argv[1]); - recorder_init_reader(argv[1], &reader); + if(argc!=2) { + std::cerr << "Usage: " << argv[0] << " \n"; + std::exit(1); + } + int mpi_size, mpi_rank; MPI_Init(&argc, &argv); MPI_Comm_size(MPI_COMM_WORLD, &mpi_size); MPI_Comm_rank(MPI_COMM_WORLD, &mpi_rank); + char textfile_dir[256]; + sprintf(textfile_dir, "%s/_chrome", argv[1]); + if(mpi_rank == 0) mkdir(textfile_dir, S_IRWXU | S_IRWXG | S_IROTH | S_IXOTH); MPI_Barrier(MPI_COMM_WORLD); + recorder_init_reader(argv[1], &reader); // Each rank will process n files (n ranks traces) int n = max(reader.metadata.total_ranks/mpi_size, 1); int start_rank = n * mpi_rank; int end_rank = min(reader.metadata.total_ranks, n*(mpi_rank+1)); + char textfile_path[256]; sprintf(textfile_path, "%s/timeline_%d.json", textfile_dir, mpi_rank); Writer local; local.outFile.open(textfile_path, std::ofstream::trunc|std::ofstream::out); - local.outFile << "{\"traceEvents\": ["; + local.outFile << "{\"traceEvents\": [\n"; + local.sep = ""; for(int rank = start_rank; rank < end_rank; rank++) { CST cst; CFG cfg; @@ -111,7 +135,7 @@ int main(int argc, char **argv) { recorder_free_cst(&cst); recorder_free_cfg(&cfg); } - local.outFile << "],\"displayTimeUnit\": \"ms\",\"systemTraceEvents\": \"SystemTraceData\",\"otherData\": {\"version\": \"Taxonomy v1.0\" }, \"stackFrames\": {}, \"samples\": []}"; + local.outFile << "],\n\"displayTimeUnit\": \"ms\",\"systemTraceEvents\": \"SystemTraceData\",\"otherData\": {\"version\": \"Taxonomy v1.0\" }, \"stackFrames\": {}, \"samples\": []}\n"; local.outFile.close(); recorder_free_reader(&reader);