Q: Performance expectations with storing go-cache in remote registry?

[genevieve]

What happened?

• What were you attempting to do?

Using the new pack cli's --publish and --cache-image flags to store an image in a remote registry and pull down the cache for reuse on rebuilds.

• What did you expect to happen?

I think I expected this to be fast albeit not as fast as local caches. Since our CI's local cache reuse is not always stable, we were interested in using the pack supported way with a remote registry for reuse in CI jobs for the same app code sha. I was really surprised by how much more time was added to the build just due to storing the gocache in the remote registry. Sharing the timestamped logs here in case there's anything you can think of to improve it.

• What was the actual behavior? Please provide log output, if possible.

About 2 minutes of a 3 minute rebuild was spent here:

2021/04/09 17:19:48.230688 Reusing cache layer 'paketo-buildpacks/go-dist:go'
Layer 'paketo-buildpacks/go-dist:go' SHA: sha256:78473bd74cb16be010b30de44123937411ec5345e6487592948af576322e843f
2021/04/09 17:19:49.566066 Adding cache layer 'paketo-buildpacks/go-build:gocache'
Layer 'paketo-buildpacks/go-build:gocache' SHA: sha256:dff9783e8c4c0218288ea0707c752f8cb6f2853da6bf5a24f9b1f1dbec9b100e
2021/04/09 17:21:54.751842 ...

While this is a small go app, I'm concerned about larger go apps that we have.

Build Configuration

• What platform (pack, kpack, tekton buildpacks plugin, etc.) are you
  using? Please include a version.

pack v0.18.0

• What buildpacks are you using? Please include versions.

2021/04/09 17:19:21.124298 Paketo Go Distribution Buildpack 0.3.1

2021/04/09 17:19:21.130936 Paketo Go Mod Vendor Buildpack 0.2.0

2021/04/09 17:19:21.135420 Paketo Go Build Buildpack 0.3.0

• What builder are you using? If custom, can you provide the output from pack inspect-builder <builder>?

Default builder from paketo in pack

• Can you provide a sample app or relevant configuration (buildpack.yml,
  nginx.conf, etc.)?

github.com/genevieve/leftovers

Checklist

• I have included log output.
• The log output includes an error message.
• I have included steps for reproduction.

[genevieve]

I've been repeatedly building the same go app using the --publish && --cache-image flags from pack so the cache is stored entirely in the remote registry. This latest runs numbers:

• 40s to restore the go cache
• 3min to upload the go cache

2021/04/13 09:31:34.507026 v0.1.3: 2021/04/13 09:31:34.507179 Pulling from builder
2021/04/13 09:31:34.507197 2021/04/13 09:31:34.508921 Digest: sha256:6b31673b8cd71e7f8155ca682193c8a1fca527d35ebf1806439da01d0737f6f7
2021/04/13 09:31:34.508948 Status: Image is up to date for builder
2021/04/13 09:31:39.568205 ===> DETECTING
2021/04/13 09:31:39.676235 3 of 6 buildpacks participating
paketo-buildpacks/go-dist       0.3.1
2021/04/13 09:31:39.676424 paketo-buildpacks/go-mod-vendor 0.2.0
2021/04/13 09:31:39.676675 paketo-buildpacks/go-build      0.3.0
===> ANALYZING
2021/04/13 09:31:40.925001 Restoring metadata for "paketo-buildpacks/go-dist:go" from cache
2021/04/13 09:31:40.925397 Restoring metadata for "paketo-buildpacks/go-build:gocache" from cache
2021/04/13 09:31:40.925593 ===> RESTORING
2021/04/13 09:31:41.257342 Restoring data for "paketo-buildpacks/go-dist:go" from cache
2021/04/13 09:31:41.257574 Restoring data for "paketo-buildpacks/go-build:gocache" from cache
2021/04/13 09:32:14.531353 ===> BUILDING
2021/04/13 09:32:14.536621 Paketo Go Distribution Buildpack 0.3.1
  Resolving Go version
    Candidate version sources (in priority order):
      go.mod    -> ">= 1.16"
      <unknown> -> ""

2021/04/13 09:32:14.537178     Selected Go version (using go.mod): 1.16.1

2021/04/13 09:32:14.537192   Reusing cached layer /layers/paketo-buildpacks_go-dist/go

