Feature: improve logging related to finding files

docs/src/developer_guide.rst

@@ -44,6 +44,11 @@ We've essentially imported Python's `PEP 8 <https://peps.python.org/pep-0008/>`_
 into the C++ side (which does not specify a recommended naming convention),
 ensuring that code that uses functionality from both languages looks natural.
 
+Further points of guidance include:
+
+* When writing error or log messages that refer to an existing file, include
+  the full path to the file by default.
+
 Contributing
 ------------
 
@@ -63,4 +68,4 @@ Going further
     developer_guide/documentation
     developer_guide/variants_cpp
     developer_guide/writing_plugin
-    developer_guide/testing
+    developer_guide/testing

src/core/fresolver.cpp

@@ -1,4 +1,5 @@
 #include <mitsuba/core/fresolver.h>
+#include <mitsuba/core/logger.h>
 #include <sstream>
 #include <algorithm>
 
@@ -21,10 +22,15 @@ bool FileResolver::contains(const fs::path &p) const {
 
 fs::path FileResolver::resolve(const fs::path &path) const {
     if (!path.is_absolute()) {
+        Log(Debug, "Looking for file \"%s\" on the resource search path(s)", path.native());
         for (auto const &base : m_paths) {
             fs::path combined = base / path;
-            if (fs::exists(combined))
+            if (fs::exists(combined)) {
+                Log(Trace, "Found file \"%s\" at %s", path.native(), combined.native());
                 return combined;
+            } else {
+                Log(Trace, "Didn't find file \"%s\" at %s", path.native(), combined.native());
+            }
         }
     }
     return path;

src/core/plugin.cpp

@@ -113,7 +113,7 @@ struct PluginManager::PluginManagerPrivate {
         fs::path resolved = resolver->resolve(filename);
 
         if (fs::exists(resolved)) {
-            Log(Debug, "Loading plugin \"%s\" ..", filename.string());
+            Log(Debug, "Loading plugin \"%s\" from \"%s\" ..", name, resolved.string());
             Plugin *plugin = new Plugin(resolved);
             // New classes must be registered within the class hierarchy
             Class::static_initialization();

src/core/spectrum.cpp

@@ -13,9 +13,9 @@ void spectrum_from_file(const fs::path &path, std::vector<Scalar> &wavelengths,
     auto fs = Thread::thread()->file_resolver();
     fs::path file_path = fs->resolve(path);
     if (!fs::exists(file_path))
-        Log(Error, "\"%s\": file does not exist!", file_path);
+        Log(Error, "\"%s\": file does not exist!", file_path.string());
 
-    Log(Info, "Loading spectral data file \"%s\" ..", file_path);
+    Log(Info, "Loading spectral data file \"%s\" ..", file_path.string());
     std::string extension = string::to_lower(file_path.extension().string());
     if (extension == ".spd") {
         ref<MemoryMappedFile> mmap = new MemoryMappedFile(file_path, false);

src/core/tensor.cpp

@@ -21,7 +21,7 @@ TensorFile::TensorFile(const fs::path &filename)
         Throw("Invalid tensor file: unknown file version.");
 
     Log(Info, "Loading tensor data from \"%s\" .. (%s, %i field%s)",
-        filename.filename(), util::mem_string(stream->size()), n_fields,
+        filename.string(), util::mem_string(stream->size()), n_fields,
         n_fields > 1 ? "s" : "");
 
     for (uint32_t i = 0; i < n_fields; ++i) {

src/emitters/envmap.cpp

@@ -108,7 +108,7 @@ class EnvironmentMapEmitter final : public Emitter<Float, Spectrum> {
         ref<Bitmap> bitmap = new Bitmap(file_path);
         if (bitmap->width() < 2 || bitmap->height() < 3)
             Throw("\"%s\": the environment map resolution must be at "
-                  "least 2x3 pixels", m_filename);
+                  "least 2x3 pixels", file_path.string());
 
         /* Convert to linear RGBA float bitmap, will undergo further
            conversion into coefficients of a spectral upsampling model below */

src/render/srgb.cpp

@@ -19,10 +19,12 @@ dr::Array<float, 3> srgb_model_fetch(const Color<float, 3> &c) {
         if (model == nullptr) {
             FileResolver *fr = Thread::thread()->file_resolver();
             std::string fname = fr->resolve("data/srgb.coeff").string();
-            Log(Info, "Loading spectral upsampling model \"data/srgb.coeff\" .. ");
+            if (!fs::exists(fname))
+                Throw("Could not find sRGB-to-spectrum upsampling model (\"data/srgb.coeff\")");
+            Log(Info, "Loading spectral upsampling model \"%s\" .. ", fname);
             model = rgb2spec_load(fname.c_str());
             if (model == nullptr)
-                Throw("Could not load sRGB-to-spectrum upsampling model ('data/srgb.coeff')");
+                Throw("Could not load sRGB-to-spectrum upsampling model (\"%s\")", fname);
             atexit([]{ rgb2spec_free(model); });
         }
     }

src/shapes/obj.cpp

@@ -155,10 +155,10 @@ class OBJMesh final : public Mesh<Float, Spectrum> {
 
         auto fail = [&](const char *descr, auto... args) {
             Throw(("Error while loading OBJ file \"%s\": " + std::string(descr))
-                      .c_str(), m_name, args...);
+                      .c_str(), file_path.string(), args...);
         };
 
-        Log(Debug, "Loading mesh from \"%s\" ..", m_name);
+        Log(Debug, "Loading mesh from \"%s\" ..", file_path.string());
         if (!fs::exists(file_path))
             fail("file not found");
 
@@ -378,7 +378,7 @@ class OBJMesh final : public Mesh<Float, Spectrum> {
             vertex_data_bytes += 2 * sizeof(InputFloat);
 
         Log(Debug, "\"%s\": read %i faces, %i vertices (%s in %s)",
-            m_name, m_face_count, m_vertex_count,
+            file_path.string(), m_face_count, m_vertex_count,
             util::mem_string(m_face_count * 3 * sizeof(ScalarIndex) +
                              m_vertex_count * vertex_data_bytes),
             util::time_string((float) timer.value())
@@ -387,7 +387,7 @@ class OBJMesh final : public Mesh<Float, Spectrum> {
         if (!m_face_normals && normals.empty()) {
             Timer timer2;
             recompute_vertex_normals();
-            Log(Debug, "\"%s\": computed vertex normals (took %s)", m_name,
+            Log(Debug, "\"%s\": computed vertex normals (took %s)", file_path.string(),
                 util::time_string((float) timer2.value()));
         }
 

src/shapes/ply.cpp

@@ -170,10 +170,10 @@ class PLYMesh final : public Mesh<Float, Spectrum> {
         m_name = file_path.filename().string();
 
         auto fail = [&](const char *descr) {
-            Throw("Error while loading PLY file \"%s\": %s!", m_name, descr);
+            Throw("Error while loading PLY file \"%s\": %s!", file_path.string(), descr);
         };
 
-        Log(Debug, "Loading mesh from \"%s\" ..", m_name);
+        Log(Debug, "Loading mesh from \"%s\" ..", file_path.string());
         if (!fs::exists(file_path))
             fail("file not found");
 
@@ -189,7 +189,7 @@ class PLYMesh final : public Mesh<Float, Spectrum> {
                     Log(Warn,
                         "\"%s\": performance warning -- this file uses the ASCII PLY format, which "
                         "is slow to parse. Consider converting it to the binary PLY format.",
-                        m_name);
+                        file_path.string());
                 stream = parse_ascii((FileStream *) stream.get(), header.elements);
             }
         } catch (const std::exception &e) {
@@ -417,7 +417,7 @@ class PLYMesh final : public Mesh<Float, Spectrum> {
 
                 m_faces = dr::load<DynamicBuffer<UInt32>>(faces.get(), m_face_count * 3);
             } else {
-                Log(Warn, "\"%s\": skipping unknown element \"%s\"", m_name, el.name);
+                Log(Warn, "\"%s\": skipping unknown element \"%s\"", file_path.string(), el.name);
                 stream->seek(stream->tell() + el.struct_->size() * el.count);
             }
         }
@@ -426,7 +426,7 @@ class PLYMesh final : public Mesh<Float, Spectrum> {
             fail("invalid file -- trailing content");
 
         Log(Debug, "\"%s\": read %i faces, %i vertices (%s in %s)",
-            m_name, m_face_count, m_vertex_count,
+            file_path.string(), m_face_count, m_vertex_count,
             util::mem_string(m_face_count * face_struct->size() +
                              m_vertex_count * vertex_struct->size()),
             util::time_string((float) timer.value())
@@ -435,7 +435,7 @@ class PLYMesh final : public Mesh<Float, Spectrum> {
         if (!m_face_normals && !has_vertex_normals) {
             Timer timer2;
             recompute_vertex_normals();
-            Log(Debug, "\"%s\": computed vertex normals (took %s)", m_name,
+            Log(Debug, "\"%s\": computed vertex normals (took %s)", file_path.string(),
                 util::time_string((float) timer2.value()));
         }
 

src/shapes/serialized.cpp

@@ -235,12 +235,13 @@ class SerializedMesh final : public Mesh<Float, Spectrum> {
     }
 
     SerializedMesh(const Properties &props) : Base(props) {
+        auto fs = Thread::thread()->file_resolver();
+        fs::path file_path = fs->resolve(props.string("filename"));
+
         auto fail = [&](const std::string &descr) {
-            Throw("Error while loading serialized file \"%s\": %s!", m_name, descr);
+            Throw("Error while loading serialized file \"%s\": %s!", file_path.string(), descr);
         };
 
-        auto fs = Thread::thread()->file_resolver();
-        fs::path file_path = fs->resolve(props.string("filename"));
         m_name = file_path.filename().string();
 
         Log(Debug, "Loading mesh from \"%s\" ..", m_name);

src/textures/bitmap.cpp

@@ -138,7 +138,7 @@ class BitmapTexture final : public Texture<Float, Spectrum> {
             FileResolver* fs = Thread::thread()->file_resolver();
             fs::path file_path = fs->resolve(props.string("filename"));
             m_name = file_path.filename().string();
-            Log(Debug, "Loading bitmap texture from \"%s\" ..", m_name);
+            Log(Debug, "Loading bitmap texture from \"%s\" ..", file_path.string());
             m_bitmap = new Bitmap(file_path);
         }