scm/git: prevent exec bomb with 'env :userpaths'

[UniqMartin]

• Have you followed the guidelines in our Contributing document?
• Have you checked to ensure there aren't other open Pull Requests for the same change?
• Have you added an explanation of what your changes do and why you'd like us to include them?
• Have you written new tests for your changes?
• Have you successfully ran brew tests with your changes locally?

---

Using git from Formula#install can cause a fork an exec bomb if used in a formula with env :userpaths because that causes both Library/ENV/4.3 and Library/ENV/scm to be in PATH, both of which contain a git binary that is the same SCM wrapper. Those will mutually fork exec each other indefinitely as they fail to detect that they are the same wrapper.

Extend the fork-bomb exec-bomb protection to check the paths after all symbolic links have been expanded to prevent this situation. (This incurs a small performance penalty because we need to rely on Pathname for Ruby 1.8.7 compatibility, but this wrapper isn't performance critical at all.)

Note: This must have happened in the past occasionally. Commit 8ca79a6 just made it much more likely to happen due to a subtle change. (And boost happens to be a formula that triggers this behavior.)

Fixes #43.
Fixes Homebrew/homebrew-core#133.

[apjanke]

Minor technical nitpick: it's not a fork bomb, because it's exec-ing without forking. That's not just a pedantic terminology niggle: it means you can't see the recursion in ps because there's only ever the one process (i.e. it's basically doing tail call optimization 😉), and if it were forking, eventually the fork bomb would cause resources to run out, one of the git calls would fail, and the build would proceed (just with incorrect output from the git call because we're not checking its return status). Made it harder to debug this.

I'll test this locally once I'm able to set up a local reproduction of the hang, but I probably can't give it a full thumbs-up even if it seems to work: I don't understand why this self-recursion is happening, and I don't really understand why this change would fix it. More importantly, I found that just adding a debugging call to the ENV/scm/git wrapper like this is also enough to fix it for me.

def logit(str)
  open("/Users/brew/Library/Logs/Homebrew/scm_git.log", "a") { |f|
    f.puts str
    f.flush
  }
end

logit "F: #{F} D: #{D}"

def exec(*args)
  # prevent fork-bombs

So I don't really know what's going on here.

[UniqMartin]

Minor technical nitpick: it's not a fork bomb, because it's exec-ing without forking. That's not just a pedantic terminology niggle: it means you can't see the recursion in ps because there's only ever the one process (i.e. it's basically doing tail call optimization 😉), […]

True; pardon my use of incorrect terminology. Should I fix my commit subject/message?

I don't understand why this self-recursion is happening, and I don't really understand why this change would fix it.

I tried to explain the scenario in my top comment. It's basically Libraray/ENV/4.3/git and Libraray/ENV/scm/git mutually exec-ing each other in this loop as they are both in PATH, not knowing that they are the same. (They don't invoke themselves because that's prevented by the fork-bomb protection in this part of the code.)

More importantly, I found that just adding a debugging call to the ENV/scm/git wrapper like this is also enough to fix it for me.

