diff --git a/CHANGES.md b/CHANGES.md index 17a916dd..0633faa4 100644 --- a/CHANGES.md +++ b/CHANGES.md @@ -106,10 +106,14 @@ This optimization significantly reduces resource requirements for large model in ## Communication and Compute Logging -Enable detailed timestamped logging of inter-node communication and computation phases for performance analysis and debugging distributed inference. +Enable detailed timestamped logging of inter-node communication and computation phases for performance analysis and debugging distributed inference. This feature can be controlled with a CLI flag to reduce overhead when not needed. - commits (eb0cac1, adad23d, a399e49) +### CLI Control + +- `--enable-comm-compute-log`: Enable communication and computation logging (disabled by default for performance) + ### Logging Categories **Communication Logs:** diff --git a/common/arg.cpp b/common/arg.cpp index 24db04d6..7bbdffb7 100644 --- a/common/arg.cpp +++ b/common/arg.cpp @@ -2066,6 +2066,13 @@ gpt_params_context gpt_params_parser_init(gpt_params & params, llama_example ex, params.dump_folder = value; } )); + add_opt(llama_arg( + {"--enable-comm-compute-log"}, + "enable communication and computation logging for gantt chart analysis", + [](gpt_params & params) { + params.enable_comm_compute_log = true; + } + )); add_opt(llama_arg( {"--positive-file"}, "FNAME", format("positive prompts file, one prompt per line (default: '%s')", params.cvector_positive_file.c_str()), diff --git a/common/common.cpp b/common/common.cpp index af535004..2e56274f 100644 --- a/common/common.cpp +++ b/common/common.cpp @@ -2021,6 +2021,8 @@ struct llama_context_params llama_context_params_from_gpt_params(const gpt_param cparams.dump_folder = nullptr; } + cparams.enable_comm_compute_log = params.enable_comm_compute_log; + cparams.n_ctx = params.n_ctx; cparams.n_predict = params.n_predict; cparams.n_seq_max = params.n_parallel; diff --git a/common/common.h b/common/common.h index 57aa25e5..546bf9c2 100644 --- a/common/common.h +++ b/common/common.h @@ -359,6 +359,9 @@ struct gpt_params { // tensor dumping std::string dump_folder = ""; // folder to dump network communication tensors + + // communication and computation logging + bool enable_comm_compute_log = false; // enable/disable communication and computation logging }; // call once at the start of a program if it uses libcommon diff --git a/include/llama.h b/include/llama.h index d75b8577..45a2bad3 100644 --- a/include/llama.h +++ b/include/llama.h @@ -381,6 +381,9 @@ extern "C" { // Tensor dumping path - if provided, network communication tensors will be dumped const char * dump_folder; + + // Enable/disable communication and computation logging for gantt chart analysis + bool enable_comm_compute_log; }; // model quantization parameters diff --git a/src/llama.cpp b/src/llama.cpp index 20bddb25..95e6796e 100644 --- a/src/llama.cpp +++ b/src/llama.cpp @@ -2704,6 +2704,7 @@ struct llama_cparams { void * cb_eval_user_data; const char * dump_folder; + bool enable_comm_compute_log; }; // TODO: separate into "llama_layer_enc" and "llama_layer_dec" @@ -18582,9 +18583,13 @@ static int llama_decode_internal( // receive data from other nodes if (n_world > 1 && !(my_rank == 0 && i == 0) && !(my_rank == 0 && is_last_l)) { - LLAMA_LOG_INFO("[%d][%s][comm][start][recv_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, receive data from other nodes]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + if (lctx.cparams.enable_comm_compute_log) { + LLAMA_LOG_INFO("[%d][%s][comm][start][recv_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, receive data from other nodes]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + } llama_recv_tensors(*lctx.recv_socket, &ubatch, is_out_embd, lctx.cparams.dump_folder); - LLAMA_LOG_INFO("[%d][%s][comm][end][recv_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, receive data from other nodes]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + if (lctx.cparams.enable_comm_compute_log) { + LLAMA_LOG_INFO("[%d][%s][comm][end][recv_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, receive data from other nodes]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + } } // ensure ggml_backend_tensor_get_async of the previous subgraph has finished @@ -18619,7 +18624,7 @@ static int llama_decode_internal( snprintf(layer_desc, sizeof(layer_desc), "transformer_blocks"); log_layer = true; } - if (log_layer) { + if (log_layer && lctx.cparams.enable_comm_compute_log) { LLAMA_LOG_INFO("[%d][%s][compute][start][%s][sbatch_tokens: %lu, ubatch_tokens: %u]\n", my_rank, start_compute_time.c_str(), layer_desc, lctx.sbatch.n_tokens, ubatch.n_tokens); LLAMA_LOG_INFO("[%d][%s][compute][end][%s][sbatch_tokens: %lu, ubatch_tokens: %u]\n", my_rank, end_compute_time.c_str(), layer_desc, lctx.sbatch.n_tokens, ubatch.n_tokens); } @@ -18655,12 +18660,16 @@ static int llama_decode_internal( // send the result to the next node or the master if (!(n_world == 1 || (my_rank == 0 && is_last_l))) { - LLAMA_LOG_INFO("[%d][%s][comm][start][send_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, send the result to the next node or the master]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + if (lctx.cparams.enable_comm_compute_log) { + LLAMA_LOG_INFO("[%d][%s][comm][start][send_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, send the result to the next node or the master]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + } struct input_tensors tensors = {sub_gf_out, lctx.inp_pos}; const bool is_to_master = my_rank != 0 && is_last_l; zmq::socket_t * s = is_to_master ? lctx.master_socket : lctx.send_socket; llama_send_tensors(*s, &ubatch, &tensors, lctx.cparams.dump_folder); - LLAMA_LOG_INFO("[%d][%s][comm][end][send_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, send the result to the next node or the master]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + if (lctx.cparams.enable_comm_compute_log) { + LLAMA_LOG_INFO("[%d][%s][comm][end][send_tensors][sbatch_tokens: %lu, ubatch_tokens: %u, send the result to the next node or the master]\n", my_rank, get_iso8601_ms_timestamp().c_str(), lctx.sbatch.n_tokens, ubatch.n_tokens); + } } // overlap memory scheduling with other nodes' communication and computing @@ -20413,6 +20422,7 @@ struct llama_context_params llama_context_default_params() { /*.abort_callback =*/ nullptr, /*.abort_callback_data =*/ nullptr, /*.dump_folder =*/ nullptr, + /*.enable_comm_compute_log =*/ false, }; return result; @@ -20924,6 +20934,7 @@ struct llama_context * llama_new_context_with_model( ctx->cparams.rank = params.rank; ctx->cparams.force = params.force; ctx->cparams.dump_folder = params.dump_folder; + ctx->cparams.enable_comm_compute_log = params.enable_comm_compute_log; ctx->cparams.original_next_rank = (params.rank + 1) % params.n_world; return ctx; }