source/blender/render/hydra/python.cc

@@ -22,7 +22,7 @@ namespace blender::render::hydra {
 
 static PyObject *init_func(PyObject * /*self*/, PyObject *args)
 {
-  CLOG_INFO(LOG_RENDER_HYDRA, 1, "Init");
+  CLOG_INFO(LOG_RENDER_HYDRA, 0, "Init");
 
   pxr::PlugRegistry::GetInstance().RegisterPlugins(std::string(BKE_appdir_program_dir()) +
                                                    "/blender.shared/usd");
@@ -59,7 +59,7 @@ static PyObject *register_plugins_func(PyObject * /*self*/, PyObject *args)
     ss << s << ", ";
   }
   ss << "]";
-  CLOG_INFO(LOG_RENDER_HYDRA, 1, "Register %s", ss.str().c_str());
+  CLOG_INFO(LOG_RENDER_HYDRA, 0, "Register %s", ss.str().c_str());
 
   Py_RETURN_NONE;
 }
@@ -125,7 +125,7 @@ static PyObject *engine_create_func(PyObject * /*self*/, PyObject *args)
     }
   }
 
-  CLOG_INFO(LOG_RENDER_HYDRA, 2, "Engine %016llx %s", engine, engine_type);
+  CLOG_INFO(LOG_RENDER_HYDRA, 1, "Engine %016llx %s", engine, engine_type);
   return PyLong_FromVoidPtr(engine);
 }
 
@@ -139,7 +139,7 @@ static PyObject *engine_free_func(PyObject * /*self*/, PyObject *args)
   Engine *engine = (Engine *)PyLong_AsVoidPtr(pyengine);
   delete engine;
 
-  CLOG_INFO(LOG_RENDER_HYDRA, 2, "Engine %016llx", engine);
+  CLOG_INFO(LOG_RENDER_HYDRA, 1, "Engine %016llx", engine);
   Py_RETURN_NONE;
 }
 
@@ -194,7 +194,7 @@ static PyObject *engine_render_func(PyObject * /*self*/, PyObject *args)
   engine->render(depsgraph);
   Py_END_ALLOW_THREADS;
 
-  CLOG_INFO(LOG_RENDER_HYDRA, 2, "Engine %016llx", engine);
+  CLOG_INFO(LOG_RENDER_HYDRA, 3, "Engine %016llx", engine);
   Py_RETURN_NONE;
 }
 

source/blender/render/hydra/scene_delegate/blender_scene_delegate.cc

@@ -426,7 +426,7 @@ void BlenderSceneDelegate::check_updates()
   ITER_BEGIN (DEG_iterator_ids_begin, DEG_iterator_ids_next, DEG_iterator_ids_end, &data, ID *, id)
   {
     CLOG_INFO(LOG_RENDER_HYDRA_SCENE,
-              2,
+              0,
               "Update: %s [%s]",
               id->name,
               std::bitset<32>(id->recalc).to_string().c_str());

source/blender/render/hydra/scene_delegate/curves.cc

@@ -21,7 +21,7 @@ CurvesData::CurvesData(BlenderSceneDelegate *scene_delegate,
 
 void CurvesData::init()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
 
   Object *object = (Object *)id;
   write_curves((Curves *)object->data);
@@ -31,7 +31,7 @@ void CurvesData::init()
 
 void CurvesData::insert()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   scene_delegate_->GetRenderIndex().InsertRprim(
       pxr::HdPrimTypeTokens->basisCurves, scene_delegate_, prim_id);
 }
@@ -64,7 +64,7 @@ void CurvesData::update()
   }
 
   scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(prim_id, bits);
-  ID_LOG(2, "");
+  ID_LOG(1, "");
 }
 
 pxr::VtValue CurvesData::get_data(pxr::SdfPath const &id, pxr::TfToken const &key) const
@@ -88,7 +88,7 @@ bool CurvesData::update_visibility()
   if (ret) {
     scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(
         prim_id, pxr::HdChangeTracker::DirtyVisibility);
-    ID_LOG(2, "");
+    ID_LOG(1, "");
   }
   return ret;
 }

source/blender/render/hydra/scene_delegate/image.cc

@@ -41,13 +41,15 @@ static std::string cache_image_file(Image *image,
   if (BKE_image_save_options_init(&opts, main, scene_delegate->scene, image, iuser, true, false)) {
     STRNCPY(opts.filepath, file_path.c_str());
     ReportList reports;
-    if (!BKE_image_save(&reports, main, image, iuser, &opts)) {
+    if (BKE_image_save(&reports, main, image, iuser, &opts)) {
+      CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 1, "%s -> %s", image->id.name, file_path.c_str());
+    }
+    else {
       file_path = "";
-    };
+    }
   }
   BKE_image_save_options_free(&opts);
 
-  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 2, "%s -> %s", image->id.name, file_path.c_str());
   return file_path;
 }
 
@@ -71,7 +73,7 @@ std::string cache_or_get_image_file(Image *image,
     }
   }
 
-  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 2, "%s -> %s", image->id.name, file_path.c_str());
+  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 1, "%s -> %s", image->id.name, file_path.c_str());
   return file_path;
 }
 

source/blender/render/hydra/scene_delegate/instancer.cc

@@ -61,19 +61,19 @@ bool InstancerData::is_visible(BlenderSceneDelegate *scene_delegate, Object *obj
 
 void InstancerData::init()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   write_instances();
 }
 
 void InstancerData::insert()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   scene_delegate_->GetRenderIndex().InsertInstancer(scene_delegate_, prim_id);
 }
 
 void InstancerData::remove()
 {
-  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 2, "%s", prim_id.GetText());
+  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 1, "%s", prim_id.GetText());
   for (auto &m_inst : mesh_instances_.values()) {
     m_inst.data->remove();
   }
@@ -87,7 +87,7 @@ void InstancerData::remove()
 
 void InstancerData::update()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   Object *object = (Object *)id;
   if (id->recalc & ID_RECALC_GEOMETRY ||
       (object->data && ((ID *)object->data)->recalc & ID_RECALC_GEOMETRY) ||
@@ -116,6 +116,7 @@ bool InstancerData::update_visibility()
   bool ret = visible != prev_visible;
 
   if (ret) {
+    ID_LOG(1, "");
     auto &change_tracker = scene_delegate_->GetRenderIndex().GetChangeTracker();
     change_tracker.MarkInstancerDirty(prim_id, pxr::HdChangeTracker::DirtyVisibility);
     for (auto &m_inst : mesh_instances_.values()) {

source/blender/render/hydra/scene_delegate/light.cc

@@ -24,7 +24,7 @@ LightData::LightData(BlenderSceneDelegate *scene_delegate,
 
 void LightData::init()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
 
   Light *light = (Light *)((Object *)id)->data;
   data_.clear();
@@ -99,19 +99,19 @@ void LightData::init()
 
 void LightData::insert()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   scene_delegate_->GetRenderIndex().InsertSprim(prim_type_, scene_delegate_, prim_id);
 }
 
 void LightData::remove()
 {
-  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 2, "%s", prim_id.GetText());
+  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 1, "%s", prim_id.GetText());
   scene_delegate_->GetRenderIndex().RemoveSprim(prim_type_, prim_id);
 }
 
 void LightData::update()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
 
   Object *object = (Object *)id;
   Light *light = (Light *)object->data;
@@ -138,6 +138,7 @@ void LightData::update()
 
 pxr::VtValue LightData::get_data(pxr::TfToken const &key) const
 {
+  ID_LOG(3, "%s", key.GetText());
   pxr::VtValue ret;
   auto it = data_.find(key);
   if (it != data_.end()) {
@@ -163,6 +164,7 @@ bool LightData::update_visibility()
   if (ret) {
     scene_delegate_->GetRenderIndex().GetChangeTracker().MarkSprimDirty(prim_id,
                                                                         pxr::HdLight::DirtyParams);
+    ID_LOG(1, "");
   }
   return ret;
 }

source/blender/render/hydra/scene_delegate/material.cc

@@ -30,7 +30,7 @@ MaterialData::MaterialData(BlenderSceneDelegate *scene_delegate,
 
 void MaterialData::init()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   double_sided = (((Material *)id)->blend_flag & MA_BL_CULL_BACKFACE) == 0;
 
   export_mtlx();
@@ -41,20 +41,20 @@ void MaterialData::init()
 
 void MaterialData::insert()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   scene_delegate_->GetRenderIndex().InsertSprim(
       pxr::HdPrimTypeTokens->material, scene_delegate_, prim_id);
 }
 
 void MaterialData::remove()
 {
-  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 2, "%s", prim_id.GetText());
+  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 1, "%s", prim_id.GetText());
   scene_delegate_->GetRenderIndex().RemoveSprim(pxr::HdPrimTypeTokens->material, prim_id);
 }
 
 void MaterialData::update()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   bool prev_double_sided = double_sided;
   init();
   scene_delegate_->GetRenderIndex().GetChangeTracker().MarkSprimDirty(prim_id,
@@ -144,12 +144,12 @@ void MaterialData::export_mtlx()
   PyGILState_Release(gstate);
 
   mtlx_path_ = pxr::SdfAssetPath(path, path);
-  ID_LOG(2, "mtlx=%s", mtlx_path_.GetResolvedPath().c_str());
+  ID_LOG(1, "mtlx=%s", mtlx_path_.GetResolvedPath().c_str());
 }
 
 void MaterialData::write_material_network_map()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   if (mtlx_path_.GetResolvedPath().empty()) {
     material_network_map_ = pxr::VtValue();
     return;

source/blender/render/hydra/scene_delegate/mesh.cc

@@ -23,7 +23,7 @@ MeshData::MeshData(BlenderSceneDelegate *scene_delegate,
 
 void MeshData::init()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
 
   Object *object = (Object *)id;
   if (object->type == OB_MESH && object->mode == OB_MODE_OBJECT &&
@@ -52,7 +52,7 @@ void MeshData::remove()
 {
   for (int i = 0; i < submeshes_.size(); ++i) {
     scene_delegate_->GetRenderIndex().RemoveRprim(submesh_prim_id(i));
-    CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 2, "%s: %d", prim_id.GetText(), i);
+    CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 1, "%s: %d", prim_id.GetText(), i);
   }
 }
 
@@ -80,7 +80,7 @@ void MeshData::update()
 
   for (int i = 0; i < submeshes_.size(); ++i) {
     scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(submesh_prim_id(i), bits);
-    ID_LOG(2, "%d", i);
+    ID_LOG(1, "%d", i);
   }
 }
 
