DRW: Revamp the performance debugging tool.

Old performance debug was doing queries for every frame even if not debugging perf.
Also, it did not record when a pass was draw multiple time, leading to incorect measurement.

New module also allows to group the timers to limit infos displayed.

Also fix the background CPU draw timer.
This commit is contained in:
Clément Foucault 2017-07-26 19:57:46 +02:00
parent 2b8f50e1d4
commit 5bfa3cf6e9
5 changed files with 326 additions and 92 deletions

View File

@ -63,6 +63,7 @@ set(SRC
intern/draw_common.c
intern/draw_manager.c
intern/draw_manager_text.c
intern/draw_manager_profiling.c
intern/draw_view.c
modes/edit_armature_mode.c
modes/edit_curve_mode.c
@ -94,6 +95,7 @@ set(SRC
intern/draw_cache_impl.h
intern/draw_common.h
intern/draw_manager_text.h
intern/draw_manager_profiling.h
intern/draw_view.h
modes/draw_mode_engines.h
engines/basic/basic_engine.h

View File

@ -49,6 +49,8 @@
#include "draw_cache.h"
#include "draw_view.h"
#include "draw_manager_profiling.h"
#include "MEM_guardedalloc.h"
#include "RE_engine.h"

View File

@ -80,6 +80,7 @@
#include "WM_types.h"
#include "draw_manager_text.h"
#include "draw_manager_profiling.h"
/* only for callbacks */
#include "draw_cache_impl.h"
@ -191,12 +192,6 @@ struct DRWPass {
ListBase shgroups; /* DRWShadingGroup */
DRWState state;
char name[MAX_PASS_NAME];
/* use two query to not stall the cpu waiting for queries to complete */
unsigned int timer_queries[2];
/* alternate between front and back query */
unsigned int front_idx;
unsigned int back_idx;
bool wasdrawn; /* if it was drawn during this frame */
};
typedef struct DRWCallHeader {
@ -1260,7 +1255,6 @@ void DRW_pass_free(DRWPass *pass)
DRW_shgroup_free(shgroup);
}
glDeleteQueries(2, pass->timer_queries);
BLI_freelistN(&pass->shgroups);
}
@ -1900,28 +1894,7 @@ static void DRW_draw_pass_ex(DRWPass *pass, DRWShadingGroup *start_group, DRWSha
DRW_state_set(pass->state);
BLI_listbase_clear(&DST.bound_texs);
/* Init Timer queries */
if (pass->timer_queries[0] == 0) {
pass->front_idx = 0;
pass->back_idx = 1;
glGenQueries(2, pass->timer_queries);
/* dummy query, avoid gl error */
glBeginQuery(GL_TIME_ELAPSED, pass->timer_queries[pass->front_idx]);
glEndQuery(GL_TIME_ELAPSED);
}
else {
/* swap indices */
unsigned int tmp = pass->back_idx;
pass->back_idx = pass->front_idx;
pass->front_idx = tmp;
}
if (!pass->wasdrawn) {
/* issue query for the next frame */
glBeginQuery(GL_TIME_ELAPSED, pass->timer_queries[pass->back_idx]);
}
DRW_stats_query_start(pass->name);
for (DRWShadingGroup *shgroup = start_group; shgroup; shgroup = shgroup->next) {
draw_shgroup(shgroup, pass->state);
@ -1943,11 +1916,7 @@ static void DRW_draw_pass_ex(DRWPass *pass, DRWShadingGroup *start_group, DRWSha
DST.shader = NULL;
}
if (!pass->wasdrawn) {
glEndQuery(GL_TIME_ELAPSED);
}
pass->wasdrawn = true;
DRW_stats_query_end();
}
void DRW_draw_pass(DRWPass *pass)
@ -2620,15 +2589,18 @@ static void DRW_engines_draw_background(void)
for (LinkData *link = DST.enabled_engines.first; link; link = link->next) {
DrawEngineType *engine = link->data;
ViewportEngineData *data = DRW_viewport_engine_data_get(engine);
double stime = PIL_check_seconds_timer();
if (engine->draw_background) {
double stime = PIL_check_seconds_timer();
DRW_stats_group_start(engine->idname);
engine->draw_background(data);
DRW_stats_group_end();
double ftime = (PIL_check_seconds_timer() - stime) * 1e3;
data->background_time = data->background_time * (1.0f - TIMER_FALLOFF) + ftime * TIMER_FALLOFF; /* exp average */
return;
}
double ftime = (PIL_check_seconds_timer() - stime) * 1e3;
data->background_time = data->background_time * (1.0f - TIMER_FALLOFF) + ftime * TIMER_FALLOFF; /* exp average */
}
/* No draw_background found, doing default background */
@ -2643,7 +2615,9 @@ static void DRW_engines_draw_scene(void)
double stime = PIL_check_seconds_timer();
if (engine->draw_scene) {
DRW_stats_group_start(engine->idname);
engine->draw_scene(data);
DRW_stats_group_end();
}
double ftime = (PIL_check_seconds_timer() - stime) * 1e3;
@ -2877,7 +2851,7 @@ static unsigned int DRW_engines_get_hash(void)
static void draw_stat(rcti *rect, int u, int v, const char *txt, const int size)
{
BLF_draw_default_ascii(rect->xmin + (1 + u * 5) * U.widget_unit,
rect->ymax - (3 + v++) * U.widget_unit, 0.0f,
rect->ymax - (3 + v) * U.widget_unit, 0.0f,
txt, size);
}
@ -2968,66 +2942,32 @@ static void DRW_debug_gpu_stats(void)
UI_FontThemeColor(BLF_default(), TH_TEXT_HI);
char time_to_txt[16];
char pass_name[MAX_PASS_NAME + 16];
int v = BLI_listbase_count(&DST.enabled_engines) + 3;
GLuint64 tot_time = 0;
if (G.debug_value > 666) {
for (LinkData *link = DST.enabled_engines.first; link; link = link->next) {
GLuint64 engine_time = 0;
DrawEngineType *engine = link->data;
ViewportEngineData *data = DRW_viewport_engine_data_get(engine);
int vsta = v;
draw_stat(&rect, 0, v, engine->idname, sizeof(engine->idname));
v++;
for (int i = 0; i < engine->vedata_size->psl_len; ++i) {
DRWPass *pass = data->psl->passes[i];
if (pass != NULL && pass->wasdrawn) {
GLuint64 time;
glGetQueryObjectui64v(pass->timer_queries[pass->front_idx], GL_QUERY_RESULT, &time);
sprintf(pass_name, " |--> %s", pass->name);
draw_stat(&rect, 0, v, pass_name, sizeof(pass_name));
sprintf(time_to_txt, "%.2fms", time / 1000000.0);
engine_time += time;
tot_time += time;
draw_stat(&rect, 2, v++, time_to_txt, sizeof(time_to_txt));
pass->wasdrawn = false;
}
}
/* engine total time */
sprintf(time_to_txt, "%.2fms", engine_time / 1000000.0);
draw_stat(&rect, 2, vsta, time_to_txt, sizeof(time_to_txt));
v++;
}
sprintf(pass_name, "Total GPU time %.2fms (%.1f fps)", tot_time / 1000000.0, 1000000000.0 / tot_time);
draw_stat(&rect, 0, v++, pass_name, sizeof(pass_name));
v++;
}
char stat_string[32];
/* Memory Stats */
unsigned int tex_mem = GPU_texture_memory_usage_get();
unsigned int vbo_mem = GWN_vertbuf_get_memory_usage();
sprintf(pass_name, "GPU Memory");
draw_stat(&rect, 0, v, pass_name, sizeof(pass_name));
sprintf(pass_name, "%.2fMB", (float)(tex_mem + vbo_mem) / 1000000.0);
draw_stat(&rect, 1, v++, pass_name, sizeof(pass_name));
sprintf(pass_name, " |--> Textures");
draw_stat(&rect, 0, v, pass_name, sizeof(pass_name));
sprintf(pass_name, "%.2fMB", (float)tex_mem / 1000000.0);
draw_stat(&rect, 1, v++, pass_name, sizeof(pass_name));
sprintf(pass_name, " |--> Meshes");
draw_stat(&rect, 0, v, pass_name, sizeof(pass_name));
sprintf(pass_name, "%.2fMB", (float)vbo_mem / 1000000.0);
draw_stat(&rect, 1, v++, pass_name, sizeof(pass_name));
sprintf(stat_string, "GPU Memory");
draw_stat(&rect, 0, v, stat_string, sizeof(stat_string));
sprintf(stat_string, "%.2fMB", (float)(tex_mem + vbo_mem) / 1000000.0);
draw_stat(&rect, 1, v++, stat_string, sizeof(stat_string));
sprintf(stat_string, " |--> Textures");
draw_stat(&rect, 0, v, stat_string, sizeof(stat_string));
sprintf(stat_string, "%.2fMB", (float)tex_mem / 1000000.0);
draw_stat(&rect, 1, v++, stat_string, sizeof(stat_string));
sprintf(stat_string, " |--> Meshes");
draw_stat(&rect, 0, v, stat_string, sizeof(stat_string));
sprintf(stat_string, "%.2fMB", (float)vbo_mem / 1000000.0);
draw_stat(&rect, 1, v++, stat_string, sizeof(stat_string));
/* Pre offset for stats_draw */
rect.ymax -= (3 + ++v) * U.widget_unit;
/* Rendering Stats */
DRW_stats_draw(&rect);
}
@ -3106,6 +3046,8 @@ void DRW_draw_render_loop_ex(
DRW_engines_cache_finish();
}
DRW_stats_begin();
/* Start Drawing */
DRW_state_reset();
DRW_engines_draw_background();
@ -3136,6 +3078,8 @@ void DRW_draw_render_loop_ex(
DRW_draw_region_info();
}
DRW_stats_reset();
if (G.debug_value > 20) {
DRW_debug_cpu_stats();
DRW_debug_gpu_stats();
@ -3555,6 +3499,7 @@ extern struct GPUTexture *globals_ramp; /* draw_common.c */
void DRW_engines_free(void)
{
DRW_shape_cache_free();
DRW_stats_free();
DrawEngineType *next;
for (DrawEngineType *type = DRW_engines.first; type; type = next) {

View File

@ -0,0 +1,242 @@
/*
* Copyright 2016, Blender Foundation.
*
* This program is free software; you can redistribute it and/or
* modify it under the terms of the GNU General Public License
* as published by the Free Software Foundation; either version 2
* of the License, or (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program; if not, write to the Free Software Foundation,
* Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
*
* Contributor(s): Blender Institute
*
*/
/** \file draw_manager_profiling.c
* \ingroup draw
*/
#include "BLI_rect.h"
#include "BLI_string.h"
#include "BKE_global.h"
#include "BLF_api.h"
#include "MEM_guardedalloc.h"
#include "GPU_glew.h"
#include "WM_api.h"
#include "WM_types.h"
#include "draw_manager_profiling.h"
#define MAX_TIMER_NAME 32
#define MAX_NESTED_TIMER 8
#define CHUNK_SIZE 8
#define GPU_TIMER_FALLOFF 0.1
typedef struct DRWTimer {
GLuint query[2];
GLuint64 time_average;
char name[MAX_TIMER_NAME];
int lvl; /* Hierarchy level for nested timer. */
bool is_query; /* Does this timer actually perform queries or is it just a group. */
} DRWTimer;
static struct DRWTimerPool {
DRWTimer *timers;
int chunk_count; /* Number of chunk allocated. */
int timer_count; /* chunk_count * CHUNK_SIZE */
int timer_increment; /* Keep track of where we are in the stack. */
int end_increment; /* Keep track of bad usage. */
bool is_recording; /* Are we in the render loop? */
bool is_querying; /* Keep track of bad usage. */
} DTP = {NULL};
void DRW_stats_free(void)
{
if (DTP.timers != NULL) {
for (int i = 0; i < DTP.timer_count; ++i) {
DRWTimer *timer = &DTP.timers[i];
glDeleteQueries(2, timer->query);
}
MEM_freeN(DTP.timers);
DTP.timers = NULL;
}
}
void DRW_stats_begin(void)
{
if (G.debug_value > 20) {
DTP.is_recording = true;
}
if (DTP.is_recording && DTP.timers == NULL) {
DTP.chunk_count = 1;
DTP.timer_count = DTP.chunk_count * CHUNK_SIZE;
DTP.timers = MEM_callocN(sizeof(DRWTimer) * DTP.timer_count, "DRWTimer stack");
}
else if(!DTP.is_recording && DTP.timers != NULL) {
DRW_stats_free();
}
DTP.is_querying = false;
DTP.timer_increment = 0;
DTP.end_increment = 0;
}
static DRWTimer *drw_stats_timer_get(void)
{
if (UNLIKELY(DTP.timer_increment >= DTP.timer_count)) {
/* Resize the stack. */
DTP.chunk_count++;
DTP.timer_count = DTP.chunk_count * CHUNK_SIZE;
DTP.timers = MEM_recallocN(DTP.timers, sizeof(DRWTimer) * DTP.timer_count);
}
return &DTP.timers[DTP.timer_increment++];
}
static void drw_stats_timer_start_ex(const char *name, const bool is_query)
{
if (DTP.is_recording) {
DRWTimer *timer = drw_stats_timer_get();
BLI_strncpy(timer->name, name, MAX_TIMER_NAME);
timer->lvl = DTP.timer_increment - DTP.end_increment - 1;
timer->is_query = is_query;
/* Queries cannot be nested or interleaved. */
BLI_assert(!DTP.is_querying);
if (timer->is_query) {
if (timer->query[0] == 0) {
glGenQueries(1, timer->query);
}
/* Issue query for the next frame */
glBeginQuery(GL_TIME_ELAPSED, timer->query[0]);
DTP.is_querying = true;
}
}
}
/* Use this to group the queries. It does NOT keep track
* of the time, it only sum what the queries inside it. */
void DRW_stats_group_start(const char *name)
{
drw_stats_timer_start_ex(name, false);
}
void DRW_stats_group_end(void)
{
if (DTP.is_recording) {
BLI_assert(!DTP.is_querying);
DTP.end_increment++;
}
}
/* NOTE: Only call this when no sub timer will be called. */
void DRW_stats_query_start(const char *name)
{
drw_stats_timer_start_ex(name, true);
}
void DRW_stats_query_end(void)
{
if (DTP.is_recording) {
DTP.end_increment++;
BLI_assert(DTP.is_querying);
glEndQuery(GL_TIME_ELAPSED);
DTP.is_querying = false;
}
}
void DRW_stats_reset(void)
{
BLI_assert((DTP.timer_increment - DTP.end_increment) <= 0 && "You forgot a DRW_stats_group/query_end somewhere!");
BLI_assert((DTP.timer_increment - DTP.end_increment) >= 0 && "You forgot a DRW_stats_group/query_start somewhere!");
if (DTP.is_recording) {
GLuint64 lvl_time[MAX_NESTED_TIMER] = {0};
/* Swap queries for the next frame and sum up each lvl time. */
for (int i = DTP.timer_increment - 1; i >= 0; --i) {
DRWTimer *timer = &DTP.timers[i];
SWAP(GLuint, timer->query[0], timer->query[1]);
BLI_assert(timer->lvl < MAX_NESTED_TIMER);
if (timer->is_query) {
GLuint64 time;
if (timer->query[0] != 0) {
glGetQueryObjectui64v(timer->query[0], GL_QUERY_RESULT, &time);
}
else {
time = 1000000000; /* 1ms default */
}
timer->time_average = timer->time_average * (1.0 - GPU_TIMER_FALLOFF) + time * GPU_TIMER_FALLOFF;
timer->time_average = MIN2(timer->time_average, 1000000000);
}
else {
timer->time_average = lvl_time[timer->lvl + 1];
lvl_time[timer->lvl + 1] = 0;
}
lvl_time[timer->lvl] += timer->time_average;
}
DTP.is_recording = false;
}
}
void DRW_stats_draw(rcti *rect)
{
char stat_string[64];
int lvl_index[MAX_NESTED_TIMER];
int v = 0;
BLI_snprintf(stat_string, sizeof(stat_string), "GPU Render Stats");
BLF_draw_default_ascii(rect->xmin + 1 * U.widget_unit, rect->ymax - v++ * U.widget_unit, 0.0f, stat_string, sizeof(stat_string));
for (int i = 0; i < DTP.timer_increment; ++i) {
double time_ms, time_percent;
DRWTimer *timer = &DTP.timers[i];
DRWTimer *timer_parent = (timer->lvl > 0) ? &DTP.timers[lvl_index[timer->lvl - 1]] : NULL;
/* Only display a number of lvl at a time */
if ((G.debug_value - 21) < timer->lvl) continue;
BLI_assert(timer->lvl < MAX_NESTED_TIMER);
lvl_index[timer->lvl] = i;
time_ms = timer->time_average / 1000000.0;
if (timer_parent != NULL) {
time_percent = ((double)timer->time_average / (double)timer_parent->time_average) * 100.0;
}
else {
time_percent = 100.0;
}
/* avoid very long number */
time_ms = MIN2(time_ms, 999.0);
time_percent = MIN2(time_percent, 100.0);
BLI_snprintf(stat_string, sizeof(stat_string), "%.2fms", time_ms);
BLF_draw_default_ascii(rect->xmin + 1 * U.widget_unit, rect->ymax - v * U.widget_unit, 0.0f, stat_string, sizeof(stat_string));
BLI_snprintf(stat_string, sizeof(stat_string), "%.0f", time_percent);
BLF_draw_default_ascii(rect->xmin + 4 * U.widget_unit, rect->ymax - v * U.widget_unit, 0.0f, stat_string, sizeof(stat_string));
BLI_snprintf(stat_string, sizeof(stat_string), "%s", timer->name);
BLF_draw_default_ascii(rect->xmin + (6 + timer->lvl) * U.widget_unit, rect->ymax - v * U.widget_unit, 0.0f, stat_string, sizeof(stat_string));
v++;
}
}

View File

@ -0,0 +1,43 @@
/*
* Copyright 2016, Blender Foundation.
*
* This program is free software; you can redistribute it and/or
* modify it under the terms of the GNU General Public License
* as published by the Free Software Foundation; either version 2
* of the License, or (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program; if not, write to the Free Software Foundation,
* Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
*
* Contributor(s): Blender Institute
*
*/
/** \file draw_manager_profiling.h
* \ingroup draw
*/
#ifndef __DRAW_MANAGER_PROFILING_H__
#define __DRAW_MANAGER_PROFILING_H__
struct rcti;
void DRW_stats_free(void);
void DRW_stats_begin(void);
void DRW_stats_reset(void);
void DRW_stats_group_start(const char *name);
void DRW_stats_group_end(void);
void DRW_stats_query_start(const char *name);
void DRW_stats_query_end(void);
void DRW_stats_draw(rcti *rect);
#endif /* __DRAW_MANAGER_PROFILING_H__ */