Down the rabbit hole | Daniel Hepper

Sometimes you just want to install a piece of software and half an hour later, you find yourself digging through endless stacktraces. All I wanted to do is install Octopress, how hard can it be? Follow me on my journey down the rabbit hole.

I was quietly following along the Octopress setup instructions, cloning and installing like a pro, when suddenly:
$ bundle install Fetching gem metadata from http://rubygems.org/.......

ArgumentError: invalid byte sequence in UTF-8 An error occured while installing rake (0.9.2), and Bundler cannot continue. Make sure that `gem install rake -v '0.9.2'` succeeds before bundling.

Ah, a charset issue, one of my favorites. I put on my debugging hat and brace myself to add another couple of minutes to the endless amount of time that has collectively been wasted because mankind can’t agree on one charset.

Let’s see if I can install rake directly.

$ gem install rake -v '0.9.2' Successfully installed rake-0.9.2 1 gem installed Installing ri documentation for rake-0.9.2... Installing RDoc documentation for rake-0.9.2... (butfriendly_blog)danielhepper@:octopress$ mvim Gemfile (butfriendly_blog)danielhepper@:octopress$ bundle install Fetching gem metadata from http://rubygems.org/.......

Looks good, maybe bundle has something more to say:

$ bundle --verbose install Fetching gem metadata from http://rubygems.org/ Query List: ["rake", "RedCloth", "posix-spawn", "albino", "blankslate", "chunky_png", "fast-stemmer", "classifier", "fssm", "sass", "compass", "directory_watcher", "ffi", "haml", "kramdown", "liquid", "syntax", "maruku", "jekyll", "rubypython", "pygments.rb", "rack", "rb-fsevent", "rdiscount", "rubypants", "tilt", "sinatra", "stringex"] Query Gemcutter Dependency Endpoint API: rake RedCloth posix-spawn albino blankslate chunky_png fast-stemmer classifier fssm sass compass directory_watcher ffi haml kramdown liquid syntax maruku jekyll rubypython pygments.rb rack rb-fsevent rdiscount rubypants tilt sinatra stringex Fetching from: http://rubygems.org/api/v1/dependencies?gems=rake,RedCloth,posix-spawn,albino,blankslate,chunky_png,fast-stemmer,classifier,fssm,sass,compass,directory_watcher,ffi,haml,kramdown,liquid,syntax,maruku,jekyll,rubypython,pygments.rb,rack,rb-fsevent,rdiscount,rubypants,tilt,sinatra,stringex HTTP Success Query List: ["stemmer", "hoe", "open4", "rack-protection", "mongrel"] Query Gemcutter Dependency Endpoint API: stemmer hoe open4 rack-protection mongrel Fetching from: http://rubygems.org/api/v1/dependencies?gems=stemmer,hoe,open4,rack-protection,mongrel HTTP Success Query List: ["rubyforge", "gemcutter", "RubyInline", "escape_utils", "gem_plugin", "daemons", "cgi_multipart_eof_fix", "fastthread"] Query Gemcutter Dependency Endpoint API: rubyforge gemcutter RubyInline escape_utils gem_plugin daemons cgi_multipart_eof_fix fastthread Fetching from: http://rubygems.org/api/v1/dependencies?gems=rubyforge,gemcutter,RubyInline,escape_utils,gem_plugin,daemons,cgi_multipart_eof_fix,fastthread HTTP Success Query List: ["json_pure", "json", "net-scp", "ZenTest"] Query Gemcutter Dependency Endpoint API: json_pure json net-scp ZenTest Fetching from: http://rubygems.org/api/v1/dependencies?gems=json_pure,json,net-scp,ZenTest HTTP Success Query List: ["spruz", "net-ssh"] Query Gemcutter Dependency Endpoint API: spruz net-ssh Fetching from: http://rubygems.org/api/v1/dependencies?gems=spruz,net-ssh HTTP Success Query List: ["needle"] Query Gemcutter Dependency Endpoint API: needle Fetching from: http://rubygems.org/api/v1/dependencies?gems=needle HTTP Success Query List: [] Unmet Dependencies: []

ArgumentError: invalid byte sequence in UTF-8 An error occured while installing rake (0.9.2), and Bundler cannot continue. Make sure that `gem install rake -v '0.9.2'` succeeds before bundling. /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:94:in `rescue in install_gem_from_spec' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:68:in `install_gem_from_spec' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:56:in `block in run' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:55:in `run' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:12:in `install' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/cli.rb:220:in `install' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor/task.rb:22:in `run' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor/invocation.rb:118:in `invoke_task' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor.rb:263:in `dispatch' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor/base.rb:386:in `start' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/bin/bundle:13:in `<top (required)>' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/bin/bundle:19:in `load' /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/bin/bundle:19:in `<main>'

Sigh. I was reluctant to use Octopress because I didn’t want to code Ruby if I ever wanted to extend it. Now I’ll have to debug Ruby to even get it running. Still better than WordPress, I guess.

$ mvim /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb

    def install_gem_from_spec(spec, standalone = false)
      # Download the gem to get the spec, because some specs that are returned
      # by rubygems.org are broken and wrong.
      Bundler::Fetcher.fetch(spec) if spec.source.is_a?(Bundler::Source::Rubygems)
 
      # Fetch the build settings, if there are any
      settings = Bundler.settings["build.#{spec.name}"]
      Bundler.rubygems.with_build_args [settings] do
        spec.source.install(spec)
        Bundler.ui.debug "from #{spec.loaded_from} "
      end
 
      # newline comes after installing, some gems say "with native extensions"
      Bundler.ui.info ""
      if Bundler.settings[:bin]
        standalone ? generate_standalone_bundler_executable_stubs(spec) : generate_bundler_executable_stubs(spec)
      end
 
      FileUtils.rm_rf(Bundler.tmp)
    rescue Exception => e
      # install hook failed
      raise e if e.is_a?(Gem::InstallError)
 
      # other failure, likely a native extension build failure
      Bundler.ui.info ""
      Bundler.ui.warn "#{e.class}: #{e.message}"
      msg = "An error occured while installing #{spec.name} (#{spec.version}),"
      msg << " and Bundler cannot continue.\nMake sure that `gem install"
      msg << " #{spec.name} -v '#{spec.version}'` succeeds before bundling."
      raise Bundler::InstallError, msg
    end

