Skip to content

misleading errors when running on nfs and overlay #289

New issue
New issue
Open
Open
misleading errors when running on nfs and overlay#289
@smoser

Description

@smoser
smoser
opened on May 6, 2022

overlayfs does not work on nfs. When using stacker, the failure path is quite non-obvious there.
Below is output of stacker current tip on nfs build.

Reasons why I lost time debugging this:

  • There isn't anything in the output that even mentions mounts failing
  • you're left with the non-fatal 'error' in the output.
  • --debug is even worse as it gives you a stack trace on the non-fatal main.doCheckAAProfile debug-log.txt .

I'd like to suggest that:

  1. stack traces of "information finding" sub-commands should not be shown. they are really hard to ignore.
  2. the message error: write /proc/30031/attr/current: invalid argument that is a result of that information subcommand (check-aa-profile) should not be written to output.
# this is centos 7.9 kernel from https://centos.pkgs.org/7/elrepo-kernel-x86_64/
$ uname -r
5.17.5-1.el7.elrepo.x86_64

$ /tmp/stacker-bins/stacker-v0.20.1-14-g8bcaa49 build
preparing image build-env...
loading docker://aci-docker-reg.cisco.com/c3/minbase:1.0.7
Copying blob 0dab16140ba4 skipped: already exists
Copying blob 6754ae8b4482 skipped: already exists
Copying config 7fe0fbc9f6 done
Writing manifest to image destination
Storing signatures
error: write /proc/30031/attr/current: invalid argument
couldn't find AppArmor profile lxc-container-default-cgns
failed to start container build-env
error: run commands failed: execute failed: exit status 1
error: exit status 1

