[Bf-blender-cvs] [a7c3f8b05f4] soc-2020-info-editor: Render: convert print to clog

Mateusz Grzeliński noreply at git.blender.org
Thu Jul 9 16:39:32 CEST 2020


Commit: a7c3f8b05f404a53bc1bcfa94f9cf2f3d07825ad
Author: Mateusz Grzeliński
Date:   Thu Jul 9 16:39:15 2020 +0200
Branches: soc-2020-info-editor
https://developer.blender.org/rBa7c3f8b05f404a53bc1bcfa94f9cf2f3d07825ad

Render: convert print to clog

- convert all prints in to logs
- remove printing background in favour of logger, that can be enabled anytime. This logger will print every 30 times, what solves T59649
- include missing header in BLI_timecode.h

===================================================================

M	intern/clog/CLG_log.h
M	source/blender/blenlib/BLI_timecode.h
M	source/blender/draw/engines/eevee/eevee_render.c
M	source/blender/render/CMakeLists.txt
M	source/blender/render/intern/include/render_types.h
M	source/blender/render/intern/source/bake_api.c
M	source/blender/render/intern/source/external_engine.c
M	source/blender/render/intern/source/pipeline.c
M	source/blender/render/intern/source/render_result.c

===================================================================

diff --git a/intern/clog/CLG_log.h b/intern/clog/CLG_log.h
index 618e7524b3d..ad11cc0d1dc 100644
--- a/intern/clog/CLG_log.h
+++ b/intern/clog/CLG_log.h
@@ -263,6 +263,29 @@ void CLG_logref_init(CLG_LogRef *clg_ref);
 #define CLOG_STR_ERROR_N(clg_ref, str) CLOG_STR_AT_SEVERITY_N(clg_ref, CLG_SEVERITY_ERROR, 0, str)
 #define CLOG_STR_FATAL_N(clg_ref, str) CLOG_STR_AT_SEVERITY_N(clg_ref, CLG_SEVERITY_FATAL, 0, str)
 
+#define LOG_EVERY_N_VARNAME(base, line) base##line
+#define LOG_OCCURRENCES LOG_EVERY_N_VARNAME(occurrences_, __LINE__)
+#define LOG_OCCURRENCES_MOD_N LOG_EVERY_N_VARNAME(occurrences_mod_n_, __LINE__)
+
+/* every n times do something */
+#define EVERY_N(n, what_to_do) \
+  static int LOG_OCCURRENCES = 0, LOG_OCCURRENCES_MOD_N = 0; \
+  ++LOG_OCCURRENCES; \
+  if (++LOG_OCCURRENCES_MOD_N > n) \
+    LOG_OCCURRENCES_MOD_N -= n; \
+  if (LOG_OCCURRENCES_MOD_N == 1) \
+  what_to_do
+
+/* same as CLOG_VERBOSE, but every n times */
+#define CLOG_VERBOSE_EVERY_N(clg_ref, verbosity_level, n, ...) \
+  EVERY_N(n, CLOG_VERBOSE(clg_ref, verbosity_level, __VA_ARGS__))
+/* same as CLOG_STR_VERBOSE, but every n times */
+#define CLOG_STR_VERBOSE_EVERY_N(clg_ref, verbosity_level, n, str) \
+  EVERY_N(n, CLOG_STR_VERBOSE(clg_ref, verbosity_level, str))
+/* same as CLOG_STR_VERBOSE_N, but every n times */
+#define CLOG_STR_VERBOSE_N_EVERY_N(clg_ref, verbosity_level, n, str) \
+  EVERY_N(n, CLOG_STR_VERBOSE_N(clg_ref, verbosity_level, str))
+
 #ifdef __cplusplus
 }
 #endif
diff --git a/source/blender/blenlib/BLI_timecode.h b/source/blender/blenlib/BLI_timecode.h
index d3c6803130a..7c77ba0e79f 100644
--- a/source/blender/blenlib/BLI_timecode.h
+++ b/source/blender/blenlib/BLI_timecode.h
@@ -25,6 +25,7 @@
  */
 
 #include "BLI_compiler_attrs.h"
