Clojurians Log v2

I am confused. I do not know much about the Java @Override annotation, other than the little I have read here so far: https://docs.oracle.com/javase/7/docs/api/java/lang/Override.html . It suggests that the Java compiler should generate an error message if the method it annotates is not overriding some method of a superclass. The @Override annotation is used on the rangedIterator method of class clojure.lang.PersistentVector, but Google searches turn up almost nothing for rangedIterator except for some things that look related to Clojure. Anyone know more about this?

https://github.com/clojure/clojure/blob/master/src/jvm/clojure/lang/PersistentVector.java#L288-L289

And if I had been a little more patient in looking before asking, I see there are two such methods, one in APersistentVector and the other in PersistentVector, one overriding the other ... sigh

Note that @Override is also often use when implementing interface methods: https://stackoverflow.com/questions/212614/should-we-override-an-interfaces-method-implementation

Looking at seq's on vectors recently, and the objects created by seq for these (and likely for all other persistent collections) have fields for hash, hasheq, and metadata. I know I'm thinking micro-optimization right now, because that's where my head is with core.rrb-vector library, but it seems .... odd .... that every seq you ever make while traversing Clojure collections has room for these things that are almost never used.

I don't have any recommendations to change anything from that. Just an observation from someone who has spent too much time thinking about shaving out bits and bytes.

On the plus side, every single point you are at a traversal of a sequence, that seq you have a reference to is ready to be used as a key in a hash map, with hash caching. 🙂

I’m looking at an extremely strange bug in the latest Cursive release. Users are reporting the following error: java.lang.ClassCastException: class com.intellij.idea.IdeaLogger cannot be cast to class org.apache.log4j.Category (com.intellij.idea.IdeaLogger and org.apache.log4j.Category are in unnamed module of loader com.intellij.util.lang.UrlClassLoader @192b07fd)

I have been unable to reproduce this bug locally. However looking at the bytcode, there’s something very strange. This is the code:

(log/debug "Checking module " (names/name module))

(defmacro debug [& args]
  `(let [logger# (get-logger ~(str \# *ns*))]
     (when (.isDebugEnabled logger#)
       (do-log logger# do-debug ~@args))))

get-logger is type hinted to return com.intellij.openapi.diagnostic.Logger: (defn ^Logger get-logger [key] ... )

However in the version of the code that was deployed, the .isDebugEnabled check does a checkcast to org.apache.log4j.Category:

public java.lang.Object invoke(java.lang.Object, java.lang.Object);
    Code:
       0: getstatic     #26                 // Field const__0:Lclojure/lang/Var;
       3: invokevirtual #32                 // Method clojure/lang/Var.getRawRoot:()Ljava/lang/Object;
       6: checkcast     #34                 // class clojure/lang/IFn
       9: ldc           #36                 // String #cursive.stubs
      11: invokeinterface #39,  2           // InterfaceMethod clojure/lang/IFn.invoke:(Ljava/lang/Object;)Ljava/lang/Object;
      16: astore_3
      17: aload_3
      18: checkcast     #41                 // class org/apache/log4j/Category
      21: invokevirtual #45                 // Method org/apache/log4j/Category.isDebugEnabled:()Z

I cannot for the life of me figure out how that happened. When I recompile the same code in the same environment, the checkcast is to com.intellij.openapi.diagnostic.Logger:

public java.lang.Object invoke(java.lang.Object, java.lang.Object);
    Code:
       0: getstatic     #26                 // Field const__0:Lclojure/lang/Var;
       3: invokevirtual #32                 // Method clojure/lang/Var.getRawRoot:()Ljava/lang/Object;
       6: checkcast     #34                 // class clojure/lang/IFn
       9: ldc           #36                 // String #cursive.stubs
      11: invokeinterface #39,  2           // InterfaceMethod clojure/lang/IFn.invoke:(Ljava/lang/Object;)Ljava/lang/Object;
      16: astore_3
      17: aload_3
      18: checkcast     #41                 // class com/intellij/openapi/diagnostic/Logger
      21: invokevirtual #45                 // Method com/intellij/openapi/diagnostic/Logger.isDebugEnabled:()Z

I’m totally mystified by this. Obviously something has changed, but I have no idea what. Could the class used for the checkcast be being determined by method overload resolution, or something like that?

The actual class being decompiled there is the fn in this code:

(reduce (fn [res module]
              (log/debug "Checking module " (names/name module))
              ...)

The logging namespace has never had a reference to Category.

All this code is AOT compiled, so it’s compiled in my environment and shouldn’t be affected by what the users are running on their machines.

the type hint on the return value is resolved relative to the imports of the namespace the class is used in, not the imports of the namespace where it is defined

so using a simple name instead of the full classname can be a bad idea

Ohhh… and in this case the namespaces are different because of macroexpansion.

However in the namespace the macro is expanded in, there is no Logger class imported.

This is with Clojure 1.10.1 BTW - I thought that that behaviour changed around Clojure 1.8?

And even if that were the case, surely it should still at least be deterministic.

ah, it did change in 1.8

Just to clarify - get-logger and the debug macro are defined in the same namespace. The usage of debug is in some other namespace with no Logger class imported.

it doesn't matter where the debug macro is defined, it only matters where it is expanded(called), because that is where the code ends up being

but if it ever did, that combined with stale aot class files would leave you with a head scratcher like this

but yeah, I am just spit balling, there are a lot of ifs and buts and maybes there

looking at the commit for clj-1232 it looks like it might only fully qualify for type hints on the arg vector

I’m pretty sure that hints on the var also resolve since 1.8, but I don’t know whether that’s on the same JIRA or not.

nope, type hinting the symbol gets resolved too, so I either read that wrong or something else fixed that

So, looking at my build I found a problem which might have left some AOT files from a previous branch there. But I still have no references to Category in any branch, and the code for these namespaces is also the same across all branches.

it wouldn't be a reference to Category, it would be org.apache.log4j.Logger and the reflection stuff (and this is hand wavy because I don't entirely recall how the reflector does this stuff) determined the correct thing to do for calling isDebugEnabled on a Logger is to cast the Logger to Category first (since Logger inherits isDebugEnabled from Category)

I guess technically it wouldn't even have to be org.apache.log4j.Logger, just any class named Logger, that extended Category

I’ll check all my branches, but I basically never work directly with log4j. It’s possible I accidentally auto-imported something I guess.

so like, if com.intellij.openapi.diagnostic.Logger extended Category at one point, the code was aot'ed, then run with com.intellij.openapi.diagnostic.Logger no longer extending Category

Hmm - that is actually plausible since I compile the older branches first, and it’s possible the older versions of IntelliJ extended Category directly.

Thanks - I’ll go with that as a working theory, and fix my build either way.