My guess would be that you tried running this with the sandbox enabled, so that the write to the log file would have killed the wrapper process due to a sandbox violation. (But could be something else; it's really just the first thing that comes to my mind.)

---

Here are step-by-step instructions to reproduce the issue locally before applying my fix:

1. Remove/unlink a brewed git as that will be in PATH and probably will prevent the bug from happening. Confirmed to happen if the wrapper is forced to fall back to /usr/bin/git (typical user installation) that is later resolved to the active developer directory.

2. Apply this patch to the main Homebrew repository (for debug output):

   diff --git i/Library/ENV/scm/git w/Library/ENV/scm/git
   index 05148339..019a57c6 100755
   --- i/Library/ENV/scm/git
   +++ w/Library/ENV/scm/git
   @@ -20,6 +20,10 @@ def exec(*args)
      # prevent fork-bombs
      arg0 = args.first
      return if arg0 =~ /^#{F}/i || File.expand_path(arg0) == File.expand_path(__FILE__)
   +  $stderr.puts caller
   +  $stderr.puts "-- arg0 = #{arg0} => #{File.expand_path(arg0)}"
   +  $stderr.puts "-- __FILE__ = #{__FILE__} => #{File.expand_path(__FILE__)}"
   +  $stderr.puts ">> #{args.inspect}"
      super
   end

3. Apply this patch to the xz formula (random choice, something that downloads and extracts quickly):

   diff --git i/Formula/xz.rb w/Formula/xz.rb
   index 1e27e044..a9908005 100644
   --- i/Formula/xz.rb
   +++ w/Formula/xz.rb
   @@ -16,7 +16,10 @@ class Xz < Formula
   
      option :universal
   
   +  env :userpaths
      def install
   +    puts ENV["PATH"].inspect
   +    system "git", "--version"
        ENV.universal_binary if build.universal?
        system "./configure", "--disable-debug",
                              "--disable-dependency-tracking",

4. Run brew install xz, abort after a few seconds (excerpt of output, shows PATH):

   […]
   "/opt/brewery/dummy/Library/ENV/4.3:/opt/brewery/dummy/bin:/usr/bin:/bin:/usr/sbin:/sbin:/opt/homebrew/Cellar/poison-ruby/1.0/bin::/usr/local/bin:/opt/brewery/dummy/Library/ENV/scm"
   ==> git --version
   […]
   

5. Inspect HOMEBREW_LOGS/xz/01.git. Its contents should be pretty convincing (excerpt):

   2016-04-07 23:05:36 +0200
   
   git
   --version
   
   /opt/brewery/dummy/Library/ENV/4.3/git:42:in `block in <main>'
   /opt/brewery/dummy/Library/ENV/4.3/git:41:in `each'
   /opt/brewery/dummy/Library/ENV/4.3/git:41:in `<main>'
   -- arg0 = /opt/brewery/dummy/Library/ENV/scm/git => /opt/brewery/dummy/Library/ENV/scm/git
   -- __FILE__ = /opt/brewery/dummy/Library/ENV/4.3/git => /opt/brewery/dummy/Library/ENV/4.3/git
   >> ["/opt/brewery/dummy/Library/ENV/scm/git", "--version"]
   /opt/brewery/dummy/Library/ENV/scm/git:42:in `block in <main>'
   /opt/brewery/dummy/Library/ENV/scm/git:41:in `each'
   /opt/brewery/dummy/Library/ENV/scm/git:41:in `<main>'
   -- arg0 = /opt/brewery/dummy/Library/ENV/4.3/git => /opt/brewery/dummy/Library/ENV/4.3/git
   -- __FILE__ = /opt/brewery/dummy/Library/ENV/scm/git => /opt/brewery/dummy/Library/ENV/scm/git
   >> ["/opt/brewery/dummy/Library/ENV/4.3/git", "--version"]
   /opt/brewery/dummy/Library/ENV/4.3/git:42:in `block in <main>'
   /opt/brewery/dummy/Library/ENV/4.3/git:41:in `each'
   /opt/brewery/dummy/Library/ENV/4.3/git:41:in `<main>'
   -- arg0 = /opt/brewery/dummy/Library/ENV/scm/git => /opt/brewery/dummy/Library/ENV/scm/git
   -- __FILE__ = /opt/brewery/dummy/Library/ENV/4.3/git => /opt/brewery/dummy/Library/ENV/4.3/git
   >> ["/opt/brewery/dummy/Library/ENV/scm/git", "--version"]
   […]
   

[apjanke]

TL;DR: 👍

Details:

True; pardon my use of incorrect terminology. Should I fix my commit subject/message?

Nah, it's close enough, and that's probably what people will search for anyway. Just wanted to get that in the history to help people who are trying to understand this or debug similar problems.

It's basically Libraray/ENV/4.3/git and Libraray/ENV/scm/git mutually exec-ing each other in this loop as they are both in PATH, not knowing that they are the same.

Ah. I understand now.

My guess would be that you tried running this with the sandbox enabled, so that the write to the log file would have killed the wrapper process due to a sandbox violation.

Okay, put these two together and I'm 90% convinced. I am running under the sandbox, and was logging to /Users/brew/Library/Logs/Homebrew/scm_git.log, which would have been denied. That's consistent with some of the git calls getting killed and fixing the hang.

Though when I ran test-bot like that, I was getting log output at that location, with a lot of git --version entries in it.

elcapitanvm-2:Homebrew brew$ pwd
/Users/brew/Library/Logs/Homebrew
elcapitanvm-2:Homebrew brew$ head log-01.txt
exec-ing /usr/local/Library/ENV/scm/git: ["/usr/local/Library/ENV/scm/git", "--version"]
exec-ing /usr/local/Library/ENV/scm/git: ["/usr/local/Library/ENV/scm/git", "--version"]
exec-ing /Applications/Xcode.app/Contents/Developer/usr/bin/git: ["/Applications/Xcode.app/Contents/Developer/usr/bin/git", "--version"]
exec-ing /usr/local/Library/ENV/scm/git: ["/usr/local/Library/ENV/scm/git", "--version"]
exec-ing /usr/local/Library/ENV/scm/git: ["/usr/local/Library/ENV/scm/git", "--version"]
exec-ing /Applications/Xcode.app/Contents/Developer/usr/bin/git: ["/Applications/Xcode.app/Contents/Developer/usr/bin/git", "--version"]
...

Probably enough git calls from outside sandboxed calls were getting recorded to produce the logs, and the ones run under it were getting denied. But now since I've read you say "sandbox", I'm not getting any logs there when attempting the same thing.

Probably just user error; I'll fiddle with it some more and see if I can figure out what I'm messing up, but this is consistent with your analysis.

Testing

I tested your PR locally with brew rm git and brew test-bot ... nginx which is known to hang here and reproduced locally. It fixed it.

I think this is the right fix. 👍

[apjanke]

Also fixes Homebrew/homebrew-core#143
Addresses the breakage encountered in Homebrew/homebrew-core#88

[apjanke]

Confirmed this works under Jenkins/test-bot with #46.

[MikeMcQuaid]

Nice work here, chaps.