Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

WITH DOCKER with cached docker root dir #3399

Closed
vladaionescu opened this issue Oct 17, 2023 · 5 comments · Fixed by #4064
Closed

WITH DOCKER with cached docker root dir #3399

vladaionescu opened this issue Oct 17, 2023 · 5 comments · Fixed by #4064
Assignees
Labels
type:proposal A proposal for a new feature

Comments

@vladaionescu
Copy link
Member

vladaionescu commented Oct 17, 2023

Use case

Faster WITH DOCKER load times (at the cost of slightly less repeatability).

Expected Behavior

Currently WITH DOCKER wipes the Docker root dir on each invocation. This is great for ensuring that builds are repeatable - nothing in the pre-existing Docker state from a previous (like a previously loaded image) can affect the current to cause inconsistency.

That, unfortunately, comes at the cost of having to load all the images into the inner Docker on each run, an operation that takes time, even though it's just a local transfer.

This proposal introduces an option for the Docker root dir to be kept around between runs, in a similar manner to which users can use global cache directories via --id.

Possible syntax:

WITH DOCKER --cache-id=my-string --load ... --pull ...
  RUN ...
END

The --cache-id option does three things:

  1. Skips the removal of the dockerd data root at the end of WITH DOCKER.
  2. Reuses an existing dockerd data root with the user-provided ID, if it already exists, instead of creating a new one
  3. For added repeatability, resets the Docker state between runs as much as possible, without removing image layers. For example, by re-tagging existing images, deleting old stopped containers, old networks, old volumes etc. Keeping the layers helps with caching, while resetting everything else maintains repeatability to some extent.

Possible extensions:

  • Having different modes of sharing the Docker instance between targets or parallel runs similar to the way there are different cache locking options for type=cache mounts.

Challenges

An implementation challenge is the fact that keeping the Docker root dirs around requires that they are managed and GC'd appropriately, in a similar manner that Buildkit manages the cache. These root dirs cannot be part of Buildkit's cache management, though, because of the inherent limitation that Buildkit operates on overlayfs, and the Docker root dir has to also be overlayfs, and you can't put overlayfs on top of overlayfs.

For this reason, the lifecycle of these Docker root dirs needs to be managed separately within Earthly's buildkit fork.

A v0 / initial experimental version of this feature could perhaps rely on manual-only clearing of Docker root dirs (via some Earthly command) and not require that we implement automatic GCing for it.

A v1 version could maintain a last-used timestamp in these directories and clean old entries on Buildkit startup (e.g. older than 14 days).

@vladaionescu vladaionescu added the type:proposal A proposal for a new feature label Oct 17, 2023
@ingwarsw
Copy link
Contributor

ingwarsw commented Oct 18, 2023

For now I was able to make really fast working setup with CACHE + WITH DOCKER seems like its working with overlay really fine.

Because we are using cache I think that Buildkit should take care of cleaning it?
@vladaionescu You thing im correct?

Something like.

test:
  CACHE --sharing=shared /static-ingwar
  WITH DOCKER --any-flags
     RUN anything
  END

Assuming that I have did 2 changes in docker-wrapper..
Changed data_root to /static-ingwar/test (seems like it dont like to be on root of mount point or its slow as hell, still need to debug that part)
and commented out wipe_data_root

What I would have to do is to add --cache switch to WITH DOCKER and use cache under the hood.

@ingwarsw
Copy link
Contributor

ingwarsw commented Oct 18, 2023

