This page is not created by, affiliated with, or supported by Slack Technologies, Inc.
2023-11-25
Channels
I have an app where the core namespace (that require
s all the other stuff) takes 10-15secs to load. Is there some way to easily see where that time is going, which namespaces/dependencies take how long to load?
It's been discussed before, e.g. https://clojurians.slack.com/archives/C03S1KBA2/p1696923668147539 Tl;dr: a regular profiler should be enough.
clj-async profiler 1.1.0 includes a startup profiler https://clojure-goes-fast.com/blog/clj-async-profiler-110/ that I think spawned after the conversation p-himik is linking
the startup profiling is described here https://clojure-goes-fast.com/kb/profiling/clj-async-profiler/startup/
Yes, exactly what @U0739PUFQ has said! @U66G3SGP5 feel free to ask if you have any troubles with it.
It matters because one approach is just loading precompiled bytecode, the other is compiling and also loading
I didn't find profiling useful for this. Patching the compiler to output timing was more helpful
Agree with @U050ECB92 that AOT'ing is one of the first things to look at as it's pretty easy
Other than that I didn't find any magic bullet other than reducing the number of dependencies, which of course can be expensive to implement
Mostly in my experience reducing startup time means doing less (unnecessary) work
Oh and getting an arm mac :-)
How would you know which experiment to run and what to measure without application of a priori logic?
> I didn't find profiling useful for this.
Have you tried following the article linked above?
To make things certain, I just tried it on one of my projects. I find it rather clear, e.g. in the case of that specific project the worst third-party offender is aleph.http
. I didn't have to modify the compiler to be able to see that.
> How would you know which experiment to run and what to measure without application of a priori logic?
We're interested in namespace loading time, so need to measure that. The experiment must be something that measures that time. Profiling suits just fine.
@U06PNK4HG The article makes a bit of a jump at the end from the call to (prof/generate-flamegraph ...)
to viewing the HTML. I think it would help to make this step a bit more explicit, maybe even with opening the HTML file automatically in the default browser.
Good point. It assumes that the user has already read the pages before this one. I'll update the doc.
Yeah I did read that page about startup profiling, but the flamegraph at the end contains no information about namespaces and which take what amount of time, so I didn’t bother with it
It does contain the information about namespaces. You have to look for frames that look like my,namespace__init.<clinit>
(e.g., clojure.core__init.<clinit>
). That marks the entrypoint to the loading of the namespace. And the width (or percentage) gives the time distribution. If you know the total load time, then it's trivial to calculate the load time of a particular namespace, if you need that.
Another option is to use JFR (Java Flight Recorder) to just record what happens during start up, then you get a synchronous view of what threads are doing
No clue how hard implementing something like this would be, but maybe useful to have an extra viewing mode that's focused specifically on loading times and hierarchies. Probably quite a task on its own, given that in my mind it also helps the user understand that if A depends on B then removing that B won't improve the total loading time because B is also a dependency of C, and so on.
Does anyone have a reliable way of checking if there is data available on stdin?
This kinda works:
(defn stdin-ready? []
(let [chan (chan)]
(go (>! chan (. ^LineNumberingPushbackReader *in* read)))
(when-let [char (alt!!
(timeout 500) nil
chan ([char] (when-not (< char 0) char)))]
(. *in* (unread char))
true)))
But I get this warning
Reflection warning, yamlscript/cli.clj:65:7 - call to method unread can't be resolved (target class is unknown).
which is on the line
(. *in* (unread char))
and when I change it to
(. ^LineNumberingPushbackReader *in* (unread char))
I get this warning:
Reflection warning, yamlscript/cli.clj:65:7 - call to method unread on clojure.lang.LineNumberingPushbackReader can't be resolved (argument types: java.lang.Object).
but both seem to work
However when I compile to native with graalvm I get
Exception in thread "main" java.lang.IllegalArgumentException: No matching method unread found taking 1 args for class clojure.lang.LineNumberingPushbackReader
at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:127)
at clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:102)
at yamlscript.cli$stdin_ready_QMARK_.invokeStatic(cli.clj:65)
at yamlscript.cli$get_code.invokeStatic(cli.clj:187)
at yamlscript.cli$do_compile.invokeStatic(cli.clj:252)
at yamlscript.cli$_main.invokeStatic(cli.clj:386)
at yamlscript.cli$_main.doInvoke(cli.clj:358)
at clojure.lang.RestFn.applyTo(RestFn.java:137)
at yamlscript.cli.main(Unknown Source)
at [email protected]/java.lang.invoke.LambdaForm$DMH/sa346b79c.invokeStaticInit(LambdaForm$DMH)
@U04V15CAJ do you have any insight here?
fwiw I do have this in my reflection.json
(used in call to native-image:
{
"name":"clojure.lang.LineNumberingPushbackReader",
"allPublicMethods":true,
"allPublicFields": true,
"allPublicConstructors": true
},
And the unread(int c)
method https://github.com/clojure/clojure/blob/master/src/jvm/clojure/lang/LineNumberingPushbackReader.java#L83-L89 seems to be there
I'm no expert, but it might need a type hint of int since it's a primitive (if the reflective lookup is happening for Object, that presumably won't be found)
alternatively, java Reader
s have a ready
method that might serve for the original question
I'll try it, thanks
https://stackoverflow.com/questions/41575434/detect-non-empty-stdin-in-clojure/41594130#41594130 seems to indicate it doesn't work
That also where I stole my (since modified) code from...
@U013JFLRFS8 the ^Long annotation got rid of the warnings!
graaling it now...
I'd cross my fingers but graal takes so damn long I'd get hand cramps
@U013JFLRFS8 It worked! You are my hero!!
I wasted almost 2 hours 😞
(defn stdin-ready? []
(let [chan (chan)]
(go (>! chan (. ^LineNumberingPushbackReader *in* read)))
(when-let [char (alt!!
(timeout 500) nil
chan ([char] (when-not (< char 0) char)))]
(. ^LineNumberingPushbackReader *in* (unread ^Long char))
true)))
@U05H8N9V0HZ You've asked this before: https://clojurians.slack.com/archives/C015LCR9MHD/p1697733050817529
@U04V15CAJ my memory isn't as good as yours. sorry
@U04V15CAJ glad you mentioned it
(defn stdin-ready? []
(.ready ^clojure.lang.LineNumberingPushbackReader *in*))
seems to work the same and mush simpler.
Strangely there was no .ready
in my code base. Not sure what happened to it from before.After more testing it turns out the simpler way falls prey to race conditions. This is probably why I abandoned that code in October...
yeah just a minute
good. I have another issue that is in your wheelhouse 🙂
FWIW I've never used .ready
in any of my projects, I think it's generally better to let users explicitly specify if your tool should read from stdin (since .ready and .available might also not be 100% accurate and give timing issues)
So ys -Y
reads ys from stdin and outputs yaml (which in a normal case is same as input):
$ echo 'a: b' | ys -Y | ys -Y | ys -Y
a: b
and with no input:
$ ys -Y
Warning: No input found.
with the .ready
code
$ echo 'a: b' | ys -Y
a: b
but
$ echo 'a: b' | ys -Y | ys -Y | ys -Y
Warning: No input found.
Warning: No input found.
What happens if you straight up use (.ready System/in)
without all the reader bs wrapped around it?
yeah same issue:
$ echo 'a: b' | clj -M -e '(when-not (zero? (.available System/in)) (prn :hello))' | clj -M -e '(.available System/in)'
0
there is an explicit flag and you get a warning if it can't find input. checking for stdin is common and nice to have in a lot of utils
$ echo 'a: b' | ys -Y - | ys -Y - | ys -Y -
a: b
is explicit
hmm ok, I've never supported that use case (checking for missing stdin) and never got any complaints about it, I would consider this a low priority issue not worth spending hours on :)
(defn stdin-ready? []
(let [chan (chan)]
(go (>! chan (. ^LineNumberingPushbackReader *in* read)))
(when-let [char (alt!!
(timeout 500) nil
chan ([char] (when-not (< char 0) char)))]
(. ^LineNumberingPushbackReader *in* (unread ^Long char))
true)))
works well so far but it also bloats the native-image by 7MB.Can you happen to see why at a glance?
that's correct. does bb have a way to minimize that?
bb doesn't expose the go
stuff. the go macro uses heavy machinery which might bloat your image
would that work for this?
I just pulled that code off stackoverflow. I'll have to understand it and change it, but good to know. Thanks
(let [ready (promise)]
(future ;; check stream here, deliver to promise when ready)
(Thread/sleep 500) (deliver nil))
@U04V15CAJ this is the best I could come up with so far
(defn stdin-ready? []
(let [ready (promise)]
(future
(let [char (. ^LineNumberingPushbackReader *in* read)]
(when (> char -1)
(. ^LineNumberingPushbackReader *in* (unread char))
(deliver ready true))))
(future
(Thread/sleep 1000)
(deliver ready false))
(let [result @ready]
(shutdown-agents)
result)))
and I get
$ time (echo 'a: b' | ys -Y)
a: b
real 0m1.035s
$ time (echo 'a: b' | ys -Y | ys -Y)
a: b
real 0m1.059s
$ time (echo 'a: b' | ys -Y | ys -Y | ys -Y)
Warning: No input found.
real 0m1.040s
Note they all take ~ 1.050s. Usually ys takes about 0.050s.
So it's waiting the whole sleep 1000.
Also worth noting the first one prints a: b
immediately, the second after 1s and the third fails.
Not sure how to stop the sleep.
Your wisdom would be appreciated 🙂(let [stdin (promise)]
(future
(deliver stdin (slurp *in*)))
(future
(Thread/sleep 1000)
(deliver stdin false))
(let [stdin @stdin]
(shutdown-agents)
(println "stdin:" stdin)))
$ time bb /tmp/stdin.clj <<< '1'
stdin: 1
bb /tmp/stdin.clj <<< '1' 0.02s user 0.01s system 77% cpu 0.035 total
$ time bb /tmp/stdin.clj
stdin: false
bb /tmp/stdin.clj 0.02s user 0.01s system 2% cpu 1.031 total
$ cat x.clj
(defn get-stdin []
(let [stdin (promise)]
(future
(deliver stdin (slurp *in*)))
(future
(Thread/sleep 1000)
(deliver stdin false))
(let [stdin @stdin]
(shutdown-agents)
stdin)))
(let [text (get-stdin)]
(if text
(print text)
(binding [*out* *err*]
(println "NO STDIN"))))
->
$ time (echo 123 | bb x.clj | bb x.clj | bb x.clj)
123
real 0m0.065s
$ time bb x.clj
NO STDIN
real 0m1.116s
all good with bb but....$ time (echo 'a: b' | ys -Y)
a: b
real 0m1.076s
works but waits 1s
$ time (echo 'a: b' | ys -Y | ys -Y | ys -Y)
Warning: No input found.
Warning: No input found.
real 0m1.095s
doesn't work
$ time (ys -Y)
Warning: No input found.
^C
hangs indefinitelyI don't think shutdown-agent
kills the Thread/sleep
Maybe bb
is doing something extra to let that work?
I'm using that same function in the bb script above in my code.
I added a (flush)
after printing but no changes.
It works as expected running in bb (there's not even a flush there). I don't understand what kills the sleep when running under bb.
ok, but what kills the sleep?
Initiates a shutdown of the thread pools that back the agent
system. Running actions will complete, but no new actions will be
accepted
Try this in a single file JVM Clojure program and see what happens. I am afk right now but if you have such a repro I’ll try when I’m back
Try this:
$ cat x.clj
(defn get-stdin []
(let [stdin (promise)]
(future
(Thread/sleep 5000)
(deliver stdin false))
(future
(deliver stdin (slurp *in*)))
(let [stdin @stdin]
(shutdown-agents)
stdin)))
(let [text (get-stdin)]
(if text
(print text)
(binding [*out* *err*]
(println "NO STDIN"))))
(flush)
then (note the alias of bb
to clj
here)
$ alias bb='clj -M'
$ time (echo 123 | bb x.clj)
123
real 0m6.215s
$ time (echo 123 | bb x.clj | bb x.clj | bb x.clj)
NO STDIN
NO STDIN
real 0m7.933s
and
$ time (bb x.clj)
NO STDIN
...hangs...
@U05H8N9V0HZ It seems that with clj -X
it does work, since -X, similar to bb, does some extra stuff:
(ns x)
(defn get-stdin []
(let [stdin (promise)
f1 (future
(Thread/sleep 2000)
(deliver stdin false))
_f2 (future
(deliver stdin (slurp *in*))
(future-cancel f1))
stdin @stdin]
stdin))
(defn doit [_]
(let [text (get-stdin)]
(if text
(do (print text)
(flush))
(binding [*out* *err*]
(println "NO STDIN"))))
(shutdown-agents))
clj -Sdeps '{:paths ["."]}' -X x/doit
Don't remember exactly what it was, but I re-implemented it in bb.cli as well, let's have a lookhmm probably the issue is that _f2
doesn't get cancelled so even when calling shutdown-agents the future is waited for (since it's not a daemon thread)
Yeah, here is a repro of that:
(def p (promise))
(def f1 (future (Thread/sleep 1000) (prn :ready) (deliver p true)))
(def f2 (future (prn :stdin (slurp *in*)) (deliver p true)))
(prn (future-cancel f1))
(prn (future-cancel f2))
(shutdown-agents)
@U05H8N9V0HZ This works in all cases:
(set! *warn-on-reflection* true)
(defn daemon-thread [^Runnable f]
(.start (doto (new Thread f)
(.setDaemon true))))
(defn get-stdin []
(let [stdin (promise)]
(daemon-thread #(do (Thread/sleep 1000)
(deliver stdin false)))
(daemon-thread #(do (deliver stdin (slurp *in*))))
@stdin))
(prn :stdin (get-stdin))
Thanks! I'll try it soon.