Clojurians Log v2

Putting this out there in vain hope, has anyone seen an issue where the cider-nrepl middleware causes the JVM to hit it's maximum open files limit? Repro:

clojure -Sdeps '{:deps {nrepl {:mvn/version "0.7.0"} refactor-nrepl {:mvn/version "2.5.0"} cider/piggieback {:mvn/version "0.4.2"} cider/cider-nrepl {:mvn/version "0.25.2"}}}' -m nrepl.cmdline --middleware "[ cider.nrepl/cider-middleware ]"

# List open file count for the JVM, assumes only one JVM open, tweak as necessary
$ ls -las /proc/$(pgrep 'java')/fd | wc -l
$ clojure -Sdeps '{:deps {nrepl {:mvn/version "0.7.0"}}}' -m nrepl.cmdline -c -p 46397
nREPL 0.7.0
Clojure 1.10.0
OpenJDK 64-Bit Server VM 11.0.5-internal+11-adhoc..jdk11u-jdk-11.0.510
Interrupt: Control+C
Exit:      Control+D or (exit) or (quit)
user=> (+ 1 1)
2
user=> (exit)
$ ls -las /proc/$(pgrep java)/fd | wc -l
4098

It appears to be a problem with the debug middleware. I can trim the repro down to typing (require 'cider.nrepl.middleware.debug) which sometimes never returns.

OK, tracked it down to (require 'cider.nrepl.inlined-deps.orchard.v0v5v10.orchard.java), so I guess orchard problem

It's down to these lines:

(future
  (doseq [class (->> (ns-imports 'clojure.core)
                     (map #(-> % ^Class val .getName symbol)))]
    (class-info class)))

Narrowed down to:

(let [klass 'java.lang.Enum]
    (when-let [path (source-path klass)]
      (when-let [root (parse-java path (module-name klass))]
        (.getTypeElement (.getElementUtils root) "java.lang.Enum"))))

> Putting this out there in vain hope, has anyone seen an issue where the cider-nrepl middleware causes the JVM to hit it’s maximum open files limit? Nope. 🙂

Seems you’ve narrowed down the issue pretty quickly, though.

I’m wondering why the resources don’t get released, though.

Blugh, sorry, I forgot to mention a critical detail: It's .jar files that are being opened, most importantly, it's my classpath's jar files being duplicated.

My open file count nearly doubles when I run the above.

In fact, it happens every time I run the above, it adds ~36 items (length of my cp)

adds 36 new open files?

Yup, but they're the same files as are already open.

So I end up with yada.jar twice, ring.jar twice, etc.

i'm running clojure -Sdeps '{:deps {nrepl {:mvn/version "0.7.0"}}}' -m nrepl.cmdline -c -p 46397 but getting connection refused for some reason

@dpsutton you'll need to make sure you use the right port :)

But the better way to do all of this is to work from the orchard repo

I've detached nrepl itself from the problem now

ah ok

i was thinking that was starting up an nrepl server on port 46397 so the port in the command line was the right port

Steps to repro now are to: * Check file descriptor count * Go to orchard, type:

$ clj
Clojure 1.10.1
user=> (require 'orchard.java) (require 'orchard.java.parser) (in-ns 'orchard.java.parser)
nil
nil
#object[clojure.lang.Namespace 0x5c83ae01 "orchard.java.parser"]
(let [klass 'java.lang.Enum]
    (when-let [path (source-path klass)]
      (when-let [root (parse-java path (module-name klass))]
        (.getTypeElement (.getElementUtils root) (str klass)))))
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by clojure.lang.InjectedInvoker/0x0000000800232040 (file:/home/overfl0w/.m2/repository/org/clojure/clojure/1.10.1/clojure-1.10.1.jar) to method com.sun.tools.javac.model.JavacElements.getTypeElement(java.lang.CharSequence)
WARNING: Please consider reporting this to the maintainers of clojure.lang.InjectedInvoker/0x0000000800232040
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
#object[com.sun.tools.javac.code.Symbol$ClassSymbol 0x383caf89 "java.lang.Enum"]

Sorry, no :p I was a bit lazy

I'm starting to think that I'm going to end up reporting a JDK bug :(

find /proc/$(pgrep java)/fd -printf '%l\n' | sort | uniq --repeated will show you what's repeated in the fds.

If I reuse the return value of getElementUtils, it doesn't use additional. So it's a resource managed by getElementUtils, but activated by calling getTypeElement.

well speaking of jdk bug, can you easily switch versions and repo, and then switch jdk vendors and repo? got correto laying around?

I can switch to 8, but that uses a totally different code path, so doesn't seem worth testing.

I'll give corretto a go

I can repro on corretto 11.

If I close the JavaFileManager under the env, the files are cleaned up!

Sticking a finally around the use of the doclet env which closes the file manager seems to do the trick, but I'd love to find some java docs saying what the cleanup is for this kind of thing…

Alternatively, we could use our own file manager, which might dedupe if it's (re)used across doclets. Then you only double the classpath.

where is this?

In the orchard repo, in orchard.java.parser, this version fixes it:

(defn source-info
  "If the source for the Java class is available on the classpath, parse it
  and return info to supplement reflection. Specifically, this includes source
  file and position, docstring, and argument name info. Info returned has the
  same structure as that of `orchard.java/reflect-info`."
  [klass]
  {:pre [(symbol? klass)]}
  (try
    (when-let [path (source-path klass)]
      (when-let [root (parse-java path (module-name klass))]
        (try
          (assoc (->> (.getIncludedElements ^DocletEnvironment root)
                      (filter #(#{ElementKind/CLASS
                                  ElementKind/INTERFACE
                                  ElementKind/ENUM}
                                 (.getKind ^Element %)))
                      (map #(parse-info % root))
                      (filter #(= klass (:class %)))
                      (first))
                 :file path
                 :path (.getPath (io/resource path)))
          (finally
            (.close (.getJavaFileManager root))))))
    (catch Throwable _)))

I think I've found the info I was looking for

https://docs.oracle.com/en/java/javase/11/docs/api/java.compiler/javax/tools/JavaCompiler.html > Reusing a file manager can potentially reduce overhead of scanning the file system and reading jar files. Although there might be no reduction in overhead, a standard file manager must work with multiple sequential compilations making the following example a recommended coding pattern: And the recommended coding pattern includes: > fileManager.close();

Given that we want to dynamically work with new docs over an extended period, I think the correct behavior is to reuse a file manager

Reusing the file manager seems to have done the trick. It doesn't even double the count, it just doesn't go up at all!

oh, that's because it's broken and there's a (catch Throwable _) 😁

Okay, now it behaved like I expect. It went 36->67, but it didn't keep ballooning like it did before. I forgot to note that I commented out the (future).

So, it works from the REPL, but not the tests.

And they run fine independently. Yay. State.

This is why it fails in the tests (and nowhere else):

/tmp/ISeq.java:18: error: cannot find symbol
public interface ISeq extends IPersistentCollection {
                              ^
  symbol: class IPersistentCollection
1 error

I wonder if there's something stateful going on with the file manager...

I can't get compiler reuse version to work, so I'm going to assume that it can't work for some technical reason I don't understand, and instead use .close.

It's no less efficient than the code is now, it just would have been faster if I'd got it to work

I suspect it's because there's compiler state between builds, or something.

https://github.com/clojure-emacs/orchard/pull/95 Opened the .close solution.

I guess I can try and workaround this by monkeypatching cider's orchard? Yikes.