$ cat .stacker/lxc.log
lxc 20220506130812.376 TRACE    lxccontainer - lxccontainer.c:do_lxcapi_save_config:2672 - Saved config file "/tmp/stacker_build-env_run2594949720"
lxc build-env 20220506130817.794 TRACE    commands - commands.c:lxc_server_init:2078 - Created abstract unix socket "/home/scmoser/test/roots/build-env/command"
lxc build-env 20220506130817.794 TRACE    start - start.c:lxc_init_handler:757 - Unix domain socket 3 for command server is ready
lxc build-env 20220506130817.795 TRACE    execute - execute.c:lxc_execute:49 - Doing lxc_execute
lxc build-env 20220506130817.795 INFO     lsm - lsm/lsm.c:lsm_init_static:38 - Initialized LSM security driver nop
lxc build-env 20220506130817.795 TRACE    start - start.c:lxc_init:781 - Initialized LSM
lxc build-env 20220506130817.795 TRACE    start - start.c:lxc_serve_state_clients:486 - Set container state to STARTING
lxc build-env 20220506130817.795 TRACE    start - start.c:lxc_serve_state_clients:489 - No state clients registered
lxc build-env 20220506130817.795 INFO     utils - utils.c:get_rundir:260 - XDG_RUNTIME_DIR isn't set in the environment
lxc build-env 20220506130817.795 TRACE    start - start.c:lxc_init:787 - Set container state to "STARTING"
lxc build-env 20220506130817.795 TRACE    start - start.c:lxc_init:843 - Set environment variables
lxc build-env 20220506130817.795 TRACE    start - start.c:lxc_init:848 - Ran pre-start hooks
lxc build-env 20220506130817.795 TRACE    start - start.c:setup_signal_fd:373 - Created signal file descriptor 6
lxc build-env 20220506130817.795 TRACE    start - start.c:lxc_init:861 - Set up signal fd
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.795 INFO     cgfsng - cgroups/cgfsng.c:legacy_hierarchy_delegated:3092 - Permission denied - Legacy hierarchy not writable, skipping
lxc build-env 20220506130817.796 TRACE    cgroup - cgroups/cgroup.c:cgroup_init:40 - Initialized cgroup driver cgfsng
lxc build-env 20220506130817.796 TRACE    cgroup - cgroups/cgroup.c:cgroup_init:47 - Unified cgroup layout
lxc build-env 20220506130817.796 TRACE    start - start.c:lxc_init:868 - Initialized cgroup driver
lxc build-env 20220506130817.796 TRACE    start - start.c:lxc_init:875 - Read seccomp policy
lxc build-env 20220506130817.796 TRACE    start - start.c:lxc_init:882 - Initialized LSM
lxc build-env 20220506130817.796 INFO     start - start.c:lxc_init:884 - Container "build-env" is initialized
lxc build-env 20220506130817.796 DEBUG    storage - storage/storage.c:get_storage_by_name:209 - Detected rootfs type "overlay"
lxc build-env 20220506130817.796 TRACE    conf - conf.c:lxc_rootfs_init:560 - Invalid argument - Not pinning on stacking filesystem
lxc build-env 20220506130817.796 TRACE    sync - sync.c:lxc_sync_init:139 - Initialized synchronization infrastructure
lxc build-env 20220506130817.796 TRACE    start - start.c:lxc_spawn:1745 - Cloned child process 30039
lxc build-env 20220506130817.796 TRACE    start - start.c:core_scheduling:1563 - No new core scheduling domain requested
lxc build-env 20220506130817.796 TRACE    utils - utils.c:lxc_can_use_pidfd:1819 - Kernel supports pidfds
lxc build-env 20220506130817.796 INFO     start - start.c:lxc_spawn:1765 - Cloned CLONE_NEWNS
lxc build-env 20220506130817.796 INFO     start - start.c:lxc_spawn:1765 - Cloned CLONE_NEWPID
lxc build-env 20220506130817.796 INFO     start - start.c:lxc_spawn:1765 - Cloned CLONE_NEWUTS
lxc build-env 20220506130817.796 INFO     start - start.c:lxc_spawn:1765 - Cloned CLONE_NEWIPC
lxc build-env 20220506130817.796 INFO     start - start.c:lxc_spawn:1765 - Cloned CLONE_NEWCGROUP
lxc build-env 20220506130817.797 DEBUG    start - start.c:lxc_try_preserve_namespace:139 - Preserved mnt namespace via fd 13 and stashed path as mnt:/proc/30038/fd/13
lxc build-env 20220506130817.797 DEBUG    start - start.c:lxc_try_preserve_namespace:139 - Preserved pid namespace via fd 14 and stashed path as pid:/proc/30038/fd/14
lxc build-env 20220506130817.797 DEBUG    start - start.c:lxc_try_preserve_namespace:139 - Preserved uts namespace via fd 15 and stashed path as uts:/proc/30038/fd/15
lxc build-env 20220506130817.797 DEBUG    start - start.c:lxc_try_preserve_namespace:139 - Preserved ipc namespace via fd 16 and stashed path as ipc:/proc/30038/fd/16
lxc build-env 20220506130817.797 DEBUG    start - start.c:lxc_try_preserve_namespace:139 - Preserved cgroup namespace via fd 17 and stashed path as cgroup:/proc/30038/fd/17
lxc build-env 20220506130817.797 TRACE    sync - sync.c:lxc_sync_barrier_child:97 - Parent waking child with sequence startup and waiting with sequence configure
lxc build-env 20220506130817.797 TRACE    sync - sync.c:lxc_sync_wait_parent:110 - Child waiting for parent with sequence startup
lxc build-env 20220506130817.797 TRACE    sync - sync.c:lxc_sync_wake_parent:104 - Child waking parent with sequence configure
lxc build-env 20220506130817.797 TRACE    conf - conf.c:lxc_set_environment:5753 - Set environment variable: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
lxc build-env 20220506130817.797 DEBUG    start - start.c:lxc_try_preserve_namespace:139 - Preserved net namespace via fd 4 and stashed path as net:/proc/30038/fd/4
lxc build-env 20220506130817.797 TRACE    conf - conf.c:lxc_set_environment:5753 - Set environment variable: TERM=xterm
lxc build-env 20220506130817.797 TRACE    conf - conf.c:lxc_set_environment:5753 - Set environment variable: STACKER_LAYER_NAME=build-env
lxc build-env 20220506130817.797 TRACE    sync - sync.c:lxc_sync_wait_parent:110 - Child waiting for parent with sequence post-configure
lxc build-env 20220506130817.797 WARN     start - start.c:lxc_spawn:1835 - Operation not permitted - Failed to allocate new network namespace id
lxc build-env 20220506130817.797 TRACE    sync - sync.c:lxc_sync_wake_child:122 - Parent waking child with sequence post-configure
lxc build-env 20220506130817.797 TRACE    sync - sync.c:lxc_sync_wait_child:116 - Parent waiting for child with sequence idmapped-mounts
lxc build-env 20220506130817.798 TRACE    conf - conf.c:turn_into_dependent_mounts:3923 - Turned all mount table entries into dependent mount
lxc build-env 20220506130817.811 INFO     overlay - storage/overlay.c:ovl_mount:481 - Permission denied - Failed to mount "/home/scmoser/test/roots/sha256_6754ae8b4482caf0381ba778a105a956a9dd703193ecf25de47a3c8c258528cd/overlay:/home/scmoser/test/roots/sha256_0dab16140ba45e4d16857a1c36b0ba23da0e4df9eab34617591baf0f714e0744/overlay" on "/home/scmoser/test/.stacker/rootfsPivot" with options "upperdir=/home/scmoser/test/roots/build-env/overlay,lowerdir=/home/scmoser/test/roots/sha256_6754ae8b4482caf0381ba778a105a956a9dd703193ecf25de47a3c8c258528cd/overlay:/home/scmoser/test/roots/sha256_0dab16140ba45e4d16857a1c36b0ba23da0e4df9eab34617591baf0f714e0744/overlay,workdir=/home/scmoser/test/roots/build-env/work". Retrying without workdir
lxc build-env 20220506130817.813 ERROR    overlay - storage/overlay.c:ovl_mount:490 - Invalid argument - Failed to mount "/home/scmoser/test/roots/sha256_6754ae8b4482caf0381ba778a105a956a9dd703193ecf25de47a3c8c258528cd/overlay:/home/scmoser/test/roots/sha256_0dab16140ba45e4d16857a1c36b0ba23da0e4df9eab34617591baf0f714e0744/overlay" on "/home/scmoser/test/.stacker/rootfsPivot" with options "upperdir=/home/scmoser/test/roots/build-env/overlay,lowerdir=/home/scmoser/test/roots/sha256_6754ae8b4482caf0381ba778a105a956a9dd703193ecf25de47a3c8c258528cd/overlay:/home/scmoser/test/roots/sha256_0dab16140ba45e4d16857a1c36b0ba23da0e4df9eab34617591baf0f714e0744/overlay"
lxc build-env 20220506130817.813 ERROR    conf - conf.c:lxc_mount_rootfs:1432 - Failed to mount rootfs "overlayfs:/home/scmoser/test/roots/sha256_6754ae8b4482caf0381ba778a105a956a9dd703193ecf25de47a3c8c258528cd/overlay:/home/scmoser/test/roots/sha256_0dab16140ba45e4d16857a1c36b0ba23da0e4df9eab34617591baf0f714e0744/overlay:/home/scmoser/test/roots/build-env/overlay" onto "/home/scmoser/test/.stacker/rootfsPivot" with options "(null)"
lxc build-env 20220506130817.814 ERROR    conf - conf.c:lxc_setup_rootfs_prepare_root:3964 - Failed to setup rootfs for
lxc build-env 20220506130817.814 ERROR    conf - conf.c:lxc_setup:4331 - Failed to setup rootfs
lxc build-env 20220506130817.814 ERROR    start - start.c:do_start:1275 - Failed to setup container "build-env"
lxc build-env 20220506130817.814 TRACE    sync - sync.c:lxc_sync_wake_parent:104 - Child waking parent with sequence error
lxc build-env 20220506130817.814 ERROR    sync - sync.c:sync_wait:34 - An error occurred in another process (expected sequence number 3)
lxc build-env 20220506130817.814 TRACE    start - start.c:lxc_serve_state_clients:486 - Set container state to ABORTING
lxc build-env 20220506130817.814 TRACE    start - start.c:lxc_serve_state_clients:489 - No state clients registered
lxc build-env 20220506130817.814 INFO     utils - utils.c:get_rundir:260 - XDG_RUNTIME_DIR isn't set in the environment
lxc build-env 20220506130817.816 ERROR    start - start.c:__lxc_start:2074 - Failed to spawn container "build-env"
lxc build-env 20220506130817.816 TRACE    start - start.c:lxc_serve_state_clients:486 - Set container state to ABORTING
lxc build-env 20220506130817.816 TRACE    start - start.c:lxc_serve_state_clients:489 - No state clients registered
lxc build-env 20220506130817.816 INFO     utils - utils.c:get_rundir:260 - XDG_RUNTIME_DIR isn't set in the environment
lxc build-env 20220506130817.816 WARN     start - start.c:lxc_abort:1039 - No such process - Failed to send SIGKILL via pidfd 12 for process 30039
lxc build-env 20220506130817.816 TRACE    start - start.c:lxc_serve_state_clients:486 - Set container state to STOPPING
lxc build-env 20220506130817.816 TRACE    start - start.c:lxc_serve_state_clients:489 - No state clients registered
lxc build-env 20220506130817.816 INFO     utils - utils.c:get_rundir:260 - XDG_RUNTIME_DIR isn't set in the environment
lxc build-env 20220506130817.816 TRACE    start - start.c:lxc_end:966 - Closed command socket
lxc build-env 20220506130817.816 INFO     utils - utils.c:get_rundir:260 - XDG_RUNTIME_DIR isn't set in the environment
lxc build-env 20220506130817.816 TRACE    start - start.c:lxc_end:977 - Set container state to "STOPPED"

$ cat stacker.yaml
build-env:
  build_only: true
  from:
    type: docker
    url: docker://docker-repo/c3/minbase:1.0.7
  run: |
    echo HELLO WORLD

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions