PR9931: generate log to help diagnosing occasional cache hash collisions

Ideas from Frank Ch. Eigler:
- extending the hash.add() function to pass names along with the
  hash-mix values, so that class hash can internally track the
  hash-report string
- storing the reports themselves in the cache, beside the .ko / .c
  files, and changing the cache-size-limit logic to delete
  these .txt files upon garbage collection

* hash.h : New member parm_stream.
* hash.cxx (get_parms): New function to convert parms stream to string.
  (hash::add): Aggregrate parms stream.
  (create_hash_log): New function to log hash operation.
  (find_*_hash): Log hash at the end of function.
* cache.cxx (clean_cache): Remove log when cache reaches limitation.

3 files changed, 58 insertions, 0 deletions

diff --git a/cache.cxx b/cache.cxx
index 29c20d0d..b113e019 100644
--- a/cache.cxx
+++ b/cache.cxx
@@ -282,6 +282,22 @@ clean_cache(systemtap_session& s)
 
       globfree(&cache_glob);
 
+      // grab info for each staphash log file (.log)
+      glob_str = s.cache_path + "/*/*.log";
+      glob(glob_str.c_str(), 0, NULL, &cache_glob);
+      for (unsigned int i = 0; i < cache_glob.gl_pathc; i++)
+        {
+          string cache_ent_path = cache_glob.gl_pathv[i];
+          struct cache_ent_info cur_info(cache_ent_path, false);
+          if (cur_info.size != 0 && cur_info.weight != 0)
+            {
+              cache_size_b += cur_info.size;
+              cache_contents.insert(cur_info);
+            }
+        }
+
+      globfree(&cache_glob);
+
       set<struct cache_ent_info>::iterator i;
       unsigned long r_cache_size = cache_size_b;
       string removed_dirs = "";
@@ -344,9 +360,11 @@ cache_ent_info::cache_ent_info(const string& path, bool is_module):
       string mod_path    = path + ".ko";
       string modsgn_path = path + ".ko.sgn";
       string source_path = path + ".c";
+      string hash_path = path + ".log";
       size = get_file_size(mod_path)
         + get_file_size(modsgn_path);
         + get_file_size(source_path);
+        + get_file_size(hash_path);
       weight = get_file_weight(mod_path);
     }
   else
@@ -365,9 +383,11 @@ cache_ent_info::unlink() const
       string mod_path    = path + ".ko";
       string modsgn_path = path + ".ko.sgn";
       string source_path = path + ".c";
+      string hash_path = path + ".log";
       ::unlink(mod_path.c_str());
       ::unlink(modsgn_path.c_str());
       ::unlink(source_path.c_str());
+      ::unlink(hash_path.c_str());
     }
   else
     ::unlink(path.c_str());
diff --git a/hash.cxx b/hash.cxx
index a4589577..8664bb63 100644
--- a/hash.cxx
+++ b/hash.cxx
@@ -43,6 +43,7 @@ hash::start()
 void
 hash::add(const unsigned char *buffer, size_t size)
 {
+  parm_stream << "," << buffer;
   mdfour_update(&md4, buffer, size);
 }
 
@@ -60,6 +61,16 @@ hash::add_file(const std::string& filename)
   add(st.st_mtime);
 }
 
+string
+hash::get_parms()
+{
+ string parms_str = parm_stream.str();
+
+ parm_stream.clear();
+ if (!parms_str.empty())
+   parms_str.erase(parms_str.begin()); // skip leading ","
+ return parms_str;
+}
 
 void
 hash::result(string& r)
@@ -78,6 +89,20 @@ hash::result(string& r)
   r = rstream.str();
 }
 
+void create_hash_log(const string &type_str, const string &parms, const string &result, const string &hash_log_path)
+{
+  ofstream log_file;
+  time_t rawtime;
+  time ( &rawtime );
+  string time_str(ctime (&rawtime));
+
+  log_file.open(hash_log_path.c_str());
+  log_file << "[" << time_str.substr(0,time_str.length()-1); // erase terminated '\n'
+  log_file << "]" << type_str;
+  log_file << ": " << parms << endl;
+  log_file << "result:" << result << endl;
+  log_file.close();
+}
 
 static void
 get_base_hash (systemtap_session& s, hash& h)
@@ -229,6 +254,8 @@ find_script_hash (systemtap_session& s, const string& script, const hash &base)
 
   // Update C source name with new module_name.
   s.translated_source = string(s.tmpdir) + "/" + s.module_name + ".c";
+  create_hash_log(string("script_hash"), h.get_parms(), result,
+                  hashdir + "/" + s.module_name + "_hash.log");
 }
 
 
@@ -249,6 +276,8 @@ find_stapconf_hash (systemtap_session& s, const hash& base)
 
   s.stapconf_name = "stapconf_" + result + ".h";
   s.stapconf_path = hashdir + "/" + s.stapconf_name;
+  create_hash_log(string("stapconf_hash"), h.get_parms(), result,
+                  hashdir + "/stapconf_" + result + "_hash.log");
 }
 
 
@@ -282,6 +311,8 @@ find_tracequery_hash (systemtap_session& s, const vector<string>& headers)
   if (!create_hashdir(s, result, hashdir))
     return "";
 
+  create_hash_log(string("tracequery_hash"), h.get_parms(), result,
+                  hashdir + "/tracequery_" + result + "_hash.log");
   return hashdir + "/tracequery_" + result + ".ko";
 }
 
@@ -306,6 +337,8 @@ find_typequery_hash (systemtap_session& s, const string& name)
   if (!create_hashdir(s, result, hashdir))
     return "";
 
+  create_hash_log(string("typequery_hash"), h.get_parms(), result,
+                  hashdir + "/typequery_" + result + "_hash.log");
   return hashdir + "/typequery_" + result
     + (name[0] == 'k' ? ".ko" : ".so");
 }
diff --git a/hash.h b/hash.h
index 6bb1c78a..173f8e51 100644
--- a/hash.h
+++ b/hash.h
@@ -1,5 +1,7 @@
 #include <string>
 #include <vector>
+#include <sstream>
+#include <fstream>
 
 extern "C" {
 #include <string.h>
@@ -13,9 +15,11 @@ class hash
 {
 private:
   struct mdfour md4;
+  std::ostringstream parm_stream;
 
 public:
   hash() { start(); }
+  hash(const hash &base) { start(); parm_stream << base.parm_stream.str();}
 
   void start();
 
@@ -34,6 +38,7 @@ public:
   void add_file(const std::string& filename);
 
   void result(std::string& r);
+  std::string get_parms();
 };
 
 void find_hash (systemtap_session& s, const std::string& script);