Pack is painfully slow

[chrono2002]

Guys, I'm sorry, why pack is so painfully slow?
It takes ~20 sec to build or rebuild a simple hello world app every time.
I've got a blazingly fast machine with a huge amounts of ram.
Docker in experimental mode (with buildkit) is much faster.
Pack takes ~10 seconds on pre-detecting phase and another ~10 to build an image.
That's ~20 seconds overhead!

root@host:~/buildpacks# time ./build.sh 
2020/05/15 22:13:59.290024 ===> DETECTING
[detector] io.buildpacks.sample.node 0.0.1
2020/05/15 22:14:01.262084 ===> ANALYZING
[analyzer] Restoring metadata for "io.buildpacks.sample.node:v13.14.0" from cache
2020/05/15 22:14:03.031370 ===> RESTORING
[restorer] Restoring data for "io.buildpacks.sample.node:v13.14.0" from cache
2020/05/15 22:14:04.910182 ===> BUILDING
[builder] ---> Node Buildpack
[builder] ---> Deploying Node v13.14.0... cached
[builder] build = false
[builder] launch = false
[builder] cache = true
[builder] v13.14.0
2020/05/15 22:14:06.473223 ===> EXPORTING
[exporter] Reusing layer 'launcher'
[exporter] Reusing 1/1 app layer(s)
[exporter] Reusing layer 'config'
[exporter] *** Images (9773d5c5a56f):
[exporter]       index.docker.io/library/sample-nodejs:v4
[exporter] Reusing cache layer 'io.buildpacks.sample.node:v13.14.0'
2020/05/15 22:14:10.018314 Successfully built image sample-nodejs:v4

real    0m18.914s
user    0m0.172s
sys     0m0.032s

[chrono2002]

I've decided to try latest master and it's much more faster but still not enough.
What is program doing for about ~10sec before the CREATING step?

root@host:~/buildpacks# time ./build.sh 
2020/05/15 22:52:00.243838 ===> CREATING
[creator] ---> DETECTING
[creator] io.buildpacks.sample.node 0.0.1
[creator] ---> ANALYZING
[creator] Restoring metadata for "io.buildpacks.sample.node:v13.14.0" from cache
[creator] ---> RESTORING
[creator] Restoring data for "io.buildpacks.sample.node:v13.14.0" from cache
[creator] ---> BUILDING
[creator] ---> Node Buildpack
[creator] ---> Deploying Node v13.14.0... cached
[creator] build = false
[creator] launch = false
[creator] cache = true
[creator] v13.14.0
[creator] ---> EXPORTING
[creator] Reusing layer 'launcher'
[creator] Reusing 1/1 app layer(s)
[creator] Reusing layer 'config'
[creator] *** Images (9773d5c5a56f):
[creator]       index.docker.io/library/sample-nodejs:v5
[creator] Reusing cache layer 'io.buildpacks.sample.node:v13.14.0'
2020/05/15 22:52:03.892267 Successfully built image sample-nodejs:v5

real    0m11.739s
user    0m0.200s
sys     0m0.028s

[jromero]

This is very valuable feedback. Thank you for the input and furthermore trying it out on master. We've got performance at the forefront of our minds so getting these insights and expectations voiced is greatly appreciated.

You can see a bit more detail as to what's going on under the hood by using the --verbose.

[jromero]

I'm will to throw a wild guess that this might be pulling the image (or at least checking if the images are up to date). I'd be interested to see what the command arguments are that you are using you can preferch the images and then run build with --no-pull.

[chrono2002]

Now that's funky! Thanks!

I have a local docker. The command is:
pack --timestamps build sample-nodejs:v8 --builder dev/builder:alpine --buildpack buildpacks/node --path apps/sample-nodejs --no-pull --verbose

root@host:~/buildpacks# time ./build.sh
2020/05/15 23:28:18.355932 Selected run image dev/stack-run:alpine
2020/05/15 23:28:18.367674 Adding buildpack io.buildpacks.sample.node version 0.0.1 to builder
2020/05/15 23:28:18.367693 Setting custom order
2020/05/15 23:28:19.883537 Using build cache volume pack-cache-efb999ac16cb.build
2020/05/15 23:28:19.883848 ===> CREATING
[creator] ---> DETECTING
[creator] ======== Results ========
[creator] pass: [email protected]
[creator] Resolving plan... (try #1)
[creator] io.buildpacks.sample.node 0.0.1
[creator] ---> ANALYZING
[creator] Analyzing image "46d819b2ae0987a8bfe1d0e9c31d7ca6ed1fb3e2d7b7147c68b7935c50787a20"
[creator] Restoring metadata for "io.buildpacks.sample.node:v13.14.0" from cache
[creator] Writing layer metadata for "io.buildpacks.sample.node:v13.14.0"
[creator] ---> RESTORING
[creator] Restoring data for "io.buildpacks.sample.node:v13.14.0" from cache
[creator] Retrieving data for "sha256:3d24094a0ef7d3109fb6ec0df7b4466a229a8245325751c9a50c16984a42c166"
[creator] ---> BUILDING
[creator] ---> Node Buildpack
[creator] ---> Deploying Node v13.14.0... cached
[creator] build = false
[creator] launch = false
[creator] cache = true
[creator] v13.14.0
[creator] ---> EXPORTING
[creator] no project metadata found at path './project-metadata.toml', project metadata will not be exported
[creator] Reusing layers from image with id '46d819b2ae0987a8bfe1d0e9c31d7ca6ed1fb3e2d7b7147c68b7935c50787a20'
[creator] Writing tarball for layer "launcher"
[creator] Reusing layer 'launcher'
[creator] Layer 'launcher' SHA: sha256:fc0f43164b552113ff10be358f50b66a631d42bde551b927763d94b69d0c9793
[creator] Layer 'app' SHA: sha256:9eafc156c11781ef5281f209dcd93a82d5b89a158ca5dac00fb3aac298c86c45
[creator] Reusing 1/1 app layer(s)
[creator] Writing tarball for layer "config"
[creator] Reusing layer 'config'
[creator] Layer 'config' SHA: sha256:d1e14b6597498db8c874d64506fd50bd214e7427758a875b39a736c66b8fc026
[creator] *** Images (46d819b2ae09):
[creator]       index.docker.io/library/sample-nodejs:v8
[creator] 
[creator] *** Image ID: 46d819b2ae0987a8bfe1d0e9c31d7ca6ed1fb3e2d7b7147c68b7935c50787a20
[creator] Writing tarball for layer "io.buildpacks.sample.node:v13.14.0"
[creator] Reusing cache layer 'io.buildpacks.sample.node:v13.14.0'
[creator] Layer 'io.buildpacks.sample.node:v13.14.0' SHA: sha256:3d24094a0ef7d3109fb6ec0df7b4466a229a8245325751c9a50c16984a42c166
2020/05/15 23:28:23.155064 Successfully built image sample-nodejs:v8

real    0m4.821s
user    0m0.020s
sys     0m0.020s

[jromero]

Can we take "funky" as a positive comment? 😄

Is there more insight or conversation needed to be had here?

We are always looking to improve performance wherever possible but would hate to have an open-ended issue around. @chrono2002 were these answers satisfactory?