diff --git a/include/haproxy/tinfo-t.h b/include/haproxy/tinfo-t.h index 7d550e7e6..8968cfa09 100644 --- a/include/haproxy/tinfo-t.h +++ b/include/haproxy/tinfo-t.h @@ -161,6 +161,7 @@ struct thread_ctx { uint32_t sched_wake_date; /* current task/tasklet's wake date in 32-bit ns or 0 if not supported */ uint64_t sched_call_date; /* current task/tasklet's call date in ns */ uint64_t lock_wait_total; /* total time in ns spent waiting for a lock (task prof) */ + uint64_t mem_wait_total; /* total time in ns spent allocating/freeing memory (task prof) */ uint64_t lock_start_date; /* date when first locked was obtained (task prof) */ uint64_t locked_total; /* total time in ns spent with at least one lock held (task prof) */ diff --git a/src/pool.c b/src/pool.c index d7928c37c..d824b2b93 100644 --- a/src/pool.c +++ b/src/pool.c @@ -20,6 +20,7 @@ #include #include #include +#include #include #include #include @@ -787,10 +788,18 @@ void pool_put_to_cache(struct pool_head *pool, void *ptr, const void *caller) pool_cache_bytes += pool->size; if (unlikely(pool_cache_bytes > global.tune.pool_cache_size * 3 / 4)) { + uint64_t mem_wait_start = 0; + + if (unlikely(th_ctx->flags & TH_FL_TASK_PROFILING)) + mem_wait_start = now_mono_time(); + if (ph->count >= 16 + pool_cache_count / 8 + CONFIG_HAP_POOL_CLUSTER_SIZE) pool_evict_from_local_cache(pool, 0); if (pool_cache_bytes > global.tune.pool_cache_size) pool_evict_from_local_caches(); + + if (unlikely(mem_wait_start)) + th_ctx->mem_wait_total += now_mono_time() - mem_wait_start; } } @@ -941,8 +950,12 @@ void pool_flush(struct pool_head *pool) void pool_gc(struct pool_head *pool_ctx) { struct pool_head *entry; + uint64_t mem_wait_start = 0; int isolated = thread_isolated(); + if (th_ctx->flags & TH_FL_TASK_PROFILING) + mem_wait_start = now_mono_time(); + if (!isolated) thread_isolate(); @@ -975,6 +988,9 @@ void pool_gc(struct pool_head *pool_ctx) if (!isolated) thread_release(); + + if (mem_wait_start) + th_ctx->mem_wait_total += now_mono_time() - mem_wait_start; } /* @@ -995,9 +1011,19 @@ void *__pool_alloc(struct pool_head *pool, unsigned int flags) if (likely(!(pool_debugging & POOL_DBG_NO_CACHE)) && !p) p = pool_get_from_cache(pool, caller); - if (unlikely(!p)) + if (unlikely(!p)) { + /* count allocation time only for cache misses */ + uint64_t mem_wait_start = 0; + + if (unlikely(th_ctx->flags & TH_FL_TASK_PROFILING)) + mem_wait_start = now_mono_time(); + p = pool_alloc_nocache(pool, caller); + if (unlikely(mem_wait_start)) + th_ctx->mem_wait_total += now_mono_time() - mem_wait_start; + } + if (likely(p)) { #ifdef USE_MEMORY_PROFILING if (unlikely(profiling & HA_PROF_MEMORY)) { @@ -1061,11 +1087,20 @@ void __pool_free(struct pool_head *pool, void *ptr) if (unlikely((pool_debugging & POOL_DBG_NO_CACHE) || (pool->flags & MEM_F_UAF) || global.tune.pool_cache_size < pool->size)) { - pool_free_nocache(pool, ptr); - return; - } + uint64_t mem_wait_start = 0; - pool_put_to_cache(pool, ptr, caller); + if (unlikely(th_ctx->flags & TH_FL_TASK_PROFILING)) + mem_wait_start = now_mono_time(); + + pool_free_nocache(pool, ptr); + + if (unlikely(mem_wait_start)) + th_ctx->mem_wait_total += now_mono_time() - mem_wait_start; + } + else { + /* this one will count its own time itself */ + pool_put_to_cache(pool, ptr, caller); + } } /* diff --git a/src/task.c b/src/task.c index 0de5a588d..4f7ef2bb2 100644 --- a/src/task.c +++ b/src/task.c @@ -570,6 +570,7 @@ unsigned int run_tasks_from_lists(unsigned int budgets[]) t->calls++; th_ctx->lock_wait_total = 0; + th_ctx->mem_wait_total = 0; th_ctx->locked_total = 0; th_ctx->sched_wake_date = t->wake_date; if (th_ctx->sched_wake_date || (t->state & TASK_F_WANTS_TIME)) { @@ -684,6 +685,8 @@ unsigned int run_tasks_from_lists(unsigned int budgets[]) HA_ATOMIC_ADD(&profile_entry->cpu_time, (uint32_t)(now_mono_time() - th_ctx->sched_call_date)); if (th_ctx->lock_wait_total) HA_ATOMIC_ADD(&profile_entry->lkw_time, th_ctx->lock_wait_total); + if (th_ctx->mem_wait_total) + HA_ATOMIC_ADD(&profile_entry->mem_time, th_ctx->mem_wait_total); if (th_ctx->locked_total) HA_ATOMIC_ADD(&profile_entry->lkd_time, th_ctx->locked_total); }