Cannot re-enter studio on Ubuntu 18.04: dev/proc/etc filesystems not unmounting

Habitat Help
1

Hi friends, I’ve got a new dev workstation (physical machine, fresh Ubuntu 18.04 install) and am seeing some whacky problems that I don’t understand.

  1. I create a studio in /home/irving/src - this works fine, I see the typical and expected (?) filesystems get mounted
devpts on /hab/studios/home--irving--src/dev/pts type devpts (rw,relatime,gid=5,mode=620,ptmxmode=000)
devpts on /dev/pts type devpts (rw,relatime,gid=5,mode=620,ptmxmode=000)
proc on /hab/studios/home--irving--src/proc type proc (rw,relatime)
sysfs on /hab/studios/home--irving--src/sys type sysfs (rw,relatime)
tmpfs on /hab/studios/home--irving--src/run type tmpfs (rw,relatime)
tmpfs on /hab/studios/home--irving--src/var/run/docker.sock type tmpfs (rw,nosuid,noexec,relatime,size=3283068k,mode=755)
/dev/nvme0n1p3 on /hab/studios/home--irving--src/hab/cache/artifacts type xfs (rw,relatime,attr2,inode64,noquota)
/dev/nvme0n1p3 on /hab/studios/home--irving--src/src type xfs (rw,relatime,attr2,inode64,noquota)

  1. I exit the studio, all filesystems still stick around

  2. I re-enter the studio, and get an error very early:

$ RUST_LOG=debug hab studio enter
[2019-01-17T18:15:25Z DEBUG habitat_common::ui] UI { shell: Shell { input: InputStream { isatty: true }, out: OutputStream { coloring: Auto, isatty: true, is_colored(): true, supports_color(): true }, err: OutputStream { coloring: Auto, isatty: true, is_colored(): true, supports_color(): true } } }
[2019-01-17T18:15:25Z DEBUG hab::command::studio::enter] Setting HAB_CACHE_KEY_PATH=/home/irving/.hab/cache/keys
[2019-01-17T18:15:25Z DEBUG hab::command::studio::enter] Setting ARTIFACT_PATH=/home/irving/.hab/cache/artifacts
[2019-01-17T18:15:25Z DEBUG habitat_core::os::process::imp] Calling execvp(): ("/usr/bin/sudo") ["-p", "[sudo hab-studio] password for %u: ", "-E", "hab", "studio", "enter"]
[2019-01-17T18:15:25Z DEBUG habitat_common::ui] UI { shell: Shell { input: InputStream { isatty: true }, out: OutputStream { coloring: Auto, isatty: true, is_colored(): true, supports_color(): true }, err: OutputStream { coloring: Auto, isatty: true, is_colored(): true, supports_color(): true } } }
[2019-01-17T18:15:25Z DEBUG habitat_core::os::process::imp] Calling execvp(): ("/hab/pkgs/core/hab-studio/0.73.0/20190115010614/bin/hab-studio") ["enter"]
   hab-studio: Creating Studio at /hab/studios/home--irving--src (default)
mount: mounting proc on /hab/studios/home--irving--src/proc failed: Resource busy
  1. I attempt to clean up the mounted filesystems (seeing 15-16 of EACH one!), but dev refuses to unmount
$ grep hab /proc/mounts | awk '{print $2}' | sort | uniq | xargs -n1 sudo umount -f
umount: /hab/studios/home--irving--src/dev: target is busy.
  1. One time I did a hab studio rm and it ended up wiping out some/all of my /dev/ filesystem and temporarily hosing the box until I rebooted - this scared the crap out of me so I’m nervous about doing that again . :slight_smile:

Has anyone seen this before? what kinds of things can I do to troubleshoot this?

2

Providing a tiny bit more information, I found the VERBOSE flag and it appears that cleanup_studio is silently failing:

1][default:/src:0]# exit
logout
+ cleanup_studio
+ kill_launcher
...
+ umount_fs -v /hab/studios/home--irving--src3/run
+ eval _mount_point=$2
+ _mount_point=/hab/studios/home--irving--src3/run
+ is_fs_mounted /hab/studios/home--irving--src3/run
+ _mount_point=/hab/studios/home--irving--src3/run
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox mount
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox grep -q on /hab/studios/home--irving--src3/run type
+ return 0
+ [ -z  ]
+ umount_fs -v /hab/studios/home--irving--src3/sys
+ eval _mount_point=$2
+ _mount_point=/hab/studios/home--irving--src3/sys
+ is_fs_mounted /hab/studios/home--irving--src3/sys
+ _mount_point=/hab/studios/home--irving--src3/sys
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox mount
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox grep -q on /hab/studios/home--irving--src3/sys type
+ return 0
+ umount_fs -v /hab/studios/home--irving--src3/proc
+ eval _mount_point=$2
+ _mount_point=/hab/studios/home--irving--src3/proc
+ is_fs_mounted /hab/studios/home--irving--src3/proc
+ _mount_point=/hab/studios/home--irving--src3/proc
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox mount
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox grep -q on /hab/studios/home--irving--src3/proc type
+ return 0
+ umount_fs -v /hab/studios/home--irving--src3/dev/pts
+ eval _mount_point=$2
+ _mount_point=/hab/studios/home--irving--src3/dev/pts
+ is_fs_mounted /hab/studios/home--irving--src3/dev/pts
+ _mount_point=/hab/studios/home--irving--src3/dev/pts
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox mount
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox grep -q on /hab/studios/home--irving--src3/dev/pts type
+ return 0
+ umount_fs -v -l /hab/studios/home--irving--src3/dev
+ eval _mount_point=$3
+ _mount_point=/hab/studios/home--irving--src3/dev
+ is_fs_mounted /hab/studios/home--irving--src3/dev
+ _mount_point=/hab/studios/home--irving--src3/dev
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox mount
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox grep -q on /hab/studios/home--irving--src3/dev type
+ return 0
+ umount_fs -v -l /hab/studios/home--irving--src3/var/run/docker.sock
+ eval _mount_point=$3
+ _mount_point=/hab/studios/home--irving--src3/var/run/docker.sock
+ is_fs_mounted /hab/studios/home--irving--src3/var/run/docker.sock
+ _mount_point=/hab/studios/home--irving--src3/var/run/docker.sock
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox mount
+ /hab/pkgs/core/hab-studio/0.73.0/20190115010614/libexec/busybox grep -q on /hab/studios/home--irving--src3/var/run/docker.sock type
+ return 0

but they are clearly still mounted.

3

I’m also seeing this with the chefes/buildkite image.

I have a script for CI that calls hab pkg build foo then enters a studio to run tests against the newly built package.
The script works fine on my Macbook but when I run it inside chefes/buildkite it fails with mount: mounting proc on /hab/studios/workdir/proc failed: Resource busy

As a weak workaround, I got my script working by having the 2nd usage of hab use the slim studio (hab studio -q -r /opt/slim run).
This is weak because the slim studio also cannot be re-entered. And I’m unsure what limitations I’m putting on myself by having the slim studio.

4

I filed an issue, with my case as reproduction steps https://github.com/habitat-sh/habitat/issues/6577

5

I’ve seen this a ton too in the last few months and haven’t pinned down what causes it, but it’s a big pain to clean up manually by umounting each and every mount depth-first

6

@irvingpop @chris I’m fairly confident that this is a musl bug exposed when you have a single /proc/mount entry with > 1024 characters. See https://github.com/habitat-sh/habitat/issues/6591 for more details.

Can either of you confirm that the systems you saw this on had a mount entry with >1024 characters? overlayfs with a docker image comprised of multiple layers seems to be the most common trigger, but I’ve got a repro using a loopback mount to a heavily nested set of sub directories.

7

@smacfarlane I’ll check next time I see this, but the docker-driven long mount entry cause is totally plausible where I’ve seen it

8

can confirm, I’ve got mounts > 1024 line length (cause docker)

#  mount | wc --max-line-length
1169