pathom 2023-04-13

Pathom’s exceptions often are huge, in the sense that they use the environment as ex-info data. Combine that with atom-based caches and printing an exception can fill multiple pages. This gets even worse if for some reason the environment contains a cyclic reference. Not sure yet if that happens in our case but it is possible, if an atom somehow ends up being referenced within the atom. We are encountering OutOfMemoryErrors in production that I think are caused by this, in this chain of events: • Something goes wrong • Pathom throws an exception with the whole environment in ex-data • Because we use the async runner, this happens within a CompletableFuture, which wraps the exception in a CompletionException • This eventually calls the constructor Throwable(Throwable cause), which calls cause.toString() to obtain the exception message • Calling toString() on an ExceptionInfo formats the data map: return "clojure.lang.ExceptionInfo: " + getMessage() + " " + data.toString(); • PersistentHashMap.toString() uses Clojure’s pr/`print` functions, which uses a StringWriter that will allocate memory • Finally this blows up with an OutOfMemoryError: Required array length 2147483645 + 8 is too large Looking at the size of the generated string, I guess we indeed have a cycle in there. Anyhow, I think it’s not a good idea to transport a lot of data in ex-info. For this reason, we already have code that strips most of the ex-data generated by Pathom, but in the case described above, we run out of memory before this code has a chance to strip the data 🙂 Should I create a GitHub issue for this?

I think the problem is in com.wsscode.pathom3.connect.runner/processor-exception, which uses the env plus additional keys as error data. I see that there was an attempt to fix this before, as this returns a proxy overwriting toString. However, this does not seem to fix it in our case.

hello @fb, I guess you are using Emacs for dev? I remember hearing from some other emacs users about this issue, I believe this has something to do with how emacs/cider deals with errors (where it tries to print the whole error data when it sees one), because in the past I tried to reproduce it on intellij and wasn't able to do so, can you try something similar using a plain REPL and see if the error persists?

wait, I missed the part you saying about prod, humm, ok, that might be something else, let me take another look here

the reason I have so much data there is to allow for a better/detailed error handling down the road, but I guess we can add some extension point that will allow you to reduce that

one idea that I'm thinking, is to move the big parts to some other location external to the error map, and put some reference in the error map to allow the user to access it, one tradeoff of that so far is to manage that reference to avoid memory leaks, because it needs to live enough for the user to access it if wanted, but not much longer after that

Maybe we can use some hook or the plugin system for people to access data while an exception is detected? From investigating these issues, I learned that we should be careful what to put in ex-data, and probably keep it minimal. I feel reminded of my C++ days, where the recommendation was to do as little as possible to create exceptions, in order to not cause other exceptions. Even memory allocation was frowned upon 😄

Btw I’m not using emacs 😄

FWIW, we’d benefit from shorter exception messages as well 🤷‍♂️. The REPL output is so long as to be almost meaningless without knowing what you’re looking for.

👍 1
👀 1

I see someone watched Rich’s talk yesterday 🙂

🙂 1

I’m using VC-Code + Calva mainly, and I’ve seen Calva to crash when a Graph execution failed exception escapes to the REPL, even without printing the data by default. This is why we first wrapped calls to the async.eql namespace, caught all exceptions, and removed moved of the keys:

(defn- remove-pathom-key? [k]
  (some->> (and (keyword? k) (namespace k))
           (re-matches #"com\.wsscode\.pathom3\.(?!error).*")))

(defn clean-error-data
  "Cleans Pathom error data (as returned by `ex-data`).

   Pathom exceptions often contain the whole environment as `ex-data`.
   This can be problematic: Printing the exception will produce multiple
   pages worth of gibberish, and Calva routinely crashes when a Pathom
   exception escapes to the REPL."
  [data]
  (if (seq data)
    (into {} (comp
              (remove #(remove-pathom-key? (key %)))
              ;; Atoms, e.g. custom Pathom caches
              (remove #(instance? clojure.lang.Atom (val %))))
          data)
    data))

Meanwhile I tried monkey-patching processor-exception to not include the environment in ex-data, and this seems to fix the OOM issue for us. Not 100% sure yet, because this whole affair is quite strange. We’ve seen OOM exception reported in our default uncaught exception handler in production, but I have not seen this locally. Will report back once I could test it on prod. I noticed that promesa’s default executor, ForkJoinPool, has a really annoying behaviour: When an exception is thrown and its toString() method also throws (e.g. OOM), then the returned promise never resolves or rejects. It just stays pending forever:

(def *p (-> (p/future (Thread/sleep 1))
            (p/then (fn [_x]
                      (throw
                       (proxy [Exception] []
                         (toString [] (throw (ex-info "Test" {})))))))))
I’ve seen our app hanging, potentially from this, with the unpatched processor-exception. With the patched one, no hang.

@fb nice, thanks for all this information, can you send me your patched version of processor-exception for me to have a look?

Sure! We decided to remove as much as possible as we did not need any of the added keys, and ended up with this:

(defn processor-exception
  "Patch for `com.wsscode.pathom3.connect.runner/processor-exception`.
   Does not include the environment in `ex-data`.  Having huge exception data will
   crash tooling, and can lead to `OutOfMemoryError`s, especially if data in the
   environment contains cyclic references.
   We observed `OutOfMemoryError`s in the following scenario:
   - A resolver fails for any reason
   - Pathom captures the environment and context information in an `ExceptionInfo`
     instance and throws it.
   - In the parallel runner, this is wrapped by `CompletableFuture` in
     `CompletionException`.
   - The `Throwable(Throwable cause)` constructor calls `toString()` on the `cause`,
     which is our `ExceptionInfo`.
   - `ExceptionInfo.toString()` prints its data map.
   - The system runs out of memory trying to print the huge and potentially
     cyclic map.
   - In the `ForkJoinPool`, this exception thrown in `toString()` causes the tracking
     promise to stay in pending state forever."
  [_env err]
  (if (pcr/processor-error? err)
    err
    (let [msg  (str "Graph execution failed: " (ex-message err))
          data (assoc (ex-data err) ::pcr/processor-error? true)]
      (ex-info msg data err))))

And then we just do: (alter-var-root #'pcr/processor-exception (constantly processor-exception)) 🙂

You can solve this by hiding the data inside a Java that has short “toString”.

So in the ex-data map you might have key :env which has value and instance of PathomEnvironment , which has just one method: .asMap that returns env map if requested

that effectively hides the map from any automatic printing mechanisms

sorry the long time on this one folks, I'm trying to revisit the whole error thing on Pathom 3, the current thing feels messy, I'm also open to ideas, if you guys have something in mind, please let me know, I'm looking for ways to make it as simple as possible

No more OOM errors, this suggests our problem was indeed the Pathom env in ex-data

cool, glad to hear, I'm down to remove that in the current form, I started working on a way to instead just keep a reference and allow the user to access the env in some indirect way

❤️ 1