Fork me on GitHub
#clojurescript
<
2024-07-11
>
Vladimir Pouzanov18:07:48

did anyone try running a cljs app with node's opentelemetry? I'm getting some wild results of span nesting and I wonder if it's because some issues with the closure compiler doing random things

p-himik19:07:27

Not sure how useful my comment would be, but I'm using Sentry with, I think, a similar concept of spans, and I haven't had any issues with it.

thheller19:07:35

the closure compiler does not do random things

⚙️ 1
Vladimir Pouzanov20:07:24

yeah, I mean, it does very deterministic things indeed, but opentelemetry seems to get deep under the node's hood with wrapping require() and propagating the context past the promise chains

Vladimir Pouzanov20:07:02

it's rather peculiar but I tried sentry now and I have the exact same issue: some of the spans don't have parents and those are exactly the same spans as the ones having issues with opentelemetry. I'll try to make a smaller repro case

p-himik20:07:15

Hmm. Maybe I'm just using Sentry at a too shallow of a level to notice anything like the issue you're facing.

Vladimir Pouzanov20:07:21

my code is pretty straightforward (I'd think):

(defn- run-scrape
  []
  (in-span "run-scrape"
           (fn [] (-> (p/let [inverter (api/retrying-call #(api/get-device-realtime % "xxx" 38))
                              sensor (api/retrying-call #(api/get-device-realtime % "yyy" 47))]
                        (scrape-device-all {:inverter inverter :sensor sensor}))
                      (p/then #(log/info "scraped ok"))
                      (p/catch #(tap> {:error %}))))))
which calls into
(defn retrying-call
  [f]
  (in-span "retrying-call"
           (fn [] (p/loop [tok @api-token]
                    (log/info "retrying-call with token " (subs (or tok "nil") 0 10))
                    (if-not tok
                      (p/-> (relogin) (p/recur))
                      (p/catch
                       (do (log/info "calling with token " (subs (or tok "nil") 0 10))
                           (f tok))
                       (fn [err]
                         (log/warn "failed" {:code (-> err ex-data :code)})
                         (condp = (-> err ex-data :code)
                           :must-relogin (p/-> (relogin) (p/recur))
                           :rate-limited (p/do
                                           (p/delay RATELIMIT-RETRY-MS)
                                           (p/recur tok))
                           (p/rejected err)))))))))
which calls into (among other things)
(defn login
  "Logs into the API. Returns the sesson token on success."
  [username password]
  (in-span "login"
           (fn [] (p/let [resp (make-request (get-url "login") {:userName username :systemCode password})
                          {headers :headers} resp]
                    (p/let [body (:body resp)
                            body (body->json body)
                            is-success (:success body)]
                      (if is-success
                        (select-one [:set-cookie (view #(.parse cookie %)) FROMJS :XSRF-TOKEN] headers)
                        (throw (ex-info "failed to call api" {:body body :resp ~resp}))))))))
so all the calls are technically nested under the run-scrape promise. in-span is just a thin wrapper:
(defn in-span
  ([name f]
   (Sentry/startSpan #js {:name name} f)))
that I made to quickly switch from otel to sentry for a test

Vladimir Pouzanov20:07:25

sentry clearly doesn't get the memo that spans are nested:

Vladimir Pouzanov20:07:34

but if I run the same code from the repl, lo and behold:

Vladimir Pouzanov20:07:54

which makes me think it's something about closure compiler's optimization passes that makes this thing explode

p-himik20:07:48

Yeah, I don't create spans manually. I was assuming that other parts of Sentry working just fine for me are indicative of spans working properly, but that might not be the case. Things I'd try: 1. The :none optimization - not via a REPL but as a proper build 2. Getting rid of Promesa

Vladimir Pouzanov20:07:50

I also had the release build minified with webpack, but I removed this step for parity now, so there's no postbundling

Vladimir Pouzanov20:07:56

> 1. Getting rid of Promesa this is going to be painful 😞 but it actually might be the problem now that you mentioned it, given it doesn't use the js's native promise and instead reimplements it.

p-himik13:07:56

Any news? Curious about the culprit.

Vladimir Pouzanov13:07:13

oh sorry, I started writing the news and forgot to send!I swapped promesa for https://github.com/athos/kitchen-async which uses the native promise runtime but is mostly the same api and I think the problems are gone, at least in the sentry logs. I didn’t try it on the otel with advanced optimizations yet though, but I think that’s what was the culprit

p-himik13:07:48

Great! Thanks for sharing.

Vladimir Pouzanov21:07:05

I’ve ported the otel code and it works perfectly even with both the advanced optimizations and webpack minifying. So yeah, it was promesa. The whole async/await story of cljs is so tricky at times but I’m glad I got it working after all. Thanks for your help!

p-himik22:07:29

Sure thing. I got badly burned by Promesa once myself, so now I just avoid it. :)