@@ -106,7 +106,7 @@ bool MeshData::update_visibility()
     for (int i = 0; i < submeshes_.size(); ++i) {
       scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(
           submesh_prim_id(i), pxr::HdChangeTracker::DirtyVisibility);
-      ID_LOG(2, "%d", i);
+      ID_LOG(1, "%d", i);
     }
   }
   return ret;
@@ -168,7 +168,7 @@ void MeshData::update_double_sided(MaterialData *mat_data)
     if (submeshes_[i].mat_data == mat_data) {
       scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(
           submesh_prim_id(i), pxr::HdChangeTracker::DirtyDoubleSided);
-      ID_LOG(2, "%d", i);
+      ID_LOG(1, "%d", i);
     }
   }
 }
@@ -278,16 +278,16 @@ void MeshData::write_submeshes(Mesh *mesh)
     pxr::SdfPath p = submesh_prim_id(i);
     if (i < sub_meshes_prev_count) {
       render_index.GetChangeTracker().MarkRprimDirty(p, pxr::HdChangeTracker::AllDirty);
-      ID_LOG(2, "Update %d", i);
+      ID_LOG(1, "Update %d", i);
     }
     else {
       render_index.InsertRprim(pxr::HdPrimTypeTokens->mesh, scene_delegate_, p);
-      ID_LOG(2, "Insert %d", i);
+      ID_LOG(1, "Insert %d", i);
     }
   }
   for (; i < sub_meshes_prev_count; ++i) {
     render_index.RemoveRprim(submesh_prim_id(i));
-    ID_LOG(2, "Remove %d", i);
+    ID_LOG(1, "Remove %d", i);
   }
 }
 

source/blender/render/hydra/scene_delegate/object.cc

@@ -98,7 +98,7 @@ void ObjectData::update_parent()
 {
   Object *object = (Object *)id;
   if (parent_ != object->parent) {
-    ID_LOG(2, "");
+    ID_LOG(1, "");
     parent_ = object->parent;
 
     /* Looking for corresponded instancer and update it as parent */

source/blender/render/hydra/scene_delegate/world.cc

@@ -37,7 +37,7 @@ WorldData::WorldData(BlenderSceneDelegate *scene_delegate,
 
 void WorldData::init()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
 
   write_transform();
 
@@ -104,20 +104,20 @@ void WorldData::init()
 
 void WorldData::insert()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   scene_delegate_->GetRenderIndex().InsertSprim(
       pxr::HdPrimTypeTokens->domeLight, scene_delegate_, prim_id);
 }
 
 void WorldData::remove()
 {
-  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 2, "%s", prim_id.GetText());
+  CLOG_INFO(LOG_RENDER_HYDRA_SCENE, 1, "%s", prim_id.GetText());
   scene_delegate_->GetRenderIndex().RemoveSprim(pxr::HdPrimTypeTokens->domeLight, prim_id);
 }
 
 void WorldData::update()
 {
-  ID_LOG(2, "");
+  ID_LOG(1, "");
   init();
   scene_delegate_->GetRenderIndex().GetChangeTracker().MarkSprimDirty(prim_id,
                                                                       pxr::HdLight::AllDirty);
@@ -135,6 +135,7 @@ pxr::VtValue WorldData::get_data(pxr::TfToken const &key) const
   auto it = data_.find(key);
   if (it != data_.end()) {
     ret = it->second;
+    ID_LOG(3, "%s", key.GetText());
   }
   return ret;
 }