Full log of CACHE + WITH DOCKER
Time dropped to 1s from ~ 50s cause now it have to download only layers that changed..

           # mount
           +kbt-test | overlay on /static-ingwar type overlay (rw,relatime,lowerdir=/tmp/earthly/buildkit/runc-overlayfs/snapshots/snapshots/67/fs,upperdir=/tmp/earthly/buildkit/runc-overlayfs/snapshots/snapshots/1341/fs,workdir=/tmp/earthly/buildkit/runc-overlayfs/snapshots/snapshots/1341/work)
          ...
           +kbt-test | Starting dockerd with data root /static-ingwar/test
           +kbt-test | Loading images from BuildKit via embedded registry...
           +kbt-test | Pulling 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-3 and retagging as bitnami/kafka:latest
           +kbt-test | Pulling 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-0 and retagging as gcr.io/kentik-continuous-delivery/kentik-alert-manager:local
           +kbt-test | Pulling 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-1 and retagging as gcr.io/kentik-continuous-delivery/notify-mock:local
           +kbt-test | Pulling 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-2 and retagging as gcr.io/kentik-continuous-delivery/tests/db-alert_manager:master
           +kbt-test | img-1: Pulling from sess-ycacdro6zpyxmjp08payjy704
           +kbt-test | img-3: Pulling from sess-ycacdro6zpyxmjp08payjy704
           +kbt-test | img-0: Pulling from sess-ycacdro6zpyxmjp08payjy704
           +kbt-test | fc521c5b9835: Already exists
           +kbt-test | img-2: Pulling from sess-ycacdro6zpyxmjp08payjy704
           +kbt-test | Digest: sha256:96a1c81a01f39d74fc61e86ffd92d906692ed396a09c66979afc2f58ca5ba269
           +kbt-test | a378f10b3218: 1d83105b0be6: Already exists
           +kbt-test | Already exists
           +kbt-test | Digest: sha256:fdd8d70d7bc4171ef76cf6a0b9717a54e886e5c8f92b383630dd1bbc7426c999
           +kbt-test | Status: Downloaded newer image for 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-1
           +kbt-test | 3ae46626af9d: Already exists
           +kbt-test | Status: Downloaded newer image for 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-3
           +kbt-test | 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-1
           +kbt-test | b596f0727bd2: Already exists
           +kbt-test | 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-3
           +kbt-test | a3ca8ddad466: Already exists
           +kbt-test | 518363397b30: Already exists
           +kbt-test | 6e0e6cf3ae2b: Already exists
           +kbt-test | cb81eb851b5c: Already exists
           +kbt-test | d4f0c91b5558: Already exists
           +kbt-test | 911186b89876: Already exists
           +kbt-test | ace5692d59be: Already exists
           +kbt-test | e349449e780b: Already exists
           +kbt-test | 19b7f523271d: Already exists
           +kbt-test | 36522ec6e0bd: Already exists
           +kbt-test | dec3f4c35148: Already exists
           +kbt-test | Untagged: 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-3
           +kbt-test | Untagged: 172.30.0.1:xxxxx@sha256:fdd8d70d7bc4171ef76cf6a0b9717a54e886e5c8f92b383630dd1bbc7426c999
           +kbt-test | 37f3833c9f88: Already exists
           +kbt-test | Untagged: 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-1
           +kbt-test | Untagged: 172.30.0.1:xxxxx@sha256:96a1c81a01f39d74fc61e86ffd92d906692ed396a09c66979afc2f58ca5ba269
           +kbt-test | 9a53aadebb04: Already exists
           +kbt-test | be52d85e2b91: Pulling fs layer
           +kbt-test | 2fd8d4b4df9d: Already exists
           +kbt-test | 665564a81906: Already exists
           +kbt-test | b69c79506eb3: Already exists
           +kbt-test | a433f9c93365: Already exists
           +kbt-test | 97035bb88a84: Already exists
           +kbt-test | b9619e4639bf: Already exists
           +kbt-test | ec9fde35224d: Already exists
           +kbt-test | 68c8f994b636: Already exists
           +kbt-test | 9452d9340a03: Already exists
           +kbt-test | 4f4fb700ef54: Already exists
           +kbt-test | c70ed36610b7: Already exists
           +kbt-test | 8a5a786ae1ca: Already exists
           +kbt-test | 6fe0a2b35968: Already exists
           +kbt-test | be52d85e2b91: Verifying Checksum
           +kbt-test | be52d85e2b91: Download complete
           +kbt-test | Digest: sha256:30eea101a9ebf8bfdc2c36590e08cf05a9fa5de90fce54c2480f69d74ed1ba5f
           +kbt-test | Status: Downloaded newer image for 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-2
           +kbt-test | 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-2
           +kbt-test | Untagged: 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-2
           +kbt-test | Untagged: 172.30.0.1:xxxxx@sha256:30eea101a9ebf8bfdc2c36590e08cf05a9fa5de90fce54c2480f69d74ed1ba5f
           +kbt-test | be52d85e2b91: Pull complete
           +kbt-test | Digest: sha256:a66e9f89dabaafb22dc90d532593f59c038d982d0ae26c5f2d6d820a91c44406
           +kbt-test | Status: Downloaded newer image for 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-0
           +kbt-test | 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-0
           +kbt-test | Untagged: 172.30.0.1:8371/sess-ycacdro6zpyxmjp08payjy704:img-0
           +kbt-test | Untagged: 172.30.0.1:xxxxx@sha256:a66e9f89dabaafb22dc90d532593f59c038d982d0ae26c5f2d6d820a91c44406
           +kbt-test | Loading images done in 1211 ms

