Change log severity for better maintability #50

Merged
Bogdan Nagirniak merged 6 commits from Vasyl-Pidhirskyi/blender_bn:BLEN-422 into hydra-render 2023-06-05 19:46:21 +02:00
10 changed files with 47 additions and 41 deletions

View File

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

View File

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

View File

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

View File

@ -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)) { if (BKE_image_save_options_init(&opts, main, scene_delegate->scene, image, iuser, true, false)) {
STRNCPY(opts.filepath, file_path.c_str()); STRNCPY(opts.filepath, file_path.c_str());
ReportList reports; 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 = ""; file_path = "";
}; }
} }
BKE_image_save_options_free(&opts); 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; 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; return file_path;
} }

View File

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

View File

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

View File

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

View File

@ -23,7 +23,7 @@ MeshData::MeshData(BlenderSceneDelegate *scene_delegate,
void MeshData::init() void MeshData::init()
{ {
ID_LOG(2, ""); ID_LOG(1, "");
Object *object = (Object *)id; Object *object = (Object *)id;
if (object->type == OB_MESH && object->mode == OB_MODE_OBJECT && 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) { for (int i = 0; i < submeshes_.size(); ++i) {
scene_delegate_->GetRenderIndex().RemoveRprim(submesh_prim_id(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) { for (int i = 0; i < submeshes_.size(); ++i) {
scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(submesh_prim_id(i), bits); 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) { for (int i = 0; i < submeshes_.size(); ++i) {
scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty( scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(
submesh_prim_id(i), pxr::HdChangeTracker::DirtyVisibility); submesh_prim_id(i), pxr::HdChangeTracker::DirtyVisibility);
ID_LOG(2, "%d", i); ID_LOG(1, "%d", i);
} }
} }
return ret; return ret;
@ -168,7 +168,7 @@ void MeshData::update_double_sided(MaterialData *mat_data)
if (submeshes_[i].mat_data == mat_data) { if (submeshes_[i].mat_data == mat_data) {
scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty( scene_delegate_->GetRenderIndex().GetChangeTracker().MarkRprimDirty(
submesh_prim_id(i), pxr::HdChangeTracker::DirtyDoubleSided); 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); pxr::SdfPath p = submesh_prim_id(i);
if (i < sub_meshes_prev_count) { if (i < sub_meshes_prev_count) {
render_index.GetChangeTracker().MarkRprimDirty(p, pxr::HdChangeTracker::AllDirty); render_index.GetChangeTracker().MarkRprimDirty(p, pxr::HdChangeTracker::AllDirty);
ID_LOG(2, "Update %d", i); ID_LOG(1, "Update %d", i);
} }
else { else {
render_index.InsertRprim(pxr::HdPrimTypeTokens->mesh, scene_delegate_, p); 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) { for (; i < sub_meshes_prev_count; ++i) {
render_index.RemoveRprim(submesh_prim_id(i)); render_index.RemoveRprim(submesh_prim_id(i));
ID_LOG(2, "Remove %d", i); ID_LOG(1, "Remove %d", i);
} }
} }

View File

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

View File

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