2021/04/13 09:32:14.543928 Paketo Go Mod Vendor Buildpack 0.2.0
  Skipping build process: modules are already vendored

2021/04/13 09:32:14.548782 Paketo Go Build Buildpack 0.3.0
2021/04/13 09:32:14.549151   Executing build process
    Running 'go build -o /layers/paketo-buildpacks_go-build/targets/bin "-ldflags=-extldflags '-f no-PIC -static'" -tags=osusergo,netgo -buildmode pie ./cmd/app'
2021/04/13 09:32:16.738635       Completed in 2.192s

2021/04/13 09:32:17.284411   Assigning launch processes
    web: /layers/paketo-buildpacks_go-build/targets/bin/app
2021/04/13 09:32:17.289497 ===> EXPORTING
2021/04/13 09:32:17.289515 Reusing layers from image '***@sha256:85a5f8f55332d3884a19f7a177123e2b04dab648bd9b1677f5b0e885d9312bab'
2021/04/13 09:32:18.525648 Adding layer 'paketo-buildpacks/go-build:targets'
2021/04/13 09:32:19.518405 Adding 1/1 app layer(s)
2021/04/13 09:32:19.528613 Adding layer 'launcher'
2021/04/13 09:32:19.591082 Adding layer 'config'
2021/04/13 09:32:19.591844 Adding layer 'process-types'
2021/04/13 09:32:19.601680 Adding label 'io.buildpacks.lifecycle.metadata'
2021/04/13 09:32:19.604922 Adding label 'io.buildpacks.build.metadata'
2021/04/13 09:32:19.605531 Adding label 'io.buildpacks.project.metadata'
2021/04/13 09:32:19.607884 Setting default process type 'web'
2021/04/13 09:32:22.901052 *** Images (sha256:ec698e48e14176cc91512ccb727afb493eb3c65e5191dfef269d29a57216def8):
      ***
2021/04/13 09:32:25.446073 Reusing cache layer 'paketo-buildpacks/go-dist:go'
2021/04/13 09:32:27.278339 Adding cache layer 'paketo-buildpacks/go-build:gocache'
2021/04/13 09:35:30.256907 Successfully built image ***

[ryanmoran]

Unfortunately, this is all out of our control. The cache and its storage in a remote registry is a CNB platform/lifecycle concern. The buildpack can only optimize those steps that occur during the detect (100ms) and build (~3s) phases. The restore and export phases are handled by the lifecycle and platform and will vary depending upon what the buildpack marks as cached layers and where that cache is stored. In your case, the cache is being retrieved across the network which likely explains its slow performance. Have you discussed this with the CNB team in an issue or on their Slack instance?

[genevieve]

I have been chatting with @ekcasey and she mentioned a few things:

1. If the cache is truly unchanged the lifecycle shouldn’t need to reupload at all. If its reuploading identical layers, this would be an issue for the lifecycle. Question: how to determine if the cache is truly unchanged? If the app code is unchanged, is the go-cache still changing in some way?
2. If there is a small diff, the lifecycle unfortunately must reupload the entire layer. This is because of the nature of the registry API. The smallest atomic unit of an image is a blob and we cannot create a new layer from what I will chose to call a blob delta.
3. The buildpack could attempt to decompose the go cache into several layers but this would be weird.

[genevieve]

Is there any possibility that the cache is being changed by the buildpack even when nothing has changed in the app? The cache size is 290 MB for the app we are testing above. I wouldn't expect it to take 2-3 minutes to reupload (1) if something had changed and (2) especially when nothing has changed.

[ForestEckhardt]

Sorry for the pause in communication. As far as I understand it the only thing that the buildpack would be doing the would alter the cache is running the go build. We have the buildpack configure such that the go build command will just create its cache in the specified cache layer which is restored for subsequent builds to take advantage of. The only thing modifying the cache on any given run is the build command itself.

As for why the cache upload is taking so long again I think it is a bit out of our control. It might be interesting to try and do something like slicing the go cache into separate layers but I have no benchmarking to prove that would be any faster or slower. That does have some potential for investigation.

[fg-j]

@genevieve and @paketo-buildpacks/go-maintainers This issue hasn't seen activity in a while. It this still a problem? Did you find a workaround?