Apparently, the root cause of the exception got swallowed in the rescue-block. This is the reason why it makes sense to reproduce the stacktrace of the original exception if you catch and reraise. Although that means you can’t make fun of the Java EE people with their stacktraces reaching to the moon and back.

Let’s comment out that rescue block and try again.

$ bundle --verbose install Fetching gem metadata from http://rubygems.org/ [...] Unfortunately, a fatal error has occurred. Please report this error to the Bundler issue tracker at https://github.com/carlhuda/bundler/issues so that we can fix it. Thanks! /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler.rb:254:in `split': invalid byte sequence in UTF-8 (ArgumentError) from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler.rb:254:in `which' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler.rb:233:in `requires_sudo?' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/fetcher.rb:28:in `download_gem_from_uri' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/fetcher.rb:19:in `fetch' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:68:in `install_gem_from_spec' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:56:in `block in run' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:55:in `run' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/installer.rb:12:in `install' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/cli.rb:220:in `install' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor/task.rb:22:in `run' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor/invocation.rb:118:in `invoke_task' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor.rb:263:in `dispatch' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler/vendor/thor/base.rb:386:in `start' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/bin/bundle:13:in `<top (required)>' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/bin/bundle:19:in `load' from /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/bin/bundle:19:in `<main>'

That could be the root of all evil, let’s have a look at line 254:

$ cat -n /Users/danielhepper/.rvm/gems/ruby-1.9.3-p125/gems/bundler-1.1.0/lib/bundler.rb | grep -a2 254 252 executable 253 else 254 path = ENV['PATH'].split(File::PATH_SEPARATOR).find { |path| 255 File.executable?(File.join(path, executable)) 256 }

Okay, so split complains about an invalid byte sequence in the PATH environment variable. Maybe I have one of those funny German umlauts in my PATH?

$ echo $PATH /opt/local/bin:/opt/local/sbin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:Vim?UnDo?:?w:?v:/usr/X11/bin:/usr/local/mysql/bin:/Users/danielhepper/bin:./node_modules/.bin:/Users/danielhepper/.rvm/bin:/Users/danielhepper/.rvm/bin

What the…? What is that crap in my PATH? And where does it come from?

Now, there are several places where the PATH variable gets manipulated on Mac OS X. One them is the directory /etc/paths.d.

$ ls -a /etc/paths.d . .. .60-MySQL.un~ 50-X11 60-MySQL $ cat /etc/paths.d/.60-MySQL.un~ 3?2W?1Oo?jH?)c?[???V7??I$g? ?w_?????O$

To say it with the words of Homer Simpson: D’Oh!

Let me explain. The content of all files in the directory /etc/paths.d gets added to the PATH environment variable. I added and edited a file for MySQL with Vim, my favorite editor, which also created an undelete file named .60-MySQL.un~. The binary gibberish from the undelete file got also added to PATH and caused bundler to choke.

And that marks the end of our journey. A sudo rm later, Octopress installed without any further hiccups.

Conclusion

Don’t get me wrong, this isn’t a rant against Octopress, bundler or Ruby (or, god forbid, Vim) by a Python fanboi. In fact, I cannot blame any of the software involved. bundler has the right to assume that the PATH is valid, although it made it a bit harder to find the issue because it swallowed the exception. It is questionable that Vim clutters the file system with undelete files, but keep in mind that I explicitly enabled that feature. One could blame Apple for including hidden files in /etc/paths.d when building the PATH.

But in the end, this is just another example of the First Rule of Programming: It’s always your fault.

It also serves to illustrate one of the reasons why Open Source rocks. Thanks to Open Source, I can have a look at the code and solve my problem. If I had the same issue in a closed source software, I would have been pretty much lost.

By the way, in the end I decided against using Octopress, mainly because I want the freedom to author blog posts from any browser. Now please excuse me while I go and fix my Vim config.

TL;DR

While installing Octopress, I got an “ArgumentError: invalid byte sequence in UTF-8” on bundle install. As it turns out, bundler choked on binary data in my $PATH, caused by a Vim undelete file in /etc/paths.d

Conclusion

TL;DR

One thought on “Down the rabbit hole”