Error Using Extensions in Ubuntu Jammy: "stat /cnb/lifecycle/extender: no such file or directory: unknown"

[a1flecke]

Summary

Using pack with extensions fails in Ubuntu Jammy with "stat /cnb/lifecycle/extender: no such file or directory: unknown". It succeeds locally on Mac OS.

If it matters, the Ubuntu Jammy is container running on an Ubuntu Focal host.

Reproduction

Steps

1. Clone this repo
2. cd use-dockerfile-extension
3. ./try-pack.sh paketobuildpacks/builder-jammy-full ${ANOTHER_DOCKER_URI} try-pack will re-tag the original builder with ${ANOTHER_DOCKER_URI} to allow extension use on a trusted builder. The script will also push the retag to the docker registry to account for pack wanting to pull the image as part of its code path.

Current behavior

Fails:

...
2023/11/16 14:11:48.977793 [extender (build)] Updating process list
2023/11/16 14:11:48.977818 [extender (build)] Finished running build for buildpack paketo-buildpacks/procfile@5.6.6
2023/11/16 14:11:48.977842 [extender (build)] Copying SBOM files
2023/11/16 14:11:48.983349 [extender (build)] Creating SBOM files for legacy BOM
2023/11/16 14:11:48.983784 [extender (build)] Listing processes
2023/11/16 14:11:48.985121 [extender (build)] Timer: Builder ran for 285.073358ms and ended at 2023-11-16T14:11:48Z
2023/11/16 14:11:49.227083 ERROR: failed to build: executing lifecycle: container start: Error response from daemon: failed to create task for container: failed to create shim task: OCI runtime create failed: runc create failed: unable to start container process: exec: "/cnb/lifecycle/extender": stat /cnb/lifecycle/extender: no such file or directory: unknown

real	0m12.061s
user	0m0.174s
sys	0m0.132s

Expected behavior

I expected pack to succeed in Ubuntu Jammy as it did with MacOS:

...
2023/11/16 08:19:47.049898 [extender (build)] Timer: Builder ran for 11.272440213s and ended at 2023-11-16T14:19:47Z
2023/11/16 08:19:47.201058 ===> EXPORTING
2023/11/16 08:19:47.201924 Running the exporter on OS linux with:
2023/11/16 08:19:47.201936 Container Settings:
2023/11/16 08:19:47.201949   Args: /cnb/lifecycle/exporter -daemon -launch-cache /launch-cache -log-level debug -app /workspace -cache-dir /cache -run /layers/run.toml -process-type run tryit
2023/11/16 08:19:47.201958   System Envs: CNB_USER_ID=1001 CNB_GROUP_ID=1000 CNB_EXPERIMENTAL_MODE=warn CNB_PLATFORM_API=0.12
2023/11/16 08:19:47.201966   Image: buildpacksio/lifecycle:0.18.1
2023/11/16 08:19:47.201971   User: root
2023/11/16 08:19:47.201982   Labels: map[author:pack]
2023/11/16 08:19:47.201987 Host Settings:
2023/11/16 08:19:47.201997   Binds: pack-cache-library_tryit_latest-5573111187f2.build:/cache pack-cache-library_tryit_latest-5573111187f2.kaniko:/kaniko /var/run/docker.sock:/var/run/docker.sock pack-cache-library_tryit_latest-5573111187f2.launch:/launch-cache pack-layers-gbjoqykgzc:/layers pack-app-qofsgfccdi:/workspace
2023/11/16 08:19:47.202005   Network Mode: 
2023/11/16 08:19:47.556105 [exporter] Starting exporter...
2023/11/16 08:19:47.556164 [exporter] Parsing inputs...
2023/11/16 08:19:47.564094 [exporter] Ensuring privileges...
2023/11/16 08:19:47.567434 [exporter] Executing command...
2023/11/16 08:19:47.570343 [exporter] Warning: Platform requested experimental feature 'Dockerfiles'
2023/11/16 08:19:47.604081 [exporter] Timer: Exporter started at 2023-11-16T14:19:47Z
2023/11/16 08:19:47.604430 [exporter] Copying SBOM lifecycle.sbom.cdx.json to /layers/sbom/build/buildpacksio_lifecycle/sbom.cdx.json
2023/11/16 08:19:47.605170 [exporter] Copying SBOM lifecycle.sbom.spdx.json to /layers/sbom/build/buildpacksio_lifecycle/sbom.spdx.json
2023/11/16 08:19:47.605378 [exporter] Copying SBOM lifecycle.sbom.syft.json to /layers/sbom/build/buildpacksio_lifecycle/sbom.syft.json
2023/11/16 08:19:47.605721 [exporter] Copying SBOM launcher.sbom.cdx.json to /layers/sbom/launch/buildpacksio_lifecycle/launcher/sbom.cdx.json
2023/11/16 08:19:47.605844 [exporter] Copying SBOM launcher.sbom.spdx.json to /layers/sbom/launch/buildpacksio_lifecycle/launcher/sbom.spdx.json
2023/11/16 08:19:47.606016 [exporter] Copying SBOM launcher.sbom.syft.json to /layers/sbom/launch/buildpacksio_lifecycle/launcher/sbom.syft.json
2023/11/16 08:19:47.610263 [exporter] Reading buildpack directory: /layers/paketo-buildpacks_ca-certificates
2023/11/16 08:19:47.610438 [exporter] Reading buildpack directory item: helper
2023/11/16 08:19:47.610631 [exporter] Reading buildpack directory item: helper.sbom.syft.json
2023/11/16 08:19:47.610678 [exporter] Reading buildpack directory item: helper.toml
2023/11/16 08:19:47.610691 [exporter] Reading buildpack directory item: launch.toml
2023/11/16 08:19:47.610782 [exporter] Processing buildpack directory: /layers/paketo-buildpacks_ca-certificates
2023/11/16 08:19:47.613175 [exporter] Processing launch layer: /layers/paketo-buildpacks_ca-certificates/helper
2023/11/16 08:19:47.666949 [exporter] Reusing tarball for layer "paketo-buildpacks/ca-certificates:helper" with SHA: sha256:851e64e0b9a1b175546c9d925e1e7659c9b8776ee6fe96bb78cd995b001ea0ae
2023/11/16 08:19:47.667001 [exporter] Adding layer 'paketo-buildpacks/ca-certificates:helper'
...