@vladaionescu
Copy link
Member Author

I suspect that dockerd uses another storage driver in this case (although I could be wrong). Can you show the dockerd logs too?

@ingwarsw
Copy link
Contributor

Dockerd logs
           +kbt-test | time="2023-10-19T08:21:45.912908459Z" level=info msg="Starting up"
           +kbt-test | time="2023-10-19T08:21:45.913654876Z" level=info msg="containerd not running, starting managed containerd"
           +kbt-test | time="2023-10-19T08:21:45.914692376Z" level=info msg="started new containerd process" address=/var/run/docker/containerd/containerd.sock module=libcontainerd pid=40
           +kbt-test | time="2023-10-19T08:21:45.941105334Z" level=info msg="starting containerd" revision=61f9fd88f79f081d64d6fa3bb1a0dc71ec870523 version=1.6.24
           +kbt-test | time="2023-10-19T08:21:45.947802043Z" level=info msg="loading plugin \"io.containerd.content.v1.content\"..." type=io.containerd.content.v1
           +kbt-test | time="2023-10-19T08:21:45.947842918Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.aufs\"..." type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948140709Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.aufs\"..." error="aufs is not supported (modprobe aufs failed: exec: \"modprobe\": executable file not found in $PATH \"\"): skip plugin" type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948153168Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948327084Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." error="path /static-ingwar/test/containerd/daemon/io.containerd.snapshotter.v1.btrfs (overlay) must be a btrfs filesystem to be used with the btrfs snapshotter: skip plugin" type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948399084Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948406376Z" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.devmapper" error="devmapper not configured"
           +kbt-test | time="2023-10-19T08:21:45.948411793Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.native\"..." type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948431543Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.overlayfs\"..." type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948522376Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.zfs\"..." type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948670293Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.zfs\"..." error="path /static-ingwar/test/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter: skip plugin" type=io.containerd.snapshotter.v1
           +kbt-test | time="2023-10-19T08:21:45.948678543Z" level=info msg="loading plugin \"io.containerd.metadata.v1.bolt\"..." type=io.containerd.metadata.v1
           +kbt-test | time="2023-10-19T08:21:45.948690626Z" level=warning msg="could not use snapshotter devmapper in metadata plugin" error="devmapper not configured"
           +kbt-test | time="2023-10-19T08:21:45.948696251Z" level=info msg="metadata content store policy set" policy=shared
           +kbt-test | time="2023-10-19T08:21:45.949047126Z" level=info msg="loading plugin \"io.containerd.differ.v1.walking\"..." type=io.containerd.differ.v1
           +kbt-test | time="2023-10-19T08:21:45.949059959Z" level=info msg="loading plugin \"io.containerd.event.v1.exchange\"..." type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:21:45.949068626Z" level=info msg="loading plugin \"io.containerd.gc.v1.scheduler\"..." type=io.containerd.gc.v1
           +kbt-test | time="2023-10-19T08:21:45.949085876Z" level=info msg="loading plugin \"io.containerd.service.v1.introspection-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949093376Z" level=info msg="loading plugin \"io.containerd.service.v1.containers-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949101334Z" level=info msg="loading plugin \"io.containerd.service.v1.content-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949107501Z" level=info msg="loading plugin \"io.containerd.service.v1.diff-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949117543Z" level=info msg="loading plugin \"io.containerd.service.v1.images-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949134751Z" level=info msg="loading plugin \"io.containerd.service.v1.leases-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949143126Z" level=info msg="loading plugin \"io.containerd.service.v1.namespaces-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949152751Z" level=info msg="loading plugin \"io.containerd.service.v1.snapshots-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949159126Z" level=info msg="loading plugin \"io.containerd.runtime.v1.linux\"..." type=io.containerd.runtime.v1
           +kbt-test | time="2023-10-19T08:21:45.949242084Z" level=info msg="loading plugin \"io.containerd.runtime.v2.task\"..." type=io.containerd.runtime.v2
           +kbt-test | time="2023-10-19T08:21:45.949319959Z" level=info msg="loading plugin \"io.containerd.monitor.v1.cgroups\"..." type=io.containerd.monitor.v1
           +kbt-test | time="2023-10-19T08:21:45.949828459Z" level=info msg="loading plugin \"io.containerd.service.v1.tasks-service\"..." type=io.containerd.service.v1
           +kbt-test | time="2023-10-19T08:21:45.949841501Z" level=info msg="loading plugin \"io.containerd.grpc.v1.introspection\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949848084Z" level=info msg="loading plugin \"io.containerd.internal.v1.restart\"..." type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:21:45.949888751Z" level=info msg="loading plugin \"io.containerd.grpc.v1.containers\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949896834Z" level=info msg="loading plugin \"io.containerd.grpc.v1.content\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949902834Z" level=info msg="loading plugin \"io.containerd.grpc.v1.diff\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949908751Z" level=info msg="loading plugin \"io.containerd.grpc.v1.events\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949915043Z" level=info msg="loading plugin \"io.containerd.grpc.v1.healthcheck\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949923543Z" level=info msg="loading plugin \"io.containerd.grpc.v1.images\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949929668Z" level=info msg="loading plugin \"io.containerd.grpc.v1.leases\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949935626Z" level=info msg="loading plugin \"io.containerd.grpc.v1.namespaces\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.949946209Z" level=info msg="loading plugin \"io.containerd.internal.v1.opt\"..." type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:21:45.950117293Z" level=info msg="loading plugin \"io.containerd.grpc.v1.snapshots\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.950125376Z" level=info msg="loading plugin \"io.containerd.grpc.v1.tasks\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.950131293Z" level=info msg="loading plugin \"io.containerd.grpc.v1.version\"..." type=io.containerd.grpc.v1
           +kbt-test | time="2023-10-19T08:21:45.950136959Z" level=info msg="loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." type=io.containerd.tracing.processor.v1
           +kbt-test | time="2023-10-19T08:21:45.950144459Z" level=info msg="skip loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." error="no OpenTelemetry endpoint: skip plugin" type=io.containerd.tracing.processor.v1
           +kbt-test | time="2023-10-19T08:21:45.950152834Z" level=info msg="loading plugin \"io.containerd.internal.v1.tracing\"..." type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:21:45.950170334Z" level=error msg="failed to initialize a tracing processor \"otlp\"" error="no OpenTelemetry endpoint: skip plugin"
           +kbt-test | time="2023-10-19T08:21:45.950319959Z" level=info msg=serving... address=/var/run/docker/containerd/containerd-debug.sock
           +kbt-test | time="2023-10-19T08:21:45.950365834Z" level=info msg=serving... address=/var/run/docker/containerd/containerd.sock.ttrpc
           +kbt-test | time="2023-10-19T08:21:45.950401251Z" level=info msg=serving... address=/var/run/docker/containerd/containerd.sock
           +kbt-test | time="2023-10-19T08:21:45.950410418Z" level=info msg="containerd successfully booted in 0.009909s"
           +kbt-test | time="2023-10-19T08:21:45.964796501Z" level=error msg="failed to mount overlay: invalid argument" storage-driver=overlay2
           +kbt-test | time="2023-10-19T08:21:45.964947751Z" level=error msg="exec: \"fuse-overlayfs\": executable file not found in $PATH" storage-driver=fuse-overlayfs
           +kbt-test | time="2023-10-19T08:21:45.977577709Z" level=info msg="Loading containers: start."
           +kbt-test | time="2023-10-19T08:21:46.101681501Z" level=info msg="Loading containers: done."
           +kbt-test | time="2023-10-19T08:21:46.107048918Z" level=warning msg="WARNING: No swap limit support"
           +kbt-test | time="2023-10-19T08:21:46.107070293Z" level=info msg="Docker daemon" commit=1a79695 graphdriver=vfs version=24.0.6
           +kbt-test | time="2023-10-19T08:21:46.107152876Z" level=info msg="Daemon has completed initialization"
           +kbt-test | time="2023-10-19T08:21:46.130288668Z" level=info msg="API listen on /var/run/docker.sock"
           +kbt-test | time="2023-10-19T08:21:46.970148043Z" level=warning msg="Error getting v2 registry: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:46.970172585Z" level=info msg="Attempting next endpoint for pull after error: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:46.972151793Z" level=warning msg="Error getting v2 registry: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:46.972172126Z" level=info msg="Attempting next endpoint for pull after error: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:46.973587543Z" level=warning msg="Error getting v2 registry: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:46.973603293Z" level=info msg="Attempting next endpoint for pull after error: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:46.978408501Z" level=warning msg="Error getting v2 registry: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:46.978433585Z" level=info msg="Attempting next endpoint for pull after error: Get \"https://172.30.0.1:8371/v2/\": http: server gave HTTP response to HTTPS client"
           +kbt-test | time="2023-10-19T08:21:48.423306044Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:21:48.423348335Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:21:48.423353960Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
           +kbt-test | time="2023-10-19T08:21:48.423533835Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/ab5fd490a0932a325a33560b60f6576140ad28d1cbfe7d37a2dae15915d10392 pid=418 runtime=io.containerd.runc.v2
           +kbt-test | time="2023-10-19T08:21:49.293231586Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:21:49.293277627Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:21:49.293283377Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
           +kbt-test | time="2023-10-19T08:21:49.293752127Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/a30934083cff7cad944eed930ba114233f43aaeaf11b6aea665d4ca290df61f8 pid=508 runtime=io.containerd.runc.v2
           +kbt-test | time="2023-10-19T08:21:51.982980545Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:21:51.983036337Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:21:51.983042337Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
           +kbt-test | time="2023-10-19T08:21:51.983243754Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/c443d5eff7180716e274181d91f758d6f5d704c1b4d630d4d018951e6b24995b pid=1610 runtime=io.containerd.runc.v2
           +kbt-test | time="2023-10-19T08:21:55.041568839Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:21:55.041630547Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:21:55.041636880Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
           +kbt-test | time="2023-10-19T08:21:55.041828214Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/ce579fec1b5c5d23bd23b9c0924f176cb55005d5f06b0b87b881cbb382a8bb1c pid=2857 runtime=io.containerd.runc.v2
           +kbt-test | time="2023-10-19T08:21:58.803984674Z" level=info msg="ignoring event" container=c443d5eff7180716e274181d91f758d6f5d704c1b4d630d4d018951e6b24995b module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
           +kbt-test | time="2023-10-19T08:21:58.804003549Z" level=info msg="shim disconnected" id=c443d5eff7180716e274181d91f758d6f5d704c1b4d630d4d018951e6b24995b
           +kbt-test | time="2023-10-19T08:21:58.804110965Z" level=warning msg="cleaning up after shim disconnected" id=c443d5eff7180716e274181d91f758d6f5d704c1b4d630d4d018951e6b24995b namespace=moby
           +kbt-test | time="2023-10-19T08:21:58.804122424Z" level=info msg="cleaning up dead shim"
           +kbt-test | time="2023-10-19T08:21:58.816243799Z" level=warning msg="cleanup warnings time=\"2023-10-19T08:21:58Z\" level=info msg=\"starting signal loop\" namespace=moby pid=3809 runtime=io.containerd.runc.v2\n"
           +kbt-test | time="2023-10-19T08:22:26.497877173Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:22:26.497922673Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:22:26.497928339Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
           +kbt-test | time="2023-10-19T08:22:26.498128089Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/c45935773271e0eec4874258ff7e46dd5cc4df28b3f41fb9ada79030c32c6c3b pid=5164 runtime=io.containerd.runc.v2
           +kbt-test | time="2023-10-19T08:22:26.514399506Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:22:26.514454506Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:22:26.514460423Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
           +kbt-test | time="2023-10-19T08:22:26.514689173Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/bdb8beac48be2ef21549d4a8d947a145c0d085c163b826da2ed16374e18e2922 pid=5233 runtime=io.containerd.runc.v2
           +kbt-test | time="2023-10-19T08:22:26.525076548Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
           +kbt-test | time="2023-10-19T08:22:26.525130173Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
           +kbt-test | time="2023-10-19T08:22:26.525136464Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
           +kbt-test | time="2023-10-19T08:22:26.525370256Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/b70433673b615dcaed544f2925f73d7a8a9c3625297aec19b1b157863ae35d6a pid=5266 runtime=io.containerd.runc.v2
           +kbt-test | time="2023-10-19T08:22:27.028854423Z" level=info msg="ignoring event" container=ab5fd490a0932a325a33560b60f6576140ad28d1cbfe7d37a2dae15915d10392 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
           +kbt-test | time="2023-10-19T08:22:27.028870006Z" level=info msg="shim disconnected" id=ab5fd490a0932a325a33560b60f6576140ad28d1cbfe7d37a2dae15915d10392
           +kbt-test | time="2023-10-19T08:22:27.028911923Z" level=warning msg="cleaning up after shim disconnected" id=ab5fd490a0932a325a33560b60f6576140ad28d1cbfe7d37a2dae15915d10392 namespace=moby
           +kbt-test | time="2023-10-19T08:22:27.028919590Z" level=info msg="cleaning up dead shim"
           +kbt-test | time="2023-10-19T08:22:27.036796215Z" level=warning msg="cleanup warnings time=\"2023-10-19T08:22:27Z\" level=info msg=\"starting signal loop\" namespace=moby pid=5465 runtime=io.containerd.runc.v2\n"
           +kbt-test | time="2023-10-19T08:22:28.056533298Z" level=info msg="shim disconnected" id=bdb8beac48be2ef21549d4a8d947a145c0d085c163b826da2ed16374e18e2922
           +kbt-test | time="2023-10-19T08:22:28.056601507Z" level=warning msg="cleaning up after shim disconnected" id=bdb8beac48be2ef21549d4a8d947a145c0d085c163b826da2ed16374e18e2922 namespace=moby
           +kbt-test | time="2023-10-19T08:22:28.056615173Z" level=info msg="cleaning up dead shim"
           +kbt-test | time="2023-10-19T08:22:28.056526382Z" level=info msg="ignoring event" container=bdb8beac48be2ef21549d4a8d947a145c0d085c163b826da2ed16374e18e2922 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
           +kbt-test | time="2023-10-19T08:22:28.061997382Z" level=info msg="shim disconnected" id=c45935773271e0eec4874258ff7e46dd5cc4df28b3f41fb9ada79030c32c6c3b
           +kbt-test | time="2023-10-19T08:22:28.062054007Z" level=warning msg="cleaning up after shim disconnected" id=c45935773271e0eec4874258ff7e46dd5cc4df28b3f41fb9ada79030c32c6c3b namespace=moby
           +kbt-test | time="2023-10-19T08:22:28.062065382Z" level=info msg="cleaning up dead shim"
           +kbt-test | time="2023-10-19T08:22:28.062193382Z" level=info msg="ignoring event" container=c45935773271e0eec4874258ff7e46dd5cc4df28b3f41fb9ada79030c32c6c3b module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
           +kbt-test | time="2023-10-19T08:22:28.067115465Z" level=info msg="shim disconnected" id=b70433673b615dcaed544f2925f73d7a8a9c3625297aec19b1b157863ae35d6a
           +kbt-test | time="2023-10-19T08:22:28.067175465Z" level=warning msg="cleaning up after shim disconnected" id=b70433673b615dcaed544f2925f73d7a8a9c3625297aec19b1b157863ae35d6a namespace=moby
           +kbt-test | time="2023-10-19T08:22:28.067187090Z" level=info msg="cleaning up dead shim"
           +kbt-test | time="2023-10-19T08:22:28.067205757Z" level=info msg="ignoring event" container=b70433673b615dcaed544f2925f73d7a8a9c3625297aec19b1b157863ae35d6a module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
           +kbt-test | time="2023-10-19T08:22:28.071855548Z" level=warning msg="cleanup warnings time=\"2023-10-19T08:22:28Z\" level=info msg=\"starting signal loop\" namespace=moby pid=5508 runtime=io.containerd.runc.v2\n"
           +kbt-test | time="2023-10-19T08:22:28.073757548Z" level=warning msg="failed to close stdin: task bdb8beac48be2ef21549d4a8d947a145c0d085c163b826da2ed16374e18e2922 not found: not found"
           +kbt-test | time="2023-10-19T08:22:28.075706632Z" level=warning msg="cleanup warnings time=\"2023-10-19T08:22:28Z\" level=info msg=\"starting signal loop\" namespace=moby pid=5514 runtime=io.containerd.runc.v2\n"
           +kbt-test | time="2023-10-19T08:22:28.076970340Z" level=warning msg="failed to close stdin: task c45935773271e0eec4874258ff7e46dd5cc4df28b3f41fb9ada79030c32c6c3b not found: not found"
           +kbt-test | time="2023-10-19T08:22:28.080101923Z" level=warning msg="cleanup warnings time=\"2023-10-19T08:22:28Z\" level=info msg=\"starting signal loop\" namespace=moby pid=5525 runtime=io.containerd.runc.v2\n"
           +kbt-test | time="2023-10-19T08:22:28.081176298Z" level=warning msg="failed to close stdin: task b70433673b615dcaed544f2925f73d7a8a9c3625297aec19b1b157863ae35d6a not found: not found"
           +kbt-test | time="2023-10-19T08:22:29.184706049Z" level=info msg="shim disconnected" id=a30934083cff7cad944eed930ba114233f43aaeaf11b6aea665d4ca290df61f8
           +kbt-test | time="2023-10-19T08:22:29.184759799Z" level=warning msg="cleaning up after shim disconnected" id=a30934083cff7cad944eed930ba114233f43aaeaf11b6aea665d4ca290df61f8 namespace=moby
           +kbt-test | time="2023-10-19T08:22:29.184768549Z" level=info msg="cleaning up dead shim"
           +kbt-test | time="2023-10-19T08:22:29.184754216Z" level=info msg="ignoring event" container=a30934083cff7cad944eed930ba114233f43aaeaf11b6aea665d4ca290df61f8 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
           +kbt-test | time="2023-10-19T08:22:29.193294507Z" level=warning msg="cleanup warnings time=\"2023-10-19T08:22:29Z\" level=info msg=\"starting signal loop\" namespace=moby pid=5616 runtime=io.containerd.runc.v2\n"
           +kbt-test | time="2023-10-19T08:22:38.304307928Z" level=info msg="Container failed to exit within 10s of signal 2 - using the force" container=ce579fec1b5c5d23bd23b9c0924f176cb55005d5f06b0b87b881cbb382a8bb1c
           +kbt-test | time="2023-10-19T08:22:38.338342428Z" level=info msg="ignoring event" container=ce579fec1b5c5d23bd23b9c0924f176cb55005d5f06b0b87b881cbb382a8bb1c module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
           +kbt-test | time="2023-10-19T08:22:38.338582595Z" level=info msg="shim disconnected" id=ce579fec1b5c5d23bd23b9c0924f176cb55005d5f06b0b87b881cbb382a8bb1c
           +kbt-test | time="2023-10-19T08:22:38.338630553Z" level=warning msg="cleaning up after shim disconnected" id=ce579fec1b5c5d23bd23b9c0924f176cb55005d5f06b0b87b881cbb382a8bb1c namespace=moby
           +kbt-test | time="2023-10-19T08:22:38.338639053Z" level=info msg="cleaning up dead shim"
           +kbt-test | time="2023-10-19T08:22:38.348604928Z" level=warning msg="cleanup warnings time=\"2023-10-19T08:22:38Z\" level=info msg=\"starting signal loop\" namespace=moby pid=5654 runtime=io.containerd.runc.v2\n"
           +kbt-test | time="2023-10-19T08:22:39.459713595Z" level=info msg="Processing signal 'terminated'"
           +kbt-test | time="2023-10-19T08:22:39.460578970Z" level=info msg="stopping event stream following graceful shutdown" error="<nil>" module=libcontainerd namespace=moby
           +kbt-test | time="2023-10-19T08:22:39.460812179Z" level=info msg="Daemon shutdown complete"
           +kbt-test | time="2023-10-19T08:22:39.460870512Z" level=info msg="stopping event stream following graceful shutdown" error="context canceled" module=libcontainerd namespace=plugins.moby
           +kbt-test | time="2023-10-19T08:22:39.460874512Z" level=info msg="stopping healthcheck following graceful shutdown" module=libcontainerd

@vladaionescu
Copy link
Member Author

vladaionescu commented Oct 20, 2023

Yeah, it seems that in this case Dockerd doesn't use overlayfs based on this line

           +kbt-test | time="2023-10-19T08:21:46.107070293Z" level=info msg="Docker daemon" commit=1a79695 graphdriver=vfs version=24.0.6

This has many disadvantages... the main one being that it tends to fill the disk very quickly as it is not a union filesystem. Read more about it here.

The vfs storage driver is intended for testing purposes, and for situations where no copy-on-write filesystem can be used. Performance of this storage driver is poor, and is not generally recommended for production use.

From here

@alexcb alexcb self-assigned this Apr 22, 2024
alexcb added a commit that referenced this issue May 3, 2024
Introduces a new `WITH DOCKER --cache-id=<name>` flag, which when
specified will cache the daya layers from the docker data-root
between runs, even when dependencies have changed.

Note that the docker image tags are NOT cached; and a user will still
have to re-load the image (via the WITH DOCKER --load or --pull flags);
however, since the data layers are cached, the re-tagging should be much
faster.

fixes #3399 #3485
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type:proposal A proposal for a new feature
Projects
Status: Done
Development

Successfully merging a pull request may close this issue.

3 participants