Forked child process within snaps causing unexpected failures

I have a weird one and I haven’t been able to fully grok what’s going on so I’m hoping someone here might have a suggestion.

In the node snap, we have yarn being bundled. Yarn follows basically the same process as npm for installing Node.js packages. Packages can have “lifecycle scripts” to aid in the installation process, the most common of these being a post-installation script that either compiles native addon code (mostly using the node-gyp command) or downloading a pre-compiled binary of the addon (node-pre-gyp or prebuild being two common tools for this). Lifecycle scripts are all executed using sh -c, I’m pretty sure npm still does this and Yarn certainly does.

npm works just fine from within its snap, installing and compiling and downloading and everything you expect.

Yarn, on the other hand, doesn’t like some very common lifecycle scripts. It has a fancy console “reporter” that prints information about install progress as it’s happen, usually obscuring stdout from child processes involved in executing these lifecycle scripts, showing it line-by-line and writing over it with status messages when done. This isn’t normally a problem and I can’t find anything about it being a problem on any platform for Yarn.

I can’t get any useful error information other than the process exiting with a non-zero exit status. If I try and handle stdio to get output by hacking Yarn I get a successful build. A true heisenbug. My fix currently is to hack Yarn with sed with the ‘install’ phase of the snap to force replacement of the “reporter” with “inherited” child process stdio (which just means that stdio, stderr and stdin are piped to/from the parent). When I do that it all goes fine, but the nice reporter output is messed up with child process output interrupting it. So it’s not ideal.

So, my current guess is that there’s something about apparmor, or other containment mechanism of snaps that is treating stdout differently to a standard non-contained application. Yarn doesn’t handle child process streams in the same way that npm does and I could believe that child process stdout buffers when it should be discarded.

To reproduce, here’s a modified version of the node snapcraft.yaml that uses an upstream binary rather than recompiling (so you don’t have to wait for a compile). The Yarn fix is commented out on the last two lines. So build this, install it, add an alias for yarn and try yarn add buffertools (uses node-gyp, an automatic part of Yarn & npm when there’s a binding.gyp), and yarn add sqlite3 (uses node-pre-gyp to download/or compile the addon) and yarn add leveldown (uses prebuild to essentially do the same thing as node-pre-gyp).

name: node
version: '8.10.0'
summary: Node.js
description: |
  A JavaScript runtime built on Chrome's V8 JavaScript engine. Node.js uses an event-driven, non-blocking I/O model that makes it lightweight and efficient. Node.js' package ecosystem, npm, is the largest ecosystem of open source libraries in the world. https://nodejs.org/

grade: stable
confinement: classic

apps:
  node:
    command: bin/node
  npm:
    command: bin/npm
  yarn:
    command: bin/yarn.js

