diff --git a/ggml/src/ggml-cpu/ggml-cpu.c b/ggml/src/ggml-cpu/ggml-cpu.c index 53d39d2..02889fd 100644 --- a/ggml/src/ggml-cpu/ggml-cpu.c +++ b/ggml/src/ggml-cpu/ggml-cpu.c @@ -35,6 +35,49 @@ #include #include #include + +// ---- lightweight per-op profiling (GGML_PROF=1), diagnostic only ---- +static int g_prof = -1; +struct ggml_prof_entry { const char * op; const char * type; const char * ty0; int64_t ne0, ne1, ne2; int64_t us; int64_t calls; }; +static struct ggml_prof_entry g_prof_tab[1024]; +static int g_prof_n = 0; +static int64_t g_prof_total = 0; + +static void ggml_prof_dump(void) { + if (g_prof_n == 0) return; + fprintf(stderr, "\n[GGML_PROF] total_us=%" PRId64 "\n", g_prof_total); + for (int i = 0; i < g_prof_n; ++i) { + fprintf(stderr, "[GGML_PROF] %-20s %-6s<%-6s [%6" PRId64 ",%5" PRId64 ",%4" PRId64 "] %9.2f ms %6.2f%% calls=%" PRId64 " us/call=%.1f\n", + g_prof_tab[i].op, g_prof_tab[i].type, g_prof_tab[i].ty0, g_prof_tab[i].ne0, g_prof_tab[i].ne1, g_prof_tab[i].ne2, + g_prof_tab[i].us/1000.0, + 100.0*g_prof_tab[i].us/(g_prof_total?g_prof_total:1), + g_prof_tab[i].calls, + (double)g_prof_tab[i].us/(g_prof_tab[i].calls?g_prof_tab[i].calls:1)); + } + fflush(stderr); +} + +static void ggml_prof_add(const struct ggml_tensor * node, int64_t us) { + g_prof_total += us; + const char * op = ggml_op_name(node->op); + const char * ty = ggml_type_name(node->type); + const char * ty0 = node->src[0] ? ggml_type_name(node->src[0]->type) : "-"; + const int64_t ne0 = node->ne[0], ne1 = node->ne[1], ne2 = node->ne[2]; + for (int i = 0; i < g_prof_n; ++i) { + if (strcmp(g_prof_tab[i].op, op) == 0 && strcmp(g_prof_tab[i].type, ty) == 0 && strcmp(g_prof_tab[i].ty0, ty0) == 0 && + g_prof_tab[i].ne0 == ne0 && g_prof_tab[i].ne1 == ne1 && g_prof_tab[i].ne2 == ne2) { + g_prof_tab[i].us += us; g_prof_tab[i].calls++; + return; + } + } + if (g_prof_n < 1024) { + g_prof_tab[g_prof_n].op = op; g_prof_tab[g_prof_n].type = ty; g_prof_tab[g_prof_n].ty0 = ty0; + g_prof_tab[g_prof_n].ne0 = ne0; g_prof_tab[g_prof_n].ne1 = ne1; g_prof_tab[g_prof_n].ne2 = ne2; + g_prof_tab[g_prof_n].us = us; g_prof_tab[g_prof_n].calls = 1; + g_prof_n++; + } +} +// ---------------------------------------------------------------- #if defined(__gnu_linux__) #include #endif @@ -3148,6 +3191,13 @@ static thread_ret_t ggml_graph_compute_thread(void * data) { continue; } + if (g_prof < 0) { + const char * e = getenv("GGML_PROF"); + g_prof = e && e[0] == '1' ? 1 : 0; + if (g_prof) atexit(ggml_prof_dump); + } + const int64_t prof_t0 = (g_prof && state->ith == 0) ? ggml_time_us() : 0; + // TODO: move fused-op detection into ggml_graph_plan so fusion decisions are made once at planning time // Try fused ops, fall back to normal compute const int n_fused = ggml_cpu_try_fuse_ops(cgraph, node_n, ¶ms, cplan); @@ -3166,6 +3216,9 @@ static thread_ret_t ggml_graph_compute_thread(void * data) { if (node_n + 1 < cgraph->n_nodes) { ggml_barrier(state->threadpool); } + if (g_prof && state->ith == 0) { + ggml_prof_add(node, ggml_time_us() - prof_t0); + } } #ifdef GGML_USE_OPENMP