---

Environment

pack info

Failing scenario:

root@66efbe60ab45:/app/use-dockerfile-extension# pack report
Pack:
  Version:  0.32.0
  OS/Arch:  linux/amd64

Default Lifecycle Version:  0.17.2

Supported Platform APIs:  0.3, 0.4, 0.5, 0.6, 0.7, 0.8, 0.9, 0.10, 0.11, 0.12

Config:
  experimental = true
  layout-repo-dir = "/root/.pack/layout-repo"

passing scenario:

❯ pack report
Pack:
  Version:  0.32.0+git-b12c9b3.build-5187
  OS/Arch:  darwin/arm64

Default Lifecycle Version:  0.17.2

Supported Platform APIs:  0.3, 0.4, 0.5, 0.6, 0.7, 0.8, 0.9, 0.10, 0.11, 0.12

Config:
  default-builder-image = "[REDACTED]"
  experimental = true
  layout-repo-dir = "/Users/aaron.fleckenstein/.pack/layout-repo"
  
  [[trusted-builders]]
    name = "[REDACTED]"
  
  [[trusted-builders]]
    name = "[REDACTED]"
                        

docker info

failing scenario:

Client:
 Version:    24.0.5
 Context:    default
 Debug Mode: false

Server:
 Containers: 3
  Running: 1
  Paused: 0
  Stopped: 2
 Images: 36
 Server Version: 24.0.2
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 3dce8eb055cbb6872793272b4f20ed16117344f8
 runc version: v1.1.7-0-g860f061
 init version: de40ad0
 Security Options:
  apparmor
  seccomp
   Profile: builtin
 Kernel Version: 5.15.0-1038-aws
 Operating System: Ubuntu 20.04.6 LTS
 OSType: linux
 Architecture: x86_64
 CPUs: 2
 Total Memory: 3.762GiB
 Name: runner-xhze-bxr-build-1700139995-c683f89a
 ID: ad2eec38-4388-4ed0-847a-1d9563a79090
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Labels:
  provider=amazonec2
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

passing scenario:

Client:
Version:    24.0.6
Context:    default
Debug Mode: false
Plugins:
 buildx: Docker Buildx (Docker Inc.)
   Version:  v0.11.2-desktop.5
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-buildx
 compose: Docker Compose (Docker Inc.)
   Version:  v2.23.0-desktop.1
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-compose
 dev: Docker Dev Environments (Docker Inc.)
   Version:  v0.1.0
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-dev
 extension: Manages Docker extensions (Docker Inc.)
   Version:  v0.2.20
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-extension
 init: Creates Docker-related starter files for your project (Docker Inc.)
   Version:  v0.1.0-beta.9
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-init
 sbom: View the packaged-based Software Bill Of Materials (SBOM) for an image (Anchore Inc.)
   Version:  0.6.0
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-sbom
 scan: Docker Scan (Docker Inc.)
   Version:  v0.26.0
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-scan
 scout: Docker Scout (Docker Inc.)
   Version:  v1.0.9
   Path:     /Users/aaron.fleckenstein/.docker/cli-plugins/docker-scout

Server:
Containers: 2
 Running: 2
 Paused: 0
 Stopped: 0
Images: 10
Server Version: 24.0.6
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Using metacopy: false
 Native Overlay Diff: true
 userxattr: false
Logging Driver: json-file
Cgroup Driver: cgroupfs
Cgroup Version: 2
Plugins:
 Volume: local
 Network: bridge host ipvlan macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: inactive
Runtimes: io.containerd.runc.v2 runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 8165feabfdfe38c65b599c4993d227328c231fca
runc version: v1.1.8-0-g82f18fe
init version: de40ad0
Security Options:
 seccomp
  Profile: unconfined
 cgroupns
Kernel Version: 6.4.16-linuxkit
Operating System: Docker Desktop
OSType: linux
Architecture: aarch64
CPUs: 10
Total Memory: 26.39GiB
Name: linuxkit-8afb52a7a04a
ID: 9ca4a62b-3847-4533-bcdf-4c513a2ef737
Docker Root Dir: /var/lib/docker
Debug Mode: false
HTTP Proxy: http.docker.internal:3128
HTTPS Proxy: http.docker.internal:3128
No Proxy: hubproxy.docker.internal
Experimental: false
Insecure Registries:
 hubproxy.docker.internal:5555
 127.0.0.0/8
Live Restore Enabled: false

[natalieparellano]

@a1flecke thanks for this - this is an interesting one. In your successful build log output, do you ever see log lines with prefix extender (run)? We are doing some acrobatics to copy the lifecycle binaries onto the run image when we extend the run image, and I suspect this doesn't play nicely with the way volume mounts are handled on linux.

[natalieparellano]

Potentially related: #850

Possible solution: we could create an "ephemeral" run image (similar to an ephemeral builder) to use for run image extension. This image would be the run image + the lifecycle binary layer from the lifecycle image. This is the right way to do it anyway. Presently we copy the /cnb directory from the restorer container and mount it into the extender container when we do run image extension.

[a1flecke]

@a1flecke thanks for this - this is an interesting one. In your successful build log output, do you ever see log lines with prefix extender (run)? We are doing some acrobatics to copy the lifecycle binaries onto the run image when we extend the run image, and I suspect this doesn't play nicely with the way volume mounts are handled on linux.

Yes I saw some. Here are some of them:

2023/11/16 09:48:57.689295 [extender (run)] Timer: Extender started at 2023-11-16T15:48:57Z
2023/11/16 09:48:57.689310 [extender (run)] Extending base image for run: index.docker.io/paketobuildpacks/run-jammy-full@sha256:c39efff9342708ed306228c202f59bc1e11f1ed10bb52b65845483c439bc0320
2023/11/16 09:48:57.689620 [extender (run)] Found run Dockerfile for extension 'custom-extension/audiowaveform'
2023/11/16 09:48:57.690150 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Building stage 'base@sha256:0426b5e8f536c335969931d963f701d36a7cc7c5c19e1752b1d949e80bca37dc' [idx: '0', base-idx: '-1']"
2023/11/16 09:48:57.690865 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Cmd: USER"
2023/11/16 09:48:57.691415 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Checking for cached layer oci:/kaniko/cache/layers/cached:c7c8f08c4886091dcbaaaee2e972537a6565162af76fa678207a02ac18f189e5..."
2023/11/16 09:48:57.691767 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="No cached layer found for cmd RUN apt-get update     && apt-get install -y software-properties-common     && add-apt-repository ppa:chris-needham/ppa     && apt-get update     && apt-get install -y audiowaveform ffmpeg     && apt-get clean"
2023/11/16 09:48:57.692095 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Cmd: USER"
2023/11/16 09:48:57.692267 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Unpacking rootfs as cmd RUN apt-get update     && apt-get install -y software-properties-common     && add-apt-repository ppa:chris-needham/ppa     && apt-get update     && apt-get install -y audiowaveform ffmpeg     && apt-get clean requires it."
2023/11/16 09:48:57.692295 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Skipping unpacking as no commands require it."
2023/11/16 09:48:57.692491 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="USER root"
2023/11/16 09:48:57.692569 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Cmd: USER"
2023/11/16 09:48:57.693014 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="No files changed in this command, skipping snapshotting."
2023/11/16 09:48:57.693400 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="RUN apt-get update     && apt-get install -y software-properties-common     && add-apt-repository ppa:chris-needham/ppa     && apt-get update     && apt-get install -y audiowaveform ffmpeg     && apt-get clean"
2023/11/16 09:48:57.693544 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Initializing snapshotter ..."
2023/11/16 09:48:57.693571 [extender (build)] time="2023-11-16T15:48:57Z" level=info msg="Taking snapshot of full filesystem..."
2023/11/16 09:48:57.699792 [extender (run)] Applying Dockerfile at /layers/generated/run/custom-extension_audiowaveform/Dockerfile to 'base@sha256:5aba372cea54257b2b5f8de3b4749744eed75afde1a14f14d817fbee26f6d9a0'...
2023/11/16 09:48:57.709851 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Built cross stage deps: map[]"
2023/11/16 09:48:57.710129 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Executing 0 build triggers"
2023/11/16 09:48:57.713893 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Building stage 'base@sha256:5aba372cea54257b2b5f8de3b4749744eed75afde1a14f14d817fbee26f6d9a0' [idx: '0', base-idx: '-1']"
2023/11/16 09:48:57.713955 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Cmd: USER"
2023/11/16 09:48:57.713962 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Checking for cached layer oci:/kaniko/cache/layers/cached:b4a0142170cd786eccc52621d60ba323dc674f09dcf82f43484905dbf70f0d39..."
2023/11/16 09:48:57.713966 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="No cached layer found for cmd RUN cp /etc/os-release /usr/lib/os-release"
2023/11/16 09:48:57.714363 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Cmd: USER"
2023/11/16 09:48:57.714672 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Unpacking rootfs as cmd RUN cp /etc/os-release /usr/lib/os-release requires it."
2023/11/16 09:48:57.714727 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Skipping unpacking as no commands require it."
2023/11/16 09:48:57.715008 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="USER root"
2023/11/16 09:48:57.715082 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Cmd: USER"
2023/11/16 09:48:57.715635 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="No files changed in this command, skipping snapshotting."
2023/11/16 09:48:57.715971 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="RUN cp /etc/os-release /usr/lib/os-release"
2023/11/16 09:48:57.716145 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Initializing snapshotter ..."
2023/11/16 09:48:57.716238 [extender (run)] time="2023-11-16T15:48:57Z" level=info msg="Taking snapshot of full filesystem..."
2023/11/16 09:49:10.652301 [extender (run)] time="2023-11-16T15:49:10Z" level=info msg="Cmd: /bin/sh"
2023/11/16 09:49:10.652351 [extender (run)] time="2023-11-16T15:49:10Z" level=info msg="Args: [-c cp /etc/os-release /usr/lib/os-release]"
2023/11/16 09:49:10.653905 [extender (run)] time="2023-11-16T15:49:10Z" level=info msg="Util.Lookup returned: &{Uid:0 Gid:0 Username:root Name:root HomeDir:/root}"
2023/11/16 09:49:10.653912 [extender (run)] time="2023-11-16T15:49:10Z" level=info msg="Performing slow lookup of group ids for root"
2023/11/16 09:49:10.654634 [extender (run)] time="2023-11-16T15:49:10Z" level=info msg="Running: [/bin/sh -c cp /etc/os-release /usr/lib/os-release]"
2023/11/16 09:49:10.694173 [extender (run)] time="2023-11-16T15:49:10Z" level=info msg="Taking snapshot of full filesystem..."

[natalieparellano]

Thanks for this - I think it's what I suspected, and we can fix it without monumental effort. I'll try to take a look in the next few days.

[a1flecke]

@natalieparellano any ETA on this? Any more information needed?

[natalieparellano]

@a1flecke apologies, I've been out unexpectedly and slow to pick this up. It's still on my list, but if anyone else has cycles to push it forward faster I can try to offer some guidance.

[a1flecke]

@natalieparellano Any updates? Is there a way that I could help here? I will be new to Go and the code base, but I learn quickly, especially if I have an example to follow.

[natalieparellano]

@a1flecke - apologies for the slow reply. I'll update this issue shortly with some breadcrumbs...