Phase 2 takes too much time to complete

[Roberto Natella <rnatella@gmail.com>]

[-- Attachment #1: Type: text/plain, Size: 2570 bytes --]

Dear SystemTap developers,
I noticed that compile time for a non-cached module greatly increased
since SystemTap snapshot 20070721.
On my system (RHEL4 with 2.6.25 kernel; dual Intel Xeon(TM) CPU
2.80GHz with HT; 5 GB RAM), phase 2
takes about half an hour to complete. This problem also occurs in
SystemTap 0.8 and in most recent snapshots.
Using strace, I found that stap spends most of time for generating the
header "stap-symbols.h" in function
dump_unwindsyms() (in translate.cxx). Here it is the "guilty" code:

  // Add unwind data to be included if it exists for this module.
  size_t len = 0;
  void *unwind = get_unwind_data (m, &len);
  if (unwind != NULL)
    {
      c->output << "#ifdef STP_USE_DWARF_UNWINDER" << endl;
      c->output << "static uint8_t _stp_module_" << stpmod_idx
        << "_unwind_data[] = " << endl;
      c->output << "  {";
      for (size_t i = 0; i < len; i++)
    {
      int h = ((uint8_t *)unwind)[i];
      c->output << "0x" << hex << h << dec << ",";
      if ((i + 1) % 16 == 0)
        c->output << endl << "   ";
    }
      c->output << "};" << endl;
      c->output << "#endif /* STP_USE_DWARF_UNWINDER */" << endl;
    }

and

  for (unsigned secidx = 0; secidx < seclist.size(); secidx++)
    {
      c->output << "struct _stp_symbol "
                << "_stp_module_" << stpmod_idx<< "_symbols_" <<
secidx << "[] = {" << endl;

      // We write out a *sorted* symbol table, so the runtime doesn't
have to sort them later.
      for (addrmap_t::iterator it = addrmap[secidx].begin(); it !=
addrmap[secidx].end(); it++)
        {
          if (it->first < extra_offset)
            continue; // skip symbols that occur before our chosen base address

          c->output << "  { 0x" << hex << it->first-extra_offset << dec
                    << ", " << lex_cast_qstring (it->second) << " }," << endl;
        }
      c->output << "};" << endl;
    }

As far as I know, the "stap-symbols.h" file contains the list of
kernel symbols (preliminarly ordered by name)
in order to speed-up symbol resolution at run-time. Because the symbol
list remains the same if the kernel
is unchanged, I think that stap-symbols.h should be cached in order to
speed up phase 2. You can find a
very simple patch I made on SystemTap 0.8 which caches stap-symbols.h
into ~/.systemtap
(it only takes into account the modification time of
/boot/vmlinux-VERSION, so it can be greatly improved).
Please consider the addition of caching mechanisms for stap-symbols.h
in future releases of SystemTap.
Thank you for your support
Roberto Natella

[-- Attachment #2: cache_unwind_symbols.patch --]
[-- Type: application/octet-stream, Size: 1570 bytes --]

diff -uNr systemtap-0.8-old/translate.cxx systemtap-0.8-new/translate.cxx
--- systemtap-0.8-old/translate.cxx	2008-11-13 21:29:23.000000000 +0100
+++ systemtap-0.8-new/translate.cxx	2009-01-26 17:18:05.000000000 +0100
@@ -28,6 +28,10 @@
 #include <elfutils/libdwfl.h>
 }
 
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <unistd.h>
+
 using namespace std;
 
 struct var;
@@ -4645,12 +4649,39 @@
 void
 emit_symbol_data (systemtap_session& s)
 {
+  /*
   string symfile = "stap-symbols.h";
 
   s.op->newline() << "#include " << lex_cast_qstring (symfile);
 
   ofstream kallsyms_out ((s.tmpdir + "/" + symfile).c_str());
+  */
 
+  string kernel_image = string("/boot/vmlinux-")+s.kernel_release;
+  struct stat stat_kernel_image;
+  stat(kernel_image.c_str(), &stat_kernel_image);
+
+  char last_modification[40];
+  sprintf(last_modification, "%lld", (long long int) stat_kernel_image.st_mtime);
+  
+  string symfile = string("stap-symbols-") + s.kernel_release.c_str() + "-" + string(last_modification) + ".h";
+  
+  string symbols_dir = s.data_path + "/symbols";
+  
+  string symfile_path = symbols_dir + "/" + symfile;
+    
+  s.op->newline() << "#include " << lex_cast_qstring (symfile_path.c_str());
+
+  if(create_dir(symbols_dir.c_str()) == 0) {
+  	struct stat stat_cached_sym;
+
+  	if(stat(symfile_path.c_str(), &stat_cached_sym) == 0) {
+		return;
+	}
+  }
+  
+  ofstream kallsyms_out (symfile_path.c_str());
+  
   unwindsym_dump_context ctx = { s, kallsyms_out, 0, s.unwindsym_modules };
 
   // XXX: copied from tapsets.cxx dwflpp::, sadly