Snapcraft blowing up with a python error without TTY (eg: snapcraft version > version.txt)

Update! Please see this bug report: https://bugs.launchpad.net/snapcraft/+bug/1906660


I’m trying to debug an issue on my local machine and CI for the Node package electron-installer-snap which uses the snapcraft tool under the hood to build snap packages.

That context aside, I’m needing to run the snapcraft command manually to try and see what error messages are happening.

When I run (without any content redirection):

$ snapcraft snap --target-arch=amd64 --output=/tmp/electron-installer-snap--17940-YGm5oN0GL92C/footest_0.0.1_amd64.snap

I can see the error message clear and fine, which is what I was after, so that I can further work on the issue:

Setting target machine to 'amd64'
Failed to get part information: Cannot find the definition for part 'desktop-gtk3', required by part 'footest'.
Remote parts are not supported with bases, so make sure that this part is defined in the `snapcraft.yaml`.

When I try and redirect output with (appending > stdout.txt):

$ snapcraft snap --target-arch=amd64 --output=/tmp/electron-installer-snap--17940-YGm5oN0GL92C/footest_0.0.1_amd64.snap > stdout.txt

I get the following:

Error in sys.excepthook:
Traceback (most recent call last):
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/snapcraft/cli/_errors.py", line 270, in exception_handler
    _process_outer_exception(exc_info, debug)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/snapcraft/cli/_errors.py", line 207, in _process_outer_exception
    click.echo(_MSG_TRACEBACK_PRINT)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/click/utils.py", line 273, in echo
    file.flush()
PermissionError: [Errno 13] Permission denied

Original exception was:
Traceback (most recent call last):
  File "/snap/snapcraft/5756/bin/snapcraft", line 33, in <module>
    sys.exit(load_entry_point('snapcraft==4.4.2', 'console_scripts', 'snapcraft')())
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/snapcraft/cli/_command.py", line 89, in invoke
    return super().invoke(ctx)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/snapcraft/cli/lifecycle.py", line 382, in snap
    _execute(steps.PRIME, parts=tuple(), pack_project=True, output=output, **kwargs)
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/snapcraft/cli/lifecycle.py", line 83, in _execute
    "Ignoring '--target-arch' flag.  This flag requires --destructive-mode and is unsupported with Multipass and LXD build providers."
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/snapcraft/cli/echo.py", line 63, in warning
    click.echo("\033[1;33m{}\033[0m".format(msg))
  File "/snap/snapcraft/5756/lib/python3.6/site-packages/click/utils.py", line 273, in echo
    file.flush()
PermissionError: [Errno 13] Permission denied
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
PermissionError: [Errno 13] Permission denied

If I run (appending | cat > stdout.txt):

$ snapcraft snap --target-arch=amd64 --output=/tmp/electron-installer-snap--17940-YGm5oN0GL92C/footest_0.0.1_amd64.snap | cat > stdout.txt

This appears to work fine.

For tools that use or spawn snapcraft under the hood, it seems impossible to retrieve any error messages when snapcraft fails to run.

In the error output from electron-installer-snap, you can see that both stdout and stderr are blank:

Error (ExitCodeError) {
    args: [
      'snap',
      '--output=/tmp/electron-installer-snap--17940-YGm5oN0GL92C/footest_0.0.1_amd64.snap',
    ],
    cmd: '/snap/bin/snapcraft',
    code: 120,
    stderr: '',
    stdout: '',
    message: `Command failed with a non-zero return code (120):␊
    /snap/bin/snapcraft snap --output=/tmp/electron-installer-snap--17940-YGm5oN0GL92C/footest_0.0.1_amd64.snap`,
  }

This actually seems to be more of a general error when a TTY isn’t present. I’ve filed a bug here: https://bugs.launchpad.net/snapcraft/+bug/1906660

Still reproducible with snapcraft v4.4.4.

What OS are you running? I cannot reproduce. Is there anything interesting about your environment? Is it somehow possible you do not have permission to call flush() on a file? Maybe try (in the same directory):

python3 -c 'with open("stdout.txt", "w") as f: f.write("foo"); f.flush()'

Ubuntu 20.10.

Interestingly… I just discovered this seems to be happening from a VS Code terminal. Using the standard Terminal app in Ubuntu doesn’t seem to have an issue.

The Python snippet above though does work regardless, in both Terminals.

Interesting, that does reproduce for me when using the VS Code snap. It looks like some apparmor denials:

= AppArmor =
Time: Dec  7 15:09:02
Log: apparmor="DENIED" operation="file_inherit" profile="/snap/snapd/10492/usr/lib/snapd/snap-confine" name="/home/chris/version.txt" pid=1106266 comm="snap-confine" requested_mask="w" denied_mask="w" fsuid=1000 ouid=1000
File: /home/chris/version.txt (write)
Suggestion:
* add 'home' to 'plugs'

= AppArmor =
Time: Dec  7 15:09:02
Log: apparmor="DENIED" operation="file_inherit" profile="/snap/snapd/10492/usr/lib/snapd/snap-confine" pid=1106266 comm="snap-confine" family="unix" sock_type="seqpacket" protocol=0 requested_mask="send receive" denied_mask="send receive" addr=none peer_addr=none

= AppArmor =
Time: Dec  7 15:09:02
Log: apparmor="DENIED" operation="file_inherit" profile="/snap/snapd/10492/usr/lib/snapd/snap-confine" pid=1106266 comm="snap-confine" family="unix" sock_type="stream" protocol=0 requested_mask="send receive" denied_mask="send receive" addr=none peer_addr=none

= AppArmor =
Time: Dec  7 15:09:02
Log: apparmor="DENIED" operation="file_inherit" profile="/snap/snapd/10492/usr/lib/snapd/snap-confine" name="/proc/1106176/statm" pid=1106266 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
File: /proc/1106176/statm (read)
Suggestion:
* adjust program to not access '@{PROC}/@{pid}/statm'

= AppArmor =
Time: Dec  7 15:09:02
Log: apparmor="DENIED" operation="file_inherit" profile="/snap/snapd/10492/usr/lib/snapd/snap-confine" name="/proc/1106176/status" pid=1106266 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
File: /proc/1106176/status (read)
Suggestion:
* adjust program to not access '@{PROC}/@{pid}/status'

= AppArmor =
Time: Dec  7 15:09:02
Log: apparmor="DENIED" operation="file_inherit" profile="/snap/snapd/10492/usr/lib/snapd/snap-confine" pid=1106266 comm="snap-confine" family="unix" sock_type="stream" protocol=0 requested_mask="send receive" denied_mask="send receive" addr=none peer_addr=none

I’m not sure why that would be the case as code is a classic snap (as well as snapcraft)… @jdstrand Perhaps you may be able to provide some insight?

Ah I bet this is https://bugs.launchpad.net/ubuntu/+source/snapd/+bug/1849753

1 Like

It does sound like the same problem. That issue appears to have been around for quite a while… is there any update/workaround/fix that is viable?

Otherwise, it seems like the only workaround is to install VSCode outside of snap :frowning:

1 Like

The approach to use is detailed in https://bugs.launchpad.net/ubuntu/+source/snapd/+bug/1849753/comments/17. I had hoped to have a fix for this some time ago, but other items have unfortunately taken priority. As a workaround, you should be able to add a file to /var/lib/snapd/apparmor/snap-confine/ (eg, /var/lib/snapd/apparmor/snap-confine/workaround) that has rules in it that you want snap-confine to have. Eg:

  @{HOME}/stdout.txt rwk,
  <other rules here>

or for a quick debugging session, just add ‘file,’ which allows all files. Once the file is in place, do: sudo apparmor_parser -r /etc/apparmor.d/usr.lib.snapd.snap-confine* /var/lib/snapd/apparmor/profiles/snap-confine.*

snapd may remove the /var/lib/snapd/apparmor/snap-confine/workaround file at some point, in which case you would need to add it back. To undo it, remove the workaround file and run apparmor_parser again.

1 Like

The stdout.txt file was just an example to be able to reproduce the error, but in reality, I have no idea what files some other programs may be wanting to create, and some aren’t creating files, but in fact, it’s just data being sent to stdout or stderr that might cause things to blow up if a child process of another program is spawned where this problem also occurs.

It feels like perhaps the wildcard file, may be an option, but having to deal with that workaround file being removed etc etc, I really feel like installing the .deb version of VSCode is probably the best for me as I just need to be able to get on with my work, I’m afraid.

I can understand that the reason this issue is happening is due to trying to make things more secure for the platforms, but unfortunately from a users perspective, it’s not ideal, and as a developer who publishes applications to snap, I’ve lost a tiny little bit of faith, unfortunately, as I don’t see how this can be handled well for my users if the error happens.

I really appreciate everyone’s input, because at least I now understand what the root cause is, and don’t need to go down any further rabbit holes :+1:

1 Like