I just started working at Trampoline Systems yesterday. Some of you might know my blog already (the one with kitten pics and programming rants). The first thing I did was configuring all the software on my new MacBook. Most of it went all right without any problems, but a few gems didn’t want to install, complaining about jni.h missing. jni.h was on the box, so the problem was basically that the gems were looking for it in a wrong place. Problems like that can usually be solved by strace -e trace=file gem install whatever | grep 'jni.h' and a symlink. Not this time, because Macs does have strace. There’s something called ktrace, but it didn’t seem to provide information I needed.
Full strace may be impossible without heave kernel hacking, but it’s not hard to write a simple file access tracing utility. The one I coded uses LD_PRELOAD-like trick to override open and stat functions in libc. These two usually provide most of the usuful information about file access, and if anything more was needed the utility can be easily extended.
The library is very simple:
#include <unistd.h>
#include <stdio.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <dlfcn.h>
#include <errno.h>
#include "errno_names.h"
/* Probably not thread-safe. I have no idea what's thread-interpretation of
dlsym(RTLD_NEXT, ...), even assuming atomic assignment to variables
*/
int (*real_open)(const char *path, int flags, mode_t mode) = 0;
int (*real_stat)(const char *path, struct stat *sb) = 0;
void report_errno(int retval)
{
if(retval == -1 && errno >= 0 && errno <= ELAST) {
fprintf(stderr, " (%s)n", errno_names_table[errno]);
} else {
fprintf(stderr, "n");
}
}
int open(const char *path, int flags, mode_t mode)
{
int retval;
if(real_open == 0)
real_open = dlsym(RTLD_NEXT, "open");
retval = real_open(path, flags, mode);
fprintf(stderr, "open("%s", ...) = %d", path, retval);
report_errno(retval);
return retval;
}
int stat(const char *path, struct stat *sb)
{
int retval;
if(real_stat == 0)
real_stat = dlsym(RTLD_NEXT, "stat");
retval = real_stat(path, sb);
fprintf(stderr, "stat("%s", ...) = %d", path, retval);
report_errno(retval);
return retval;
}
Fist of error names in errno_names.h is generated by Rakefile, which looks like that (stripping the testing-related parts):
desc "Build trace_file_access library"
task :build => "libtfa.dylib"
file "libtfa.dylib" => ["errno_names.h", "libtfa.c"] do
sh "gcc", "-O6", "libtfa.c", "-dynamiclib", "-fPIC", "-o", "libtfa.dylib"
end
file "errno_names.h" do
errnos = []
File.open("/usr/include/sys/errno.h").each{|line|
errnos[$2.to_i] = $1 if line =~ /A#defines+(E[A-Z]+)s+(d+)/
}
File.open("errno_names.h", "w") {|fh|
fh.puts "/*n * This code is automatically generated by the Rakefilen * Do not modify by handn */"
fh.puts "static const char *errno_names_table [] = {"
errnos.each_with_index{|name, i|
fh.puts " "#{name}", /* #{i} */"
}
fh.puts "};"
}
end
Finally trace_file_access command script sets up the tracing, with the results looking like this: #!/usr/bin/env ruby
ENV["DYLD_FORCE_FLAT_NAMESPACE"] = "1"
ENV["DYLD_INSERT_LIBRARIES"] = "./libtfa.dylib"
exec *ARGV
$ ./trace_file_access ruby -e 'require "rational"'
open("/dev/urandom", ...) = 3
stat("/opt/local/lib/ruby/site_ruby/1.8/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/site_ruby/1.8/rational.bundle", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/site_ruby/1.8/i686-darwin8.9.3/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/site_ruby/1.8/i686-darwin8.9.3/rational.bundle", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/site_ruby/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/site_ruby/rational.bundle", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/1.8/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/1.8/rational.bundle", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/1.8/i686-darwin8.9.3/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/1.8/i686-darwin8.9.3/rational.bundle", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/rational.bundle", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/1.8/rational.rb", ...) = 0
open("/opt/local/lib/ruby/1.8/rational.rb", ...) = 3
stat("/opt/local/lib/ruby/site_ruby/1.8/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/site_ruby/1.8/i686-darwin8.9.3/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/site_ruby/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/1.8/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/1.8/i686-darwin8.9.3/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/vendor_ruby/rational.rb", ...) = -1 (ENOENT)
stat("/opt/local/lib/ruby/1.8/rational.rb", ...) = 0
open("/opt/local/lib/ruby/1.8/rational.rb", ...) = 3
open("/opt/local/lib/ruby/1.8/rational.rb", ...) = 3
open("/opt/local/lib/ruby/1.8/rational.rb", ...) = 3
open("/opt/local/lib/ruby/1.8/rational.rb", ...) = 3
However, he’s the only person to have committed between 1am and 2am!