Rather than alchemy, methodical troubleshooting

 

I recently encountered a pesky problem while trying to build a React Native project under Apple’s Xcode. The build would fail with an error reporting: EMFILE: too many open files, watch. Frustratingly, all available advice on the web pointed to different (often inexplicable) directions, none of which worked. After tormenting myself with these, I decided to troubleshoot the problem methodically, which allowed me to pinpoint it and solve it with an uncommon and noteworthy application of the git bisect command. Here’s the story.

A Google search for EMFILe xcode returns 49,000 results with many inexplicable and conflicting suggestions. These include the following.

  • Increasing the open files limit with ulimit, with launchctl, by modifying /etc/sysctl.conf, or by creating a plist file
  • Installing watchman
  • Reinstalling watchman
  • Upgrading watchman
  • Installing watchman using x86_64 brew
  • Reinstalling brew
  • Running watchman under Rosetta 2
  • Not running Xcode under Rosetta
  • Clearing the build files
  • Removing and reinstalling the node_modules files (classic)
  • Removing the cached Cocoa Pods and reinstalling them,
  • Excluding the arm64 architecture in the Xcode project’s build specifications
  • Using an earlier version of Node
  • Creating a symbolic link from /usr/local/var/run/watchman

Although advice from the web can often help us solve tough problems in seconds, as the author of the book Effective Debugging, I felt ashamed of wasting time by following increasingly nonsensical advice. I therefore decided to troubleshoot the issue methodically, even though my knowledge of Xcode and the macOS platform is very limited. My reasoning was that the top-down troubleshooting advice I give in the book can be applied to any problem.

My first step was to verify that the increased file limit I enforced by creating a /Library/LaunchDaemons/limit.maxfiles.plist file was visible to Xcode. For this I created a one-line shell script file containing open -a Terminal, and added this as a new Xcode “behavior” (Xcode - Behaviors). Running ulimit -n in the new terminal, showed me that Xcode’s environment was indeed running with an increased limit on open files. I further validated this by running a Perl command to create an array of open files until it was no longer possible.

perl -e 'for (;;) { open($a[++$i], "<", "/dev/null") || die "$!: $i"; }'
Too many open files in system: 61791 at -e line 1.

Having excluded the possibility of a low open file limit, my second step involved focusing on the failing command. This was a React Native bundling step, clearly visible on the Xcode build log. I pasted the command on a terminal window, and, surprisingly, it worked without a hitch. I also pasted the command on the Xcode terminal window I had created, and it worked there as well. This demonstrated that the reason of the failure was the environment in which the command was running.

My third step involved methodically determining how the command’s environment was causing its failure. The command was preceded by the setting of hundreds (488) of environment variables, starting with export ACTION=install and ending with export variant=normal. Which of these was causing the command’s failure?

The failing command took 23 seconds to execute, so iteratively adding each variable until the command would fail could take up to three hours. Instead, I used the git bisect command to binary search for the offending variable. The git bisect command is normally used to find which of a series of commits is responsible for a failure.

As I lacked such a series, I created a synthetic one for git bisect to run on. I started this process by exporting the Xcode log file, and editing it into a shell script. I then created a new Git branch in which I committed the script with all variables commented out, e.g. #export ACTION=install. This was the working commit. I then run a shell loop to reintroduce each variable and commit each result, thus creating a series of 488 commits (one for each introduced variable).

# Iterate while there are commented export lines
while grep -q '#export' xcode-bundle  ; do
  # Uncomment the first commented line
  sed -i .bak '1,/#export/s/^#//' xcode-bundle
  # Commit the result
  git commit -m 'Add export line' xcode-bundle
done

(If you want to find more about creating such commands, consider following my free edX MOOC Unix Tools: Data, Software and Production Engineering.) At the end of the loop the script was in its failing form.

I then provided to git bisect the first correct and the first failing commit, and left it running to find the one that caused the failure.

$ git bisect start
$ git bisect bad
$ git bisect good 6fec32ad0627ca1890a234982f08eb128ba9039a
Bisecting: 243 revisions left to test after this (roughly 8 steps)
$ git bisect run xcode-bundle
running xcode-bundle
[...]
Bisecting: 243 revisions left to test after this (roughly 8 steps)
Bisecting: 121 revisions left to test after this (roughly 7 steps)
Bisecting: 60 revisions left to test after this (roughly 6 steps)
Bisecting: 30 revisions left to test after this (roughly 5 steps)
Bisecting: 15 revisions left to test after this (roughly 4 steps)
Bisecting: 7 revisions left to test after this (roughly 3 steps)
Bisecting: 3 revisions left to test after this (roughly 2 steps)
Bisecting: 1 revision left to test after this (roughly 1 step)
Bisecting: 0 revisions left to test after this (roughly 0 steps)

879f283a7ea7cf92d9720c107aa34b90ee8f6451 is the first bad commit
bisect run success

A look at the offending bad commit, showed me that the problematic statement set the PATH environment variable. Running the previously working bundling command with the set PATH caused it to fail, validating the finding. Thanks to the binary search strategy of git bisect Git pinpointed the offending commit in just 9 rather than 488 steps, which took less than four minutes rather than hours.

I examined the two PATH variables and saw that, among other differences, the faulty PATH lacked the brew path /opt/homebrew/bin. Adding the brew path to the faulty PATH variable fixed the problem in the terminal window.

The last step involved fixing the issue in Xcode. For that I modified the shell script associated with the “Bundle React Native code and images” project’s build phase, adding a line to fix the path: export PATH="$PATH:/opt/homebrew/bin".

After wasting many hours with web-advice alchemy, I was able to fix the problem in less than an hour of methodical troubleshooting. Lesson learned!

Comments   Toot! Share


Last modified: Saturday, November 27, 2021 8:21 pm

Creative Commons Licence BY NC

Unless otherwise expressly stated, all original material on this page created by Diomidis Spinellis is licensed under a Creative Commons Attribution-NonCommercial 4.0 International License.