fix relative dependent filenames in bam cache

panda/src/pgraph/loader.cxx

@@ -274,6 +274,10 @@ try_load_file(const Filename &pathname, const LoaderOptions &options,
       PT(PandaNode) node = ModelPool::load_model(pathname, options);
       if (node != (PandaNode *)NULL &&
           (options.get_flags() & LoaderOptions::LF_allow_instance) == 0) {
+        if (loader_cat.is_debug()) {
+          loader_cat.debug()
+            << "Model " << pathname << " found in ModelPool.\n";
+        }
         // But return a deep copy of the shared model.
         node = node->copy_subgraph();
       }
@@ -281,7 +285,7 @@ try_load_file(const Filename &pathname, const LoaderOptions &options,
     }
   }
 
-  bool report_errors = (options.get_flags() & LoaderOptions::LF_report_errors) != 0;
+  bool report_errors = ((options.get_flags() & LoaderOptions::LF_report_errors) != 0 || loader_cat.is_debug());
 
   PT(BamCacheRecord) record;
   if (cache->get_cache_models() && requested_type->get_allow_disk_cache(options)) {
@@ -309,6 +313,11 @@ try_load_file(const Filename &pathname, const LoaderOptions &options,
       }
     }
   }
+
+  if (loader_cat.is_debug()) {
+    loader_cat.debug()
+      << "Model " << pathname << " not found in cache.\n";
+  }
   
   if (!cache_only) {
     PT(PandaNode) result = requested_type->load_file(pathname, options, record);

panda/src/putil/bamCache.cxx

@@ -805,15 +805,28 @@ read_record(const Filename &source_pathname,
   
   if (!cache_pathname.exists()) {
     // There is no such cache file already.  Declare it.
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << "Declaring new cache file " << cache_pathname << " for " << source_pathname << "\n";
+    }
     PT(BamCacheRecord) record =
       new BamCacheRecord(source_pathname, cache_filename);
     record->_cache_pathname = cache_pathname;
     return record;
   }
 
+  if (util_cat.is_debug()) {
+    util_cat.debug()
+      << "Reading cache file " << cache_pathname << " for " << source_pathname << "\n";
+  }
+
   PT(BamCacheRecord) record = do_read_record(cache_pathname, true);
   if (record == (BamCacheRecord *)NULL) {
     // Well, it was invalid, so blow it away, and make a new one.
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << "Deleting invalid cache file " << cache_pathname << "\n";
+    }
     vfs->delete_file(cache_pathname);
     remove_from_index(source_pathname);
 
@@ -825,10 +838,12 @@ read_record(const Filename &source_pathname,
 
   if (record->get_source_pathname() != source_pathname) {
     // This might be just a hash conflict.
-    util_cat.debug()
-      << "Cache file " << cache_pathname << " references "
-      << record->get_source_pathname() << ", not "
-      << source_pathname << "\n";
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << "Cache file " << cache_pathname << " references "
+        << record->get_source_pathname() << ", not "
+        << source_pathname << "\n";
+    }
     return NULL;
   }
 
@@ -850,21 +865,27 @@ PT(BamCacheRecord) BamCache::
 do_read_record(const Filename &cache_pathname, bool read_data) {
   DatagramInputFile din;
   if (!din.open(cache_pathname)) {
-    util_cat.debug()
-      << "Could not read cache file: " << cache_pathname << "\n";
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << "Could not read cache file: " << cache_pathname << "\n";
+    }
     return NULL;
   }
   
   string head;
   if (!din.read_header(head, _bam_header.size())) {
-    util_cat.debug()
-      << cache_pathname << " is not a cache file.\n";
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << cache_pathname << " is not a cache file.\n";
+    }
     return NULL;
   }
   
   if (head != _bam_header) {
-    util_cat.debug()
-      << cache_pathname << " is not a cache file.\n";
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << cache_pathname << " is not a cache file.\n";
+    }
     return NULL;
   }
   
@@ -875,21 +896,27 @@ do_read_record(const Filename &cache_pathname, bool read_data) {
   
   TypedWritable *object = reader.read_object();
   if (object == (TypedWritable *)NULL) {
-    util_cat.debug()
-      << cache_pathname << " is empty.\n";
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << cache_pathname << " is empty.\n";
+    }
     return NULL;
     
   } else if (!object->is_of_type(BamCacheRecord::get_class_type())) {
-    util_cat.debug()
-      << "Cache file " << cache_pathname << " contains a "
-      << object->get_type() << ", not a BamCacheRecord.\n";
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << "Cache file " << cache_pathname << " contains a "
+        << object->get_type() << ", not a BamCacheRecord.\n";
+    }
     return NULL;
   }
   
   PT(BamCacheRecord) record = DCAST(BamCacheRecord, object);
   if (!reader.resolve()) {
-    util_cat.debug()
-      << "Unable to fully resolve cache record in " << cache_pathname << "\n";
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << "Unable to fully resolve cache record in " << cache_pathname << "\n";
+    }
     return NULL;
   }
 
@@ -906,8 +933,10 @@ do_read_record(const Filename &cache_pathname, bool read_data) {
 
     if (reader.read_object(ptr, ref_ptr)) {
       if (!reader.resolve()) {
-        util_cat.debug()
-          << "Unable to fully resolve cached object in " << cache_pathname << "\n";
+        if (util_cat.is_debug()) {
+          util_cat.debug()
+            << "Unable to fully resolve cached object in " << cache_pathname << "\n";
+        }
         delete object;
       } else {
         // The object is valid.  Store it in the record.

panda/src/putil/bamCacheRecord.cxx

@@ -94,6 +94,11 @@ bool BamCacheRecord::
 dependents_unchanged() const {
   VirtualFileSystem *vfs = VirtualFileSystem::get_global_ptr();
 
+  if (util_cat.is_debug()) {
+    util_cat.debug()
+      << "Validating dependents for " << get_source_pathname() << "\n";
+  }
+
   DependentFiles::const_iterator fi;
   for (fi = _files.begin(); fi != _files.end(); ++fi) {
     const DependentFile &dfile = (*fi);
@@ -101,17 +106,34 @@ dependents_unchanged() const {
     if (file == (VirtualFile *)NULL) {
       // No such file.
       if (dfile._timestamp != 0) {
+        if (util_cat.is_debug()) {
+          util_cat.debug()
+            << dfile._pathname << " does not exist.\n";
+        }
         return false;
       }
     } else {
       if (file->get_timestamp() != dfile._timestamp ||
           file->get_file_size() != dfile._size) {
         // File has changed timestamp or size.
+        if (util_cat.is_debug()) {
+          util_cat.debug()
+            << dfile._pathname << " has changed timestamp or size.\n";
+        }
         return false;
       }
     }
     
     // Presumably, the file is unchanged.
+    if (util_cat.is_debug()) {
+      util_cat.debug()
+        << dfile._pathname << " is unchanged.\n";
+    }
+  }
+
+  if (util_cat.is_debug()) {
+    util_cat.debug()
+      << "Dependents valid.\n";
   }
 
   return true;
@@ -145,8 +167,9 @@ add_dependent_file(const Filename &pathname) {
   _files.push_back(DependentFile());
   DependentFile &dfile = _files.back();
   dfile._pathname = pathname;
+  dfile._pathname.make_absolute();
 
-  PT(VirtualFile) file = vfs->get_file(pathname);
+  PT(VirtualFile) file = vfs->get_file(dfile._pathname);
   if (file == (VirtualFile *)NULL) {
     // No such file.
     dfile._timestamp = 0;