Red Green Repeat Adventures of a Spec Driven Junkie

Adventures in Vagrant: tee

I am sharing another adventure in working with provisioning in Vagrant. I will go over a time where I debugged a slow nodejs installation and found a better way to collect screen output using tee.

If this article improves the way you work with the vagrant provisioner or any other UNIX command, then I have done my job. Using tee can help debug provisioning delay and/or errors by combing through files instead of screen output. This article will take less than four minutes of your time, probably less because there’s console output.

Petamenophis Relief source & more details

Introduction

From my last article, I use nvm to manage node, so the provisioning script would run nvm to install node (nvm install).

The installation progress stalled at 50% for a long time. I was kind of wondering: “Why?” and just assumed it was Wi-Fi. When a coworker saw the same thing on the company Internet connection, that made me think: “There is something going on here.”

tmux to the Rescue

Thanks to tmux, I was able to review the Vagrant provisioner output and saw:

default: (
default: -54): Error in the pull function.
default: Binary download from https://nodejs.org/dist/v12.8.1/node-v12.8.1-linux-x64.tar.xz failed, trying source.
default: grep: /home/vagrant/.nvm/.cache/bin/node-v12.8.1-linux-x64/node-v12.8.1-linux-x64.tar.xz
default: : No such file or directory
default: Provided file to checksum does not exist.
default: Binary download failed, trying source.
default: Detected that you have 2 CPU core(s)
default: Number of CPU core(s) less than or equal to 2, running in single-threaded mode
default: Downloading https://nodejs.org/dist/v12.8.1/node-v12.8.1.tar.xz...

This made think: Wow, two cores is not enough?! I decided: let’s add CPU cores to the virtual machine!

More CPU cores - faster downloads?!

The next time I ran the provisioner, there was no problem and downloaded immediately. Easy peasy!

This made me think: what else is happening in Vagrant provisioning stage that I am not catching??

Catching error Sooner?

One reason I’m not catching these errors: I can’t scroll back that far, especially as long output happens. When node installs, it’s verbose:

    default: #
    default: #
    default: ######################################################      94.6%
    default: #
    ...
    default: #
    default: #####################################################      95.3%
    default: #
    default: #
    default: ###################################################################### 100.0%
    default: Computing checksum with sha256sum
    default: Checksums matched!
    default: Now using node v12.9.1 (npm v6.10.2)
    default: Creating default alias: default -> node (-> v12.9.1 *)

I tune out when there is this amount of output and not at the computer when running vagrant up.

Solutions?

I was only able to catch the problem thanks to tmux. Are there better solutions?

  • Does nvm have a quiet option? nope.
  • Does keep_color option help preserve line formatting? nope.
  • Can I redirect output to a file (for later inspection)? MAYBE

Redirecting output: Using > or >> to redirect all output (i.e. vagrant up > vagrant_up.log) works, there’s no output to the screen. When there’s no output, is the provisioning step moving along or just stuck at 50%?

Having the provisioner output to the screen is important feedback, it’s definitely needed. Ironically, I may or may not be at the computer when vagrant up is showing this feedback.

Welcome my new friend: tee

In researching more on screen output, I found out about tee, which is another UNIX utility, it can output to the screen AND to a file.

$ vagrant up | tee vagrant_up.log

If everything goes well, remove the vagrant_up.log file, if something doesn’t go well, I can see it on screen AND comb through the vagrant_up.log file for errors and notifications, such as not enough CPU cores.

Conclusion

Vagrant’s provisioner is fantastic in creating custom virtual machines. Its output can be verbose and hide errors in its process.

I was lucky this time tmux captured the output, or I would have a slow nodejs installation every time.

Instead of trying to be lucky or attend every provisioning step, I looked for a better solution.

Trying to find a better solution, tee, to solve a simple problem has led me to another UNIX utility that I can use more often.

Use tee with vagrant up, it can help you debug your provisioning problems sooner! vagrant up | tee vagrant_up.log