+#include <stddef.h>
 
 #ifdef __cplusplus
 extern "C" {
diff --git a/source/blender/draw/engines/eevee/eevee_render.c b/source/blender/draw/engines/eevee/eevee_render.c
index f903fa905e8..7c811d2ce1f 100644
--- a/source/blender/draw/engines/eevee/eevee_render.c
+++ b/source/blender/draw/engines/eevee/eevee_render.c
@@ -540,8 +540,7 @@ void EEVEE_render_draw(EEVEE_Data *vedata, RenderEngine *engine, RenderLayer *rl
       EEVEE_temporal_sampling_reset(vedata);
       stl->effects->ssr_was_valid_double_buffer = stl->g_data->valid_double_buffer;
     }
-    /* Don't print every samples as it can lead to bad performance. (see T59649) */
-    else if ((render_samples % 25) == 0 || (render_samples + 1) == tot_sample) {
+    else {
       char info[42];
       BLI_snprintf(
           info, sizeof(info), "Rendering %u / %u samples", render_samples + 1, tot_sample);
diff --git a/source/blender/render/CMakeLists.txt b/source/blender/render/CMakeLists.txt
index f49c68a258d..93139491dd0 100644
--- a/source/blender/render/CMakeLists.txt
+++ b/source/blender/render/CMakeLists.txt
@@ -35,6 +35,7 @@ set(INC
   ../physics
   ../../../intern/atomic
   ../../../intern/guardedalloc
+  ../../../intern/clog
   ../../../intern/mikktspace
   ../../../intern/mantaflow/extern
 )
diff --git a/source/blender/render/intern/include/render_types.h b/source/blender/render/intern/include/render_types.h
index 3ae4b9c0b90..69c30b4bcdb 100644
--- a/source/blender/render/intern/include/render_types.h
+++ b/source/blender/render/intern/include/render_types.h
@@ -37,6 +37,9 @@
 
 #include "RE_pipeline.h"
 
+extern struct CLG_LogRef *RENDER_LOG_BAKE;
+extern struct CLG_LogRef *RENDER_LOG;
+
 struct GHash;
 struct Main;
 struct Object;
diff --git a/source/blender/render/intern/source/bake_api.c b/source/blender/render/intern/source/bake_api.c
index 06f77854595..9be4397db38 100644
--- a/source/blender/render/intern/source/bake_api.c
+++ b/source/blender/render/intern/source/bake_api.c
@@ -61,6 +61,7 @@
  * For a complete implementation example look at the Cycles Bake commit.
  */
 
+#include <CLG_log.h>
 #include <limits.h>
 
 #include "MEM_guardedalloc.h"
@@ -88,6 +89,8 @@
 #include "render_types.h"
 #include "zbuf.h"
 
+CLG_LOGREF_DECLARE_GLOBAL(RENDER_LOG_BAKE, "render.bake");
+
 typedef struct BakeDataZSpan {
   BakePixel *pixel_array;
   int primitive_id;
@@ -578,8 +581,9 @@ bool RE_bake_pixels_populate_from_objects(struct Mesh *me_low,
       BKE_bvhtree_from_mesh_get(&treeData[i], me_highpoly[i], BVHTREE_FROM_LOOPTRI, 2);
 
       if (treeData[i].tree == NULL) {
-        printf("Baking: out of memory while creating BHVTree for object \"%s\"\n",
-               highpoly[i].ob->id.name + 2);
+        CLOG_ERROR(RENDER_LOG_BAKE,
+                   "Baking: out of memory while creating BHVTree for object \"%s\"",
+                   highpoly[i].ob->id.name + 2);
         result = false;
         goto cleanup;
       }
diff --git a/source/blender/render/intern/source/external_engine.c b/source/blender/render/intern/source/external_engine.c
index 5391775cab8..e7d8bfd5b07 100644
--- a/source/blender/render/intern/source/external_engine.c
+++ b/source/blender/render/intern/source/external_engine.c
@@ -21,6 +21,11 @@
  * \ingroup render
  */
 
+#include <BKE_callbacks.h>
+#include <BLI_dynstr.h>
+#include <BLI_timecode.h>
+#include <CLG_log.h>
+#include <PIL_time.h>
 #include <stddef.h>
 #include <stdlib.h>
 #include <string.h>
@@ -67,6 +72,9 @@
 #include "render_types.h"
 #include "renderpipeline.h"
 
+static struct CLG_LogRef RENDER_LOG_ENGINE = {"render.engine"};
+static struct CLG_LogRef RENDER_LOG_STATS = {"render.stats"};
+
 /* Render Engine Types */
 
 ListBase R_engines = {NULL, NULL};
@@ -103,6 +111,7 @@ void RE_engines_register(RenderEngineType *render_type)
     DRW_engine_register(render_type->draw_engine);
   }
   BLI_addtail(&R_engines, render_type);
+  CLOG_VERBOSE(&RENDER_LOG_ENGINE, 0, "Renderer registered: %s", render_type->idname);
 }
 
 RenderEngineType *RE_engines_find(const char *idname)
@@ -368,7 +377,7 @@ void RE_engine_end_result(
     else if (re->result->do_exr_tile) {
       /* if written result does not match any tile and we are using save
        * buffers, we are going to get openexr save errors */
-      fprintf(stderr, "RenderEngine.end_result: dimensions do not match any OpenEXR tile.\n");
+      CLOG_ERROR(&RENDER_LOG_ENGINE, "Dimensions do not match any OpenEXR tile");
     }
   }
 
@@ -415,6 +424,50 @@ bool RE_engine_test_break(RenderEngine *engine)
 
 /* Statistics */
 
+static char *render_stats_sprinfN(RenderStats *rs)
+{
+  uintptr_t mem_in_use, peak_memory;
+  float megs_used_memory, megs_peak_memory;
+  char info_time_str[32];
+
+  mem_in_use = MEM_get_memory_in_use();
+  peak_memory = MEM_get_peak_memory();
+
+  megs_used_memory = (mem_in_use) / (1024.0 * 1024.0);
+  megs_peak_memory = (peak_memory) / (1024.0 * 1024.0);
+  DynStr *message = BLI_dynstr_new();
+
+  BLI_dynstr_appendf(message,
+                     TIP_("Fra:%d Mem:%.2fM (Peak %.2fM) "),
+                     rs->cfra,
+                     megs_used_memory,
+                     megs_peak_memory);
+
+  BLI_timecode_string_from_time_simple(
+      info_time_str, sizeof(info_time_str), PIL_check_seconds_timer() - rs->starttime);
+  BLI_dynstr_appendf(message, TIP_("| Time:%s | "), info_time_str);
+
+  if (rs->infostr && strcmp(rs->infostr, "") != 0) {
+    BLI_dynstr_appendf(message, "%s | ", rs->infostr);
+  }
+  if (rs->statstr && strcmp(rs->statstr, "") != 0) {
+    BLI_dynstr_appendf(message, "%s | ", rs->statstr);
+  }
+  BLI_dynstr_appendf(message,
+                     TIP_("Sce: \"%s\" Ve:%d Fa:%d La:%d"),
+                     rs->scene_name,
+                     rs->totvert,
+                     rs->totface,
+                     rs->totlamp);
+  char *cstring = BLI_dynstr_get_cstring(message);
+  /* Flush stdout to be sure python callbacks are printing stuff after blender. */
+  /* TODO (grzelins) is it possible/necessary to flush logs? */
+  fflush(stdout);
+
+  BLI_dynstr_free(message);
+  return cstring;
+}
+
 void RE_engine_update_stats(RenderEngine *engine, const char *stats, const char *info)
 {
   Render *re = engine->re;
@@ -424,10 +477,22 @@ void RE_engine_update_stats(RenderEngine *engine, const char *stats, const char
     re->i.statstr = stats;
     re->i.infostr = info;
     re->stats_draw(re->sdh, &re->i);
+    /* (grzelins) I would rather have separate log callback, but this is good enough
+     * render engine chooses when to call update: in eevee per sample, in cycles every second...
+     * note: it is possible that no logs will be printed (for short renders), messages like
+     * "cancel" can be missed */
+    if (CLOG_CHECK_IN_USE(&RENDER_LOG_STATS)) {
+      /* this is special use of log to allow user to control how much is printed with verbosity */
+      CLOG_STR_VERBOSE_N_EVERY_N(&RENDER_LOG_STATS, 2, 30, render_stats_sprinfN(&re->i));
+    }
     re->i.infostr = NULL;
     re->i.statstr = NULL;
   }
 
+  /* NOTE: using G_MAIN seems valid here???
+   * Not sure it's actually even used anyway, we could as well pass NULL? */
+  BKE_callback_exec_null(G_MAIN, BKE_CB_EVT_RENDER_STATS);
+
   /* set engine text */
   engine->text[0] = '\0';
 
diff --git a/source/blender/render/intern/source/pipeline.c b/source/blender/render/intern/source/pipeline.c
index b335862abe0..d0f5598f39d 100644
--- a/source/blender/render/intern/source/pipeline.c
+++ b/source/blender/render/intern/source/pipeline.c
@@ -21,6 +21,7 @@
  * \ingroup render
  */
 
+#include <CLG_log.h>
 #include <errno.h>
 #include <limits.h>
 #include <math.h>
@@ -130,6 +131,8 @@
 
 /* ********* globals ******** */
 
+CLG_LOGREF_DECLARE_GLOBAL(RENDER_LOG, "render");
+
 /* here we store all renders */
 static struct {
   ListBase renderlist;
@@ -185,56 +188,11 @@ static int default_break(void *UNUSED(arg))
   return G.is_break == true;
 }
 
-static void stats_background(void *UNUSED(arg), RenderStats *rs)
-{
-  uintptr_t mem_in_use, peak_memory;
-  float megs_used_memory, megs_peak_memory;
-  char info_time_str[32];
-
-  mem_in_use = MEM_get_memory_in_use();
-  peak_memory = MEM_get_peak_memory();
-
-  megs_used_memory = (mem_in_use) / (1024.0 * 1024.0);
-  megs_peak_memory = (peak_memory) / (1024.0 * 1024.0);
-
-  fprintf(stdout,
-          TIP_("Fra:%d Mem:%.2fM (Peak %.2fM) "),
-          rs->cfra,
-          megs_used_memory,
-          megs_peak_memory);
-

@@ Diff output truncated at 10240 characters. @@



More information about the Bf-blender-cvs mailing list