<< Back to previous view

[CLJ-1152] PermGen leak in multimethods and protocol fns when evaled Created: 30/Jan/13  Updated: 18/Apr/14

Status: Open
Project: Clojure
Component/s: None
Affects Version/s: Release 1.4
Fix Version/s: Release 1.7

Type: Defect Priority: Critical
Reporter: Chouser Assignee: Unassigned
Resolution: Unresolved Votes: 3
Labels: memory, protocols

Approval: Vetted

 Description   

There is a PermGen memory leak that we have tracked down to protocol methods and multimethods called inside an eval, because of the caches these methods use. The problem only arises when the value being cached is an instance of a class (such as a function or reify) that was defined inside the eval. Thus extending IFn or dispatching a multimethod on an IFn are likely triggers.

My fellow LonoClouder, Jeff Dik describes how to reproduce and work around the problem:

The easiest way that I have found to test this is to set "-XX:MaxPermSize" to a reasonable value so you don't have to wait too long for the PermGen space to fill up, and to use "-XX:+TraceClassLoading" and "-XX:+TraceClassUnloading" to see the classes being loaded and unloaded.

leiningen project.clj
(defproject permgen-scratch "0.1.0-SNAPSHOT"
  :dependencies [[org.clojure/clojure "1.5.0-RC1"]]
  :jvm-opts ["-XX:MaxPermSize=32M"
             "-XX:+TraceClassLoading"
             "-XX:+TraceClassUnloading"])

You can use lein swank 45678 and connect with slime in emacs via M-x slime-connect.

To monitor the PermGen usage, you can find the Java process to watch with "jps -lmvV" and then run "jstat -gcold <PROCESS_ID> 1s". According to the jstat docs, the first column (PC) is the "Current permanent space capacity (KB)" and the second column (PU) is the "Permanent space utilization (KB)". VisualVM is also a nice tool for monitoring this.

Multimethod leak

Evaluating the following code will run a loop that eval's (take* (fn foo [])).

multimethod leak
(defmulti take* (fn [a] (type a)))

(defmethod take* clojure.lang.Fn
  [a]
  '())

(def stop (atom false))
(def sleep-duration (atom 1000))

(defn run-loop []
  (when-not @stop
    (eval '(take* (fn foo [])))
    (Thread/sleep @sleep-duration)
    (recur)))

(future (run-loop))

(reset! sleep-duration 0)

In the lein swank session, you will see many lines like below listing the classes being created and loaded.

[Loaded user$eval15802$foo__15803 from __JVM_DefineClass__]
[Loaded user$eval15802 from __JVM_DefineClass__]

These lines will stop once the PermGen space fills up.

In the jstat monitoring, you'll see the amount of used PermGen space (PU) increase to the max and stay there.

-    PC       PU        OC          OU       YGC    FGC    FGCT     GCT
 31616.0  31552.7    365952.0         0.0      4     0    0.000    0.129
 32000.0  31914.0    365952.0         0.0      4     0    0.000    0.129
 32768.0  32635.5    365952.0         0.0      4     0    0.000    0.129
 32768.0  32767.6    365952.0      1872.0      5     1    0.000    0.177
 32768.0  32108.2    291008.0     23681.8      6     2    0.827    1.006
 32768.0  32470.4    291008.0     23681.8      6     2    0.827    1.006
 32768.0  32767.2    698880.0     24013.8      8     4    1.073    1.258
 32768.0  32767.2    698880.0     24013.8      8     4    1.073    1.258
 32768.0  32767.2    698880.0     24013.8      8     4    1.073    1.258

A workaround is to run prefer-method before the PermGen space is all used up, e.g.

(prefer-method take* clojure.lang.Fn java.lang.Object)

Then, when the used PermGen space is close to the max, in the lein swank session, you will see the classes created by the eval'ing being unloaded.

[Unloading class user$eval5950$foo__5951]
[Unloading class user$eval3814]
[Unloading class user$eval2902$foo__2903]
[Unloading class user$eval13414]

In the jstat monitoring, there will be a long pause when used PermGen space stays close to the max, and then it will drop down, and start increasing again when more eval'ing occurs.

-    PC       PU        OC          OU       YGC    FGC    FGCT     GCT
 32768.0  32767.9    159680.0     24573.4      6     2    0.167    0.391
 32768.0  32767.9    159680.0     24573.4      6     2    0.167    0.391
 32768.0  17891.3    283776.0     17243.9      6     2   50.589   50.813
 32768.0  18254.2    283776.0     17243.9      6     2   50.589   50.813

The defmulti defines a cache that uses the dispatch values as keys. Each eval call in the loop defines a new foo class which is then added to the cache when take* is called, preventing the class from ever being GCed.

The prefer-method workaround works because it calls clojure.lang.MultiFn.preferMethod, which calls the private MultiFn.resetCache method, which completely empties the cache.

Protocol leak

The leak with protocol methods similarly involves a cache. You see essentially the same behavior as the multimethod leak if you run the following code using protocols.

protocol leak
(defprotocol ITake (take* [a]))

(extend-type clojure.lang.Fn
  ITake
  (take* [this] '()))

(def stop (atom false))
(def sleep-duration (atom 1000))

(defn run-loop []
  (when-not @stop
    (eval '(take* (fn foo [])))
    (Thread/sleep @sleep-duration)
    (recur)))

(future (run-loop))

(reset! sleep-duration 0)

Again, the cache is in the take* method itself, using each new foo class as a key.

A workaround is to run -reset-methods on the protocol before the PermGen space is all used up, e.g.

(-reset-methods ITake)

This works because -reset-methods replaces the cache with an empty MethodImplCache.



 Comments   
Comment by Chouser [ 30/Jan/13 9:10 AM ]

I think the most obvious solution would be to constrain the size of the cache. Adding an item to the cache is already not the fastest path, so a bit more work could be done to prevent the cache from growing indefinitely large.

That does raise the question of what criteria to use. Keep the first n entries? Keep the n most recently used (which would require bookkeeping in the fast cache-hit path)? Keep the n most recently added?

Comment by Jamie Stephens [ 18/Oct/13 9:35 AM ]

At a minimum, perhaps a switch to disable the caches – with obvious performance impact caveats.

Seems like expensive LRU logic is probably the way to go, but maybe don't have it kick in fully until some threshold is crossed.

Comment by Alex Miller [ 18/Oct/13 4:28 PM ]

A report seeing this in production from mailing list:
https://groups.google.com/forum/#!topic/clojure/_n3HipchjCc

Comment by Adrian Medina [ 10/Dec/13 11:43 AM ]

So this is why we've been running into PermGen space exceptions! This is a fairly critical bug for us - I'm making extensive use of multimethods in our codebase and this exception will creep in at runtime randomly.

Comment by Kevin Downey [ 17/Apr/14 9:52 PM ]

it might be better to split this in to two issues, because at a very abstract level the two issues are the "same", but concretely they are distinct (protocols don't really share code paths with multimethods), keeping them together in one issue seems like a recipe for a large hard to read patch





[CLJ-1322] doseq with several bindings causes "ClassFormatError: Invalid Method Code length" Created: 10/Jan/14  Updated: 22/Apr/14

Status: Open
Project: Clojure
Component/s: None
Affects Version/s: Release 1.5
Fix Version/s: Release 1.7

Type: Defect Priority: Major
Reporter: Miikka Koskinen Assignee: Unassigned
Resolution: Unresolved Votes: 1
Labels: None
Environment:

Clojure 1.5.1, java 1.7.0_25, OpenJDK Runtime Environment (IcedTea 2.3.10) (7u25-2.3.10-1ubuntu0.12.04.2)


Approval: Vetted

 Description   
user=> (def a1 (range 10))
#'user/a1
user=> (doseq [x1 a1 x2 a1 x3 a1 x4 a1 x5 a1 x6 a1 x7 a1 x8 a1] (do))
CompilerException java.lang.ClassFormatError: Invalid method Code length 69883 in class file user$eval1032, compiling:(NO_SOURCE_PATH:2:1)

While this example is silly, it's a problem we've hit a couple of times. It's pretty surprising when you have just a couple of lines of code and suddenly you get the code length error.



 Comments   
Comment by Kevin Downey [ 18/Apr/14 12:20 AM ]

reproduces with jdk 1.8.0 and clojure 1.6

Comment by Nicola Mometto [ 22/Apr/14 5:35 PM ]

A potential fix for this is to make doseq generate intermediate fns like `for` does instead of expanding all the code directly.





[CLJ-1192] vec function is substantially slower than into function Created: 06/Apr/13  Updated: 18/Apr/14

Status: Open
Project: Clojure
Component/s: None
Affects Version/s: Release 1.5
Fix Version/s: Release 1.7

Type: Defect Priority: Major
Reporter: Luke VanderHart Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: performance

Approval: Vetted

 Description   

(vec coll) and (into [] coll) do exactly the same thing. However, due to into using transients, it is substantially faster. On my machine:

(time (dotimes [_ 100] (vec (range 100000))))
"Elapsed time: 732.56 msecs"

(time (dotimes [_ 100] (into [] (range 100000))))
"Elapsed time: 491.411 msecs"

This is consistently repeatable.

Since vec's sole purpose is to transform collections into vectors, it should do so at the maximum speed available.



 Comments   
Comment by Andy Fingerhut [ 07/Apr/13 5:50 PM ]

I am pretty sure that Clojure 1.5.1 also uses transient vectors for (vec (range n)) (probably also some earlier versions of Clojure, too).

Look at vec in core.clj. It checks whether its arg is a java.util.Collection, which lazy seqs are, so calls (clojure.lang.LazilyPersistentVector/create coll).

LazilyPersistentVector's create method checks whether its argument is an ISeq, which lazy seqs are, so it calls PersistentVector.create(RT.seq(coll)).

All 3 of PersistentVector's create() methods use transient vectors to build up the result.

I suspect the difference in run times are not because of transients or not, but because of the way into uses reduce, and perhaps may also have something to do with the perhaps-unnecessary call to RT.seq in LazilyPersistentVector's create method (in this case, at least – it is likely needed for other types of arguments).

Comment by Alan Malloy [ 14/Jun/13 2:17 PM ]

I'm pretty sure the difference is that into uses reduce: since reducers were added in 1.5, chunked sequences know how to reduce themselves without creating unnecessary cons cells. PersistentVector/create doesn't use reduce, so it has to allocate a cons cell for each item in the sequence.

Comment by Gary Fredericks [ 08/Sep/13 1:55 PM ]

Is there any downside to (defn vec [coll] (into [] coll)) (or the inlined equivalent)?

Comment by Ghadi Shayban [ 11/Apr/14 5:13 PM ]

While I agree that there are improvements and possibly low-hanging fruit, FWIW https://github.com/clojure/tools.analyzer/commit/cf7dda81a22f4c9c1fe64c699ca17e7deed61db4#commitcomment-5989545

showed a 5% slowdown from a few callsites in tools.analyzer.

This ticket's benchmark is incomplete in that it covers a single type of argument (chunked range), and flawed as it timing the expense of realizing the range. (That could be a legit benchmark case, but it shouldn't be the only one).

Sorry to rain on a parade. I promise like speed too!





[CLJ-701] Compiler loses 'loop's return type in some cases Created: 03/Jan/11  Updated: 18/Apr/14

Status: Open
Project: Clojure
Component/s: None
Affects Version/s: Backlog
Fix Version/s: Release 1.7

Type: Defect Priority: Major
Reporter: Chouser Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None
Environment:

Clojure commit 9052ca1854b7b6202dba21fe2a45183a4534c501, version 1.3.0-master-SNAPSHOT


Approval: Vetted

 Description   
(set! *warn-on-reflection* true)
(fn [] (loop [b 0] (recur (loop [a 1] a))))

Generates the following warnings:

recur arg for primitive local: b is not matching primitive, had: Object, needed: long
Auto-boxing loop arg: b

This is interesting for several reasons. For one, if the arg to recur is a let form, there is no warning:

(fn [] (loop [b 0] (recur (let [a 1] a))))

Also, the compiler appears to understand the return type of loop forms just fine:

(use '[clojure.contrib.repl-utils :only [expression-info]])
(expression-info '(loop [a 1] a))
;=> {:class long, :primitive? true}

The problem can of course be worked around using an explicit cast on the loop form:

(fn [] (loop [b 0] (recur (long (loop [a 1] a)))))

Reported by leafw in IRC: http://clojure-log.n01se.net/date/2011-01-03.html#10:31



 Comments   
Comment by a_strange_guy [ 03/Jan/11 4:36 PM ]

The problem is that a 'loop form gets converted into an anonymous fn that gets called immediately, when the loop is in a expression context (eg. its return value is needed, but not as the return value of a method/fn).

so

(fn [] (loop [b 0] (recur (loop [a 1] a))))

gets converted into

(fn [] (loop [b 0] (recur ((fn [] (loop [a 1] a))))))

see the code in the compiler:
http://github.com/clojure/clojure/blob/master/src/jvm/clojure/lang/Compiler.java#L5572

this conversion already bites you if you have mutable fields in a deftype and want to 'set! them in a loop

http://dev.clojure.org/jira/browse/CLJ-274

Comment by Christophe Grand [ 23/Nov/12 2:28 AM ]

loops in expression context are lifted into fns because else Hotspot doesn't optimize them.
This causes several problems:

  • type inference doesn't propagate outside of the loop[1]
  • the return value is never a primitive
  • mutable fields are inaccessible
  • surprise allocation of one closure objects each time the loop is entered.

Adressing all those problems isn't easy.
One can compute the type of the loop and emit a type hint but it works only with reference types. To make it works with primitive, primitie fns aren't enough since they return only long/double: you have to add explicit casts.
So solving the first two points can be done in a rather lccal way.
The two other points require more impacting changes, the goal would be to emit a method rather than a fn. So it means at the very least changing ObjExpr and adding a new subclassof ObjMethod.

[1] beware of CLJ-1111 when testing.

Comment by Alex Miller [ 21/Oct/13 10:28 PM ]

I don't think this is going to make it into 1.6, so removing the 1.6 tag.





[CLJ-1100] Reader literals cannot contain periods Created: 02/Nov/12  Updated: 22/Apr/14

Status: Open
Project: Clojure
Component/s: None
Affects Version/s: None
Fix Version/s: Release 1.7

Type: Defect Priority: Minor
Reporter: Kevin Lynagh Assignee: Steve Miner
Resolution: Unresolved Votes: 1
Labels: reader

Approval: Vetted

 Description   

The reader tries to read a record instead of a literal if the tag contains periods.

user> (binding [*data-readers* {'foo/bar #'identity}] (read-string "#foo/bar 1"))
1
user> (binding [*data-readers* {'foo/bar.x #'identity}] (read-string "#foo/bar.x 1"))
ClassNotFoundException foo/bar.x  java.lang.Class.forName0 (Class.java:-2)

Summary of reader forms:

Kind Example Constraint Status
Record #user.Foo[1] record class name OK
Class #java.lang.String["abc"] class name OK
Clojure reader tag #uuid "c48d7d6e-f3bb-425a-abc5-44bd014a511d" not a class name, no "/" OK
Library reader tag #my/card "5H" not a class name, has "/" OK
  #my.ns/card "5H" not a class name, has "/" OK
  #my/playing.card "5H" not a class name, has "/" BROKEN - read as record

Note: reader tags should not be allowed to override the record reader.

Cause: In LispReader, CtorReader.invoke() decides between record and tagged literal based on whether the tag has a ".".

Proposed: Change the discriminator in CtorReader.

Alternative 1 (purely string inspection):

  • If name has a "/" -> readTagged (not a legal class name)
  • If name has no "/" or "." -> readTagged (records must have qualified names)
  • Else -> readRecord (also covers Java classes)

Tradeoffs: Clojure-defined data reader tags must not contain periods. Not possible to read a Java class with no package. Avoids unnecessary class loading/construction for all tags.

Alternative 2 (prioritize Class check):

  • Attempt readRecord (also covers Java classes)
  • If failed, attempt readTagged

Tradeoffs: Clojure tags could not override Java/record constructors - I'm not sure that's something we'd ever want to do, but this would cut that off. This alternative may attempt classloading when it would not have before.

Hybrids of these are also possible.

Patch:

Screened by:



 Comments   
Comment by Steve Miner [ 06/Nov/12 9:41 AM ]

The suggested patch (clj-1100-reader-literal-periods.patch) will break reading records when *default-data-reader-fn* is set. Try adding a test like this:

(deftest tags-containing-periods-with-default
      ;; we need a predefined record for this test so we (mis)use clojure.reflect.Field for convenience
      (let [v "#clojure.reflect.Field{:name \"fake\" :type :fake :declaring-class \"Fake\" :flags nil}"]
        (binding [*default-data-reader-fn* nil]
          (is (= (read-string v) #clojure.reflect.Field{:name "fake" :type :fake :declaring-class "Fake" :flags nil})))
        (binding [*default-data-reader-fn* (fn [tag val] (assoc val :meaning 42))]
          (is (= (read-string v) #clojure.reflect.Field{:name "fake" :type :fake :declaring-class "Fake" :flags nil})))))
Comment by Rich Hickey [ 29/Nov/12 9:36 AM ]

The problem assessment is ok, but the resolution approach may not be. What happens should be based not upon what is in data-readers but whether or not the name names a class.

Is the intent here to allow readers to circumvent records? I'm not in favor of that.

Comment by Steve Miner [ 29/Nov/12 4:01 PM ]

New patch following Rich's comments. The decision to read a record is now based on the symbol containing periods and not having a namespace. Otherwise, it is considered a data reader tag. User
defined tags are required to be qualified but they may now have periods in the name. Tests added to show that
data readers cannot override record classes. Note: Clojure-defined data reader tags may be unqualified, but they should not contain periods in order to avoid confusion with record classes.

Comment by Steve Miner [ 29/Nov/12 4:17 PM ]

I deleted my old patch and some comments referring to it to avoid confusion.

In Clojure 1.5 beta 1, # followed by a qualified symbol with a period in the name is considered a record and causes an exception for the missing record class. With the patch, only non-qualified symbols containing periods are considered records. That allows user-defined qualified symbols with periods in their names to be used as data reader tags.

Comment by Andy Fingerhut [ 07/Feb/13 9:05 AM ]

clj-1100-periods-in-data-reader-tags-patch-v2.txt dated Feb 7 2013 is identical to CLJ-1100-periods-in-data-reader-tags.patch dated Nov 29 2012, except it applies cleanly to latest master. The only change appears to be in some white space in the context lines.

Comment by Andy Fingerhut [ 07/Feb/13 12:53 PM ]

I've removed clj-1100-periods-in-data-reader-tags-patch-v2.txt mentioned in the previous comment, because I learned that CLJ-1100-periods-in-data-reader-tags.patch dated Nov 29 2012 applies cleanly to latest master and passes all tests if you use this command to apply it.

% git am --keep-cr -s --ignore-whitespace < CLJ-1100-periods-in-data-reader-tags.patch

I've already updated the JIRA workflow and screening patches wiki pages to mention this --ignore-whitespace option.

Comment by Andy Fingerhut [ 13/Feb/13 11:31 AM ]

Both of the current patches, CLJ-1100-periods-in-data-reader-tags.patch dated Nov 29 2012, and clj-1100-reader-literal-periods.patch dated Nov 6 2012, fail to apply cleanly to latest master (1.5.0-RC15) as of today, although they did last week. Given all of the changes around read / read-string and edn recently, they should probably be evaluated by their authors to see how they should be updated.

Comment by Steve Miner [ 14/Feb/13 12:23 PM ]

I deleted my patch: CLJ-1100-periods-in-data-reader-tags.patch. clj-1100-reader-literal-periods.patch is clearly wrong, but the original author or an administrator has to delete that.

Comment by Kevin Lynagh [ 14/Feb/13 1:28 PM ]

I cannot figure out how to remove my attachment (clj-1100-reader-literal-periods.patch) in JIRA.

Comment by Steve Miner [ 14/Feb/13 1:43 PM ]

Downarrow (popup) menu to the right of the "Attachments" section. Choose "manager attachments".

Comment by Kevin Lynagh [ 14/Feb/13 2:02 PM ]

Great, thanks Steve. Are you going to take another pass at this issue, or should I give it a go?

Comment by Steve Miner [ 14/Feb/13 3:04 PM ]

Kevin, I'm not planning to work on this right now as 1.5 is pretty much done. It might be worthwhile discussing the issue a bit on the dev mailing list before working on a patch, but that's up to you. I think my approach was correct, although now changes would have to be applied to both LispReader and EdnReader.

Comment by Alex Miller [ 09/Apr/14 10:29 AM ]

Updated description based on my understanding.

Comment by Steve Miner [ 22/Apr/14 3:30 PM ]

I will resurrect my old patch and update it for the changes since 1.5.





[CLJ-823] Piping seque into seque can deadlock Created: 03/Aug/11  Updated: 18/Apr/14

Status: Open
Project: Clojure
Component/s: None
Affects Version/s: Release 1.3
Fix Version/s: Release 1.7

Type: Defect Priority: Minor
Reporter: Greg Chapman Assignee: Unassigned
Resolution: Unresolved Votes: 1
Labels: None
Environment:

Windows 7; JVM 1.6; Clojure 1.3 beta 1


Approval: Vetted

 Description   

I'm not sure if this is a supported scenario, but the following deadlocks in Clojure 1.3:

(let [xs (seque (range 150000))
ys (seque (filter odd? xs))]
(apply + ys))

As I understand it, the problem is that ys' fill takes place on an agent thread, so when it calls xs' drain, the (send-off agt fill) does not immediately trigger xs' fill, but is instead put on the nested list to be performed when ys' agent returns. Unfortunately, ys' fill will eventually block trying to take from xs, and so it never returns and the pending send-offs are never sent. Wrapping the send-off in drain to:

(future (send-off agt fill))

is a simple (probably not optimal) way to fix the deadlock.



 Comments   
Comment by Peter Monks [ 07/Jan/13 3:43 PM ]

Reproduced on 1.4.0 and 1.5.0-RC1 as well, albeit with this example:

(seque 3 (seque 3 (range 10)))

Comment by Stuart Halloway [ 30/Mar/13 9:16 AM ]

release-pending-sends?





Generated at Thu Apr 24 10:44:10 CDT 2014 using JIRA 4.4#649-r158309.