parts:
  node:
    #plugin: make
    plugin: dump
    source-type: tar
    #source: https://nodejs.org/download/release/v8.10.0/node-v8.10.0.tar.gz
    source: https://nodejs.org/download/release/v8.10.0/node-v8.10.0-linux-x64.tar.gz
    #build-packages:
    #  - g++
    #  - make
    #  - python2.7
    #prepare: |
    #  ./configure --prefix=/ --release-urlbase=https://nodejs.org/download/release/ --tag=
    stage: [usr/*,bin/*,lib/*]
    install: |
      mkdir -p $SNAPCRAFT_PART_INSTALL/etc
      echo "prefix = /usr/local" >> $SNAPCRAFT_PART_INSTALL/etc/npmrc
  yarn:
    source-type: tar
    source: https://yarnpkg.com/latest.tar.gz
    plugin: dump
    # Yarn has a problem with lifecycle scripts when used inside snap, they don't complete properly, with exit code !=0.
    # Replacing the spinner with proper stdio appears to fix it.
    #install: |
    #  sed -i "s/var stdio = spinner ? undefined : 'inherit';/var stdio = 'inherit';/" $SNAPCRAFT_PART_INSTALL/lib/cli.js

There’s one more weird thing about this … I can get node-gyp builds to work without my Yarn hack if I hack the way that node-gyp is called by Yarn inside the snap. To do this, I need to stage [python2.7,python] in the package and add the following to the install for the ‘node’ part:

      echo -n '#!/bin/sh\nexport PYTHON=$SNAP/usr/bin/python\necho $PATH\nexec "$SNAP/bin/node" "$SNAP/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "$@"' > $SNAPCRAFT_PART_INSTALL/bin/node-gyp
      chmod 755 $SNAPCRAFT_PART_INSTALL/bin/node-gyp
      ln -sf ../../../../../bin/node-gyp $SNAPCRAFT_PART_INSTALL/lib/node_modules/npm/bin/node-gyp-bin/node-gyp

What this essentially does is replace the default node-gyp launch script that Yarn reaches for with one that is slightly more direct. But all it’s doing is replacing:

#!/usr/bin/env sh
if [ "x$npm_config_node_gyp" = "x" ]; then
  node "`dirname "$0"`/../../node_modules/node-gyp/bin/node-gyp.js" "$@"
else
  "$npm_config_node_gyp" "$@"
fi

(that first branch is the most common)

But this only fixes node-gyp, not node-pre-gyp, prebuild and anything else non-standard. Plus, I don’t understand why this might work, at all. Perhaps it’s to do with using /usr/bin/env to find sh (this is a common pattern in Node-land, particularly for finding Node: #!/usr/bin/env node), replacing it with a more direct call and also the direct PYTHON reference.

I can’t reproduce this issue using your example yaml:

$ yarn add buffertools
yarn add v1.5.1
info No lockfile found.
[1/4] Resolving packages...
[2/4] Fetching packages...
[3/4] Linking dependencies...
[4/4] Building fresh packages...
success Saved lockfile.
success Saved 1 new dependency.
info Direct dependencies
└─ buffertools@2.1.6
info All dependencies
└─ buffertools@2.1.6
Done in 1.07s.

What version of core are you running? Can you share the output of snap version please?

AppArmor shouldn’t be affecting this if you don’t see denials in your logs. In addition to answering @lucyllewy’s question, does this work if you install the snap in devmode but not strict mode?

@lucyllewy thanks for trying to reproduce and I guess it’s partly good news that you don’t experience the same problem.

I’ve been experiencing this problem on:

snap    2.31.2
snapd   2.31.2
series  16
ubuntu  17.10
kernel  4.13.0-37-generic

But have been building and testing in lxd on (because of the pain of the “libc6 needed in stage-packages” error that you can’t make go away when you’re not building on Xenial):

snap    2.31.2
snapd   2.31.2
series  16
ubuntu  16.04
kernel  4.13.0-37-generic

Versions of the node snap before this week had node.yarn but not the hack I’ve applied and these have been a problem on my system too. Unfortunately I can’t get --revision to work for older releases using either snap refresh or snap install. Revision 217 is a good candidate to check, channel 8/stable.

But, I’ve just downloaded the .snap from https://dashboard.snapcraft.io/snaps/node/revisions/217/ and put it on a machine where I’ve never touched snap before and has had minimal node work on it so doesn’t have the clutter of config files and other things likely on my primary machine.

Its config is:

snap    2.31.2
snapd   2.31.2
series  16
ubuntu  16.04
kernel  4.4.0-112-generic

And I get the error I described:

$ sudo snap install /tmp/MEd4V4HHFkCXBSz6UzVmKF2D2PmWcVwR_217.snap --dangerous --classic
node 8.10.0 installed
$ node -v
v8.10.0
$ which node
/snap/bin/node
rvagg@media:/tmp$ sudo snap alias node.yarn yarn
Added:
  - node.yarn as yarn
$ cd /tmp/
$ yarn add buffertools
yarn add v1.5.1
info No lockfile found.
[1/4] Resolving packages...
[2/4] Fetching packages...
[3/4] Linking dependencies...
[4/4] Building fresh packages...
error An unexpected error occurred: "/tmp/node_modules/buffertools: Command failed.
Exit code: 1
Command: sh
Arguments: -c node-gyp rebuild
Directory: /tmp/node_modules/buffertools
Output:
".
info If you think this is a bug, please open a bug report with the information provided in "/tmp/yarn-error.log".
info Visit https://yarnpkg.com/en/docs/cli/add for documentation about this command.

@jdstrand: this is a classic confined snap and I haven’t been testing with devmode but have now and I get interesting results:

$ yarn add buffertools
yarn add v1.5.1
info No lockfile found.
[1/4] Resolving packages...
[2/4] Fetching packages...
[3/4] Linking dependencies...
[4/4] Building fresh packages...
error An unexpected error occurred: "/tmp/node_modules/buffertools: Command failed.
Exit code: 1
Command: sh
Arguments: -c node-gyp rebuild
Directory: /tmp/node_modules/buffertools
Output:
gyp info it worked if it ends with ok
gyp info using node-gyp@3.6.2
gyp info using node@8.10.0 | linux | x64
gyp ERR! configure error
gyp ERR! stack Error: Can't find Python executable \"python\", you can set the PYTHON env variable.
gyp ERR! stack     at PythonFinder.failNoPython (/snap/node/x1/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:483:19)
gyp ERR! stack     at PythonFinder.<anonymous> (/snap/node/x1/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:397:16)
gyp ERR! stack     at F (/snap/node/x1/lib/node_modules/npm/node_modules/which/which.js:68:16)
gyp ERR! stack     at E (/snap/node/x1/lib/node_modules/npm/node_modules/which/which.js:80:29)
gyp ERR! stack     at /snap/node/x1/lib/node_modules/npm/node_modules/which/which.js:89:16
gyp ERR! stack     at /snap/node/x1/lib/node_modules/npm/node_modules/which/node_modules/isexe/index.js:42:5
gyp ERR! stack     at /snap/node/x1/lib/node_modules/npm/node_modules/which/node_modules/isexe/mode.js:8:5
gyp ERR! stack     at FSReqWrap.oncomplete (fs.js:152:21)
gyp ERR! System Linux 4.13.0-37-generic
gyp ERR! command \"/snap/node/x1/bin/node\" \"/snap/node/x1/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js\" \"rebuild\"
gyp ERR! cwd /tmp/node_modules/buffertools
gyp ERR! node -v v8.10.0
gyp ERR! node-gyp -v v3.6.2
gyp ERR! not ok".
info If you think this is a bug, please open a bug report with the information provided in "/tmp/yarn-error.log".
info Visit https://yarnpkg.com/en/docs/cli/add for documentation about this command.

Getting the output here is new, even though the error is still a problem. It should just be finding python on my system, outside of the snap.

But trying other tools that don’t use node-gyp such as sqlite3 and leveldown work just fine!

$ yarn add sqlite3
yarn add v1.5.1
warning package.json: No license field
warning No license field
[1/4] Resolving packages...
[2/4] Fetching packages...
[3/4] Linking dependencies...
[4/4] Building fresh packages...
success Saved 1 new dependency.
info Direct dependencies
└─ sqlite3@4.0.0
info All dependencies
└─ sqlite3@4.0.0
warning No license field
Done in 3.73s.

As soon as I switch back to a classic version of the same build then it all starts failing again.

I don’t understand the python not found error at all. I can’t get that to go away when in devmode unless I ship python in the snap or replace the node-gyp wrapper with the one I pasted up in the OP. I guess that’s a separate issue.

I see. Since devmode brings in the per-snap mount namespace and changes the runtime significantly, I wouldn’t expect the snap to just work in devmode without modification when it was designed to work for classic. I think you can disregard the devmode tests and should just focus on the classic ones. I would suggest focusing on trying to determine the relevant differences between the systems that work and don’t work to see if that reveals anything.

I believe this is your issue. Snaps cannot write to the system /tmp folder.

Edit: Tell a lie, @daniel, this is a classic snap. hmm the mystery continues :slight_smile: