a running watch has everything in memory, a freshly started one has to load it into memory first + compile whatever changed in the meantime

if you run with --verbose you should see where all the time is going in detail

(or use the shadow-cljs UI)

naturally. I just tried a kill and restart and got ~12s of startup before [:app] Compiling... then [:app] Build completed. (346 files, 8 compiled, 0 warnings, 8.08s)

so perhaps that is suggesting that the cache did most of the work, and the time is going to file reads and such. I'll try with --verbose.

12s startup time suggests you likely have a user.clj on the classpath that loads a bunch of stuff?

so its 8sec actual compil time, which seems rather excessive for so few files

M1 Max with SSD, for the record.

well I have

[:ui] Compiling ...
[:ui] Build completed. (255 files, 1 compiled, 0 warnings, 0.61s)

huh, verbose is showing some really long cache read times. most of them are 2ms, 6ms. a few larger files (cljs.core, say) are 49ms. but then shadow/cljs/devtools/client/hud.cljs (607ms) and camel_snake_kebab/internals/alter_name.cljc (267ms) and even malli/core.cljc (880ms) 😨

so unless those files are pure gigantic macro monsters it shouldn't take that long 😛

malli.core is definitely a gigantic macro monster 😄 but that still seems like way too long.

it does. but you aren't the first to report slow cache times recently. I suspect that there is something weird going on with macs

let me try building metabase locally and see what it does on my machine

ack some of our own files are 2641 or so! perhaps those are cumulative times? still though.

(`yarn build-hot:cljs` to run this)

on the initial startup, yes there's a dev/src/user.clj. it doesn't load a ton of things but it definitely does some stuff. it's irrelevant to our CLJS build but I'm not sure how to skip it.

don't have it on the classpath is the only way to skip it. clojure loads it and there is nothing shadow-cljs can do to stop that.

yikes Cache read: malli/core.cljc (2293ms)

hmm Cache read: malli/core.cljc (6ms)

thheller@beast:~/code/oss/metabase$ npx shadow-cljs watch app
shadow-cljs - config: /mnt/c/Users/thheller/code/oss/metabase/shadow-cljs.edn
shadow-cljs - connected to server
shadow-cljs - watching build :app
[:app] Configuring build.
[:app] Compiling ...
[:app] Build completed. (328 files, 0 compiled, 0 warnings, 1.71s)

Worker shutdown.
thheller@beast:~/code/oss/metabase$ npx shadow-cljs watch app
shadow-cljs - config: /mnt/c/Users/thheller/code/oss/metabase/shadow-cljs.edn
shadow-cljs - connected to server
shadow-cljs - watching build :app
[:app] Configuring build.
[:app] Compiling ...
[:app] Build completed. (328 files, 0 compiled, 0 warnings, 1.59s)

Worker shutdown.

I deleted user.clj

thheller@beast:~/code/oss/metabase$ rm -rf .shadow-cljs/builds/app/
thheller@beast:~/code/oss/metabase$ npx shadow-cljs watch app
shadow-cljs - config: /mnt/c/Users/thheller/code/oss/metabase/shadow-cljs.edn
shadow-cljs - connected to server
shadow-cljs - watching build :app
[:app] Configuring build.
[:app] Compiling ...
[:app] Build completed. (328 files, 328 compiled, 0 warnings, 5.69s)

Worker shutdown.
thheller@beast:~/code/oss/metabase$ npx shadow-cljs watch app
shadow-cljs - config: /mnt/c/Users/thheller/code/oss/metabase/shadow-cljs.edn
shadow-cljs - connected to server
shadow-cljs - watching build :app
[:app] Configuring build.
[:app] Compiling ...
[:app] Build completed. (328 files, 0 compiled, 0 warnings, 1.40s)

Worker shutdown.

looks normal to me now

(this is with a npx shadow-cljs server running in another terminal, just to remove startup time)

but this looks about right. does user.clj do anything disk intensive maybe?

