Slow `dagger do deploy` in latest todoapp

[shykes]

Just now running dagger do deploy in #1693 , there is a 3s delay before seeing any output.

Observed just now with @gerhard .

Reporting early in case it's related to the ongoing cueflow fixes by @aluzzardi and @jlongtine

[gerhard]

Even when everything is cached, dagger do takes ~3s:

❯ time dagger do deps
10:22PM INF actions.deps._dag."2".script._write | computing
10:22PM INF client.filesystem.".".read | computing
10:22PM INF actions.deps._dag."0"._dag."0"._op | computing
10:22PM INF actions.deps._dag."2".script._write | completed    duration=0s
10:22PM INF client.filesystem.".".read | completed    duration=0s
10:22PM INF actions.deps._dag."0"._dag."0"._op | completed    duration=0s
10:22PM INF actions.deps._dag."0"._dag."1"._exec | computing
10:22PM INF actions.deps._dag."0"._dag."1"._exec | completed    duration=0s
10:22PM INF actions.deps._dag."0"._dag."2"._exec | computing
10:22PM INF actions.deps._dag."0"._dag."2"._exec | completed    duration=0s
10:22PM INF actions.deps._dag."0"._dag."3"._exec | computing
10:22PM INF actions.deps._dag."0"._dag."3"._exec | completed    duration=0s
10:22PM INF actions.deps._dag."1"._copy | computing
10:22PM INF actions.deps._dag."1"._copy | completed    duration=0s
10:22PM INF actions.deps._dag."2"._exec | computing
10:22PM INF actions.deps._dag."2"._exec | completed    duration=0s
dagger do deps  1.37s user 3.28s system 109% cpu 4.233 total

If I comment everything other the the deps action, with everything cached, dagger up also takes ~3s:

❯ time dagger up
10:25PM INF actions.deps._dag."2".script._write | computing
10:25PM INF client.env.NETLIFY_TEAM | computing
10:25PM INF client.platform | computing
10:25PM INF client.env.APP_NAME | computing
10:25PM INF client.filesystem.".".read | computing
10:25PM INF client.env.NETLIFY_TEAM | completed    duration=0s
10:25PM INF actions.deps._dag."0"._dag."0"._op | computing
10:25PM INF client.env.NETLIFY_TOKEN | computing
10:25PM INF client.env.APP_NAME | completed    duration=0s
10:25PM INF client.platform | completed    duration=0s
10:25PM INF client.env.NETLIFY_TOKEN | completed    duration=0s
10:25PM INF actions.deps._dag."2".script._write | completed    duration=0s
10:25PM INF client.filesystem.".".read | completed    duration=0s
10:25PM INF actions.deps._dag."0"._dag."0"._op | completed    duration=0s
10:25PM INF actions.deps._dag."0"._dag."1"._exec | computing
10:25PM INF actions.deps._dag."0"._dag."1"._exec | completed    duration=0s
10:25PM INF actions.deps._dag."0"._dag."2"._exec | computing
10:25PM INF actions.deps._dag."0"._dag."2"._exec | completed    duration=0s
10:25PM INF actions.deps._dag."0"._dag."3"._exec | computing
10:25PM INF actions.deps._dag."0"._dag."3"._exec | completed    duration=0s
10:25PM INF actions.deps._dag."1"._copy | computing
10:25PM INF actions.deps._dag."1"._copy | completed    duration=0s
10:25PM INF actions.deps._dag."2"._exec | computing
10:25PM INF actions.deps._dag."2"._exec | completed    duration=0s
dagger up  1.09s user 3.61s system 107% cpu 4.370 total

cue eval takes 0.3s:

cue eval netlify.cue  0.33s user 0.03s system 135% cpu 0.260 total

[aluzzardi]

I did notice this as well with @gerhard's configuration (larger than our tests) . @jlongtine any ideas? Could this be the runner algorithm?

[jlongtine]

I'm unable to replicate this on Mac OS. I tried adding a big (1G) file to stress the buildkit uploader... but that didn't make a difference once it was cached.

@gerhard Where are you running this?

[aluzzardi]

Can't repro either

[gerhard]

@jlongtine:

❯ neofetch
                    'c.          gerhard@hannibal
                 ,xNMM.          ----------------
               .OMMMMo           OS: macOS 12.2.1 21D62 arm64
               OMMM0,            Host: MacBookPro18,2
     .;loddo:' loolloddol;.      Kernel: 21.3.0
   cKMMMMMMMMMMNWMMMMMMMMMM0:    Uptime: 23 days, 24 mins
 .KMMMMMMMMMMMMMMMMMMMMMMMWd.    Packages: 1 (brew)
 XMMMMMMMMMMMMMMMMMMMMMMMX.      Shell: zsh 5.8
;MMMMMMMMMMMMMMMMMMMMMMMM:       Resolution: 3456x2234
:MMMMMMMMMMMMMMMMMMMMMMMM:       DE: Aqua
.MMMMMMMMMMMMMMMMMMMMMMMMX.      WM: Quartz Compositor
 kMMMMMMMMMMMMMMMMMMMMMMMMWd.    WM Theme: Blue (Dark)
 .XMMMMMMMMMMMMMMMMMMMMMMMMMMk   Terminal: iTerm2
  .XMMMMMMMMMMMMMMMMMMMMMMMMK.   Terminal Font: MesloLGS-RegularForPowerline 12
    kMMMMMMMMMMMMMMMMMMMMMMd     CPU: Apple M1 Max
     ;KMMMMMMMWXXWMMMMMMMk.      GPU: Apple M1 Max
       .cooc,.    .,coo:.        Memory: 4442MiB / 32768MiB

I can show you today.

I am hitting another issue. Running dagger do build the second time, with a full cache, takes a full 28s. It gets fast to the last step and then it just hangs:

❯ time dagger do build
2:51PM INF actions.build.run.script._write | computing
2:51PM INF client.filesystem.".".read | computing
2:51PM INF actions.test.script._write | computing
2:51PM INF actions.deps._dag."0"._dag."0"._op | computing
2:51PM INF actions.deps._dag."2".script._write | computing
2:51PM INF actions.test.script._write | completed    duration=0s
2:51PM INF actions.deps._dag."2".script._write | completed    duration=0s
2:51PM INF actions.build.run.script._write | completed    duration=0s
2:51PM INF client.filesystem.".".read | completed    duration=0s
2:51PM INF actions.deps._dag."0"._dag."0"._op | completed    duration=800ms
2:51PM INF actions.deps._dag."0"._dag."1"._exec | computing
2:51PM INF actions.deps._dag."0"._dag."1"._exec | completed    duration=0s
2:51PM INF actions.deps._dag."0"._dag."2"._exec | computing
2:51PM INF actions.deps._dag."0"._dag."2"._exec | completed    duration=0s
2:51PM INF actions.deps._dag."0"._dag."3"._exec | computing
2:51PM INF actions.deps._dag."0"._dag."3"._exec | completed    duration=0s
2:51PM INF actions.deps._dag."1"._copy | computing
2:51PM INF actions.deps._dag."1"._copy | completed    duration=0s
2:51PM INF actions.deps._dag."2"._exec | computing
2:51PM INF actions.deps._dag."2"._exec | completed    duration=0s
2:51PM INF actions.test._exec | computing
2:51PM INF actions.test._exec | completed    duration=0s
2:51PM INF actions.build.run._exec | computing
2:51PM INF actions.build.run._exec | completed    duration=0s
2:51PM INF actions.build.contents._copy | computing
2:51PM INF actions.build.contents._copy | completed    duration=0s
2:51PM INF client.filesystem.build.write | computing
2:51PM INF client.filesystem.build.write | completed    duration=100ms
dagger do build  1.21s user 0.10s system 4% cpu 28.638 total

❯ dagger version
dagger devel (17c45ea3) darwin/arm64

[shykes]

I believe this issue has been solved.