Memory use rises with requests

[vise890]

Library Version(s)

[metosin/compojure-api "1.1.13"] + [prismatic/schema "0.1.12"]

Problem

We were experiencing high memory usage, and eventually found out that the issue was introduced with the upgrade to prismatic/schema "0.1.12":

1. In prismatic/schema, commit https://github.com/plumatic/schema/commit/08261aa0cfdae4b117ff5054e68da2c7af9b4989#diff-42f4e811a77e59a977aa6f449ac181b2bdee60083b7284a1be4c450cee90192dR825 introduced a new lambda, so every call to schema.core/map-elements instantiates a new schema (since (not= #() #())).

2. compojure.api.core/GET and related macros eventually call compojure.api.coerce/coerce! on every request. This eventually calls compojure.api.coerce/time-matcher and possibly compojure.api.coerce/custom-matcher (see the full call stack below). Since these are multi-methods, every call to them that falls through to the :default implementation ends up storing the return value of the dispatch function in the method's cache. This cache kept growing with every request and lead to a memory leak.

   Related issue: https://ask.clojure.org/index.php/10532/memory-leak-using-the-default-method-of-a-multimethod

The full call stack

• compojure.api.coerce/coerce!
  • compojure.api.coerce/cached-coercer
    • schema.coerce/coercer
      • schema.core/spec
        • clojure.lang.APersistentMap implementation of schema.core/Schema in schema.core
          • schema.core/map-spec
            • schema.core/map-elements
              • https://github.com/plumatic/schema/commit/08261aa0cfdae4b117ff5054e68da2c7af9b4989#diff-42f4e811a77e59a977aa6f449ac181b2bdee60083b7284a1be4c450cee90192dR825 introduces a new lambda, so every call instantiates a different schema
  • compojure.api.middleware/coercion-matchers
    • compojure.api.middleware/default-coercion-matchers
      • compojure.api.coerce/json-schema-coercion-matcher
        • compojure.api.coerce/time-matcher and compojure.api.coerce/custom-matcher, which are multimethods so will cache every new schema that falls through the :default implementation

The failing test

Here is a test that fails on [metosin/compojure-api "1.1.13"] + [prismatic/schema "0.1.12"]:

(ns solaris.middleware.coercion-test
  (:require [clojure.test :refer [deftest is]]
            compojure.api.coerce
            [compojure.api.core :as cc]
            [ring.swagger.coerce :as coerce]
            [schema.core :as s]))

(defn get-method-cache [multimethod]
  (-> (.getDeclaredField (.getClass multimethod) "methodCache")
      (doto (.setAccessible true))
      (.get multimethod)))

(deftest cache-should-not-grow-across-multiple-coerce-calls



  (letfn [(coerce! [] (compojure.api.coerce/coerce!
                       {s/Keyword schema.core/Any}
                       :query-params
                       :string
                       {:query-params {:foo :bar}}))]

    (coerce!)

    (let [original-custom-matcher-cache-count (count (get-method-cache coerce/custom-matcher))
          original-time-matcher-cache-count   (count (get-method-cache coerce/time-matcher))]

      (coerce!)

      (is (= original-custom-matcher-cache-count (count (get-method-cache coerce/custom-matcher))))
      (is (= original-time-matcher-cache-count (count (get-method-cache coerce/time-matcher)))))))

.. for now we have fallen back to [prismatic/schema "0.1.10"] to resolve the issue..

Also, could this be related to https://github.com/metosin/compojure-api/issues/366?

[frenchy64]

I reported this upstream: https://github.com/plumatic/schema/issues/433

But I think in general even if this is fixed in schema, it could be triggered if your schema has an extra-key which does not have stable equality. Perhaps compojure-api could use a different kind of caching mechanism to prevent unbounded memory use.

[frenchy64]

I think everywhere time-matcher is mentioned it's actually referring to ring.swagger.coerce/time-matcher (similar for the other multimethods).

[frenchy64]

I think a reasonable fix would be to use (defmulti time-matcher #(when (class? %) %)) instead of (defmulti time-matcher identity) to work around https://ask.clojure.org/index.php/10532/memory-leak-using-the-default-method-of-a-multimethod

EDIT: oh, this was already encouraged by Tommi https://ask.clojure.org/index.php/10532/memory-leak-using-the-default-method-of-a-multimethod?show=10825#c10825