I'm seeing roughly 7.5s repeatedly with the cache, user.clj still present, and no server running. let me try closing each of those gaps.

ok, when I start with a fresh JVM and no server running it goes up to

[:app] Build completed. (328 files, 0 compiled, 0 warnings, 9.10s)

so even with full cache and no new compiled files it takes 7.7sec longer, with apparently most of the time spent loading the macro namespaces

yeah, when macros are loaded everything is fine and quick. if not there are some rather big delays

$ clj -A:cljs
Clojure 1.11.2
(time (require 'metabase.lib.convert))
Reflection warning, metabase/util/jvm.clj:318:17 - call to static method sleep on java.lang.Thread can't be resolved (argument types: java.lang.Object).
2024-05-21 15:27:55,764 INFO metabase.util :: Maximum memory available to JVM: 7.9 GB
operator.clj:172 recur arg for primitive local: sum is not matching primitive, had: Object, needed: long
Auto-boxing loop arg: sum
"Elapsed time: 12055.2212 msecs"

something in there is taking a rather long time. this is when its also loading everything else, since user.clj didn't load anything at all yet

that doesn't surprise me; that's a substantial namespace and it pulls in pretty much all of src/metabase/lib (105 files, 22kLOC) plus some metabase.util code and other things.

unfortunately I don't know a good way to get per-ns load times, but all the slowdowns I can find are in CLJ code. so doesn't seem to be related to CLJS compilation in any way

> (105 files, 22kLOC)

I'm suspicious of how much Malli compilation we're doing in these namespaces; I'll start there.

and all of that is relevant for CLJS compilation?

that directory is all shared CLJC code.

there is nothing out of the ordinary in the CLJS build. apart from the initial CLJ loading everything is smooth

okay, there's got to be something in the CLJ side, doing way too much work to load the namespace. if I empty metabase.lib.convert it loads in 7ms.

FWIW the the slow "cache load" like malli/core.cljc (880ms) is caused by the CLJ macro namespaces being loaded. not much I can do about that, except maybe make that more explicit in the verbose timing output

how does the macro logic play with the caching? I gather that the CLJ side code like macros needs to be loaded fresh on each load and is not part of the caching?

I think there's way more stuff being loaded on the CLJ side than is really necessary for the CLJS build to work, but that's a Metabase codebase issue and not a shadow-cljs issue.

yeah, the cache can only store the CLJS analyzer metadata. macros cannot be cached that way, and just need to have the code loaded

I suppose with some super eloborate tricks it could delay that loading until actually needed, but that would require changes in CLJS directly and I'm not sure it would be worth the effort overall

is there a way to tell at CLJ load time that it's being loaded by shadow-cljs for macro purposes? I'm wondering if I can break a few deps with #?@(:clj-proper [[real.dep]], :clj-shadow []) sort of things.

I found a https://gist.github.com/pesterhazy/7f8af5701b51ccd86f99fc222436e6ea to show load times for all modules. some of the times are interesting but also the set of things loaded by that (require 'metabase.lib.convert) is much, much too large. like it's loading Toucan 2 and JDBC drivers, neither of which it's going to use.

I also hacked on something for this a while ago. basically loading this namespace first and then whatever else will do a prn with the timing https://github.com/thheller/shadow-cljs/blob/master/src/repl/shadow/load_debug.clj

but it is widely inaccurate since it only logs CLJ namespaces and not things that load java classes or AOT clj classes

so in the end not all that useful

> is there a way to tell at CLJ load time that it's being loaded by shadow-cljs for macro purposes? I'm wondering if I can break a few deps with #?@(:clj-proper [[real.dep]], :clj-shadow []) sort of things. wondering about this. I guess I could use :jvm-opts to set some property, but that's less handy than a reader conditional.

no, as clojure does not expose such a feature

right, that's shadow's magic.

thanks again for your top-notch support!

yeah for cljs shadow controls the reader