Deubgging Duplicate classes, unwanted transitive dependencies

[Eric Ayers]

Hi Pants-devel,

I’m getting closer to getting a working binary out of my pants build. I’ve been able to compile with ‘./pants goal bundle ‘ and I get a directory full of stuff under dist/-bundle/ just like I expected.

I’m getting many duplicate classes listed in the output, like:

Duplicate classes and/or resources detected in artifacts: (u'log4j-apache-log4j-extras-1.2.17.jar', u'log4j-log4j-1.2.17.jar', u'org.slf4j-log4j-over-slf4j-1.7.4.jar')

… There are 37 different messages like this …
As a part of the conversion from Maven, I took all of the stantzas in our pom.xml files and turned them into jar().exclude() calls in out Pants BUILD files, but either I missed some or that was not sufficient.
Unfortunately, this isn’t just annoying, it keeps my app from running:

java -jar ./dist/foo-bundle/foo.jar  
SLF4J: Detected both log4j-over-slf4j.jar AND slf4j-log4j12.jar on the class path, preempting StackOverflowError.  
SLF4J: See also http://www.slf4j.org/codes.html#log4jDelegationLoop for more details. 
Exception in thread "main" java.lang.ExceptionInInitializerError 
    at org.apache.log4j.Logger.getLogger(Logger.java:40) 
    at org.apache.log4j.Logger.getLogger(Logger.java:48) 
    at ... 
Caused by: java.lang.IllegalStateException: Detected both log4j-over-slf4j.jar AND slf4j-log4j12.jar on the class path, preempting StackOverflowError. See also http://www.slf4j.org/codes.html#log4jDelegationLoop for more details. 
    at org.apache.log4j.Log4jLoggerFactory.<clinit>(Log4jLoggerFactory.java:50) 
    ... 5 more

In trying to diagnose this, I came across the goad depmap:

$ ./pants goal depmap <name>  > /tmp/depmap.out

$ grep log4j-over-slf4j /tmp/depmap.out 
<nothing>

When I look at depmap.out I see a very nice dependency tree, but I what I don’t see is the transient dependencies that ivy is pulling in, and these are the ones I need to work on filtering out. Do you have any suggestions on how to go about finding these? I was thinking it would be nice to have a flag to add to goal depmap that would show ivy deps embedded with the rest of the depmap.

Also, maybe related, there is some output that I don’t understand:

                      Missing BUILD dependency testing/src/main/java:lib -> 3rdparty:com.sun.jersey.jersey-core because: 
                           testing/src/main/java/com/squareup/testing/integration/ProtoJsonHttpClient.java uses .pants.d/ivy/jars/com.sun.jersey/jersey-core/jars/jersey-core-1.18.1.jar 
                           testing/src/main/java/com/squareup/testing/http/MockHttpHeaders.java uses .pants.d/ivy/jars/com.sun.jersey/jersey-core/jars/jersey-core-1.18.1.jar 
                       Missing BUILD dependency common/card/src/main/java:lib -> .pants.d/ivy/jars/com.squareup.common/common-foo/jars/common-foo-d6ed88d6-a279fe02.jar 
                       ... about 306 of these ...

Thanks!
-Eric.

[John Sirois]

On Mon, May 5, 2014 at 5:25 AM, Eric Ayers <zun...@squareup.com> wrote:

Hi Pants-devel,

I’m getting closer to getting a working binary out of my pants build. I’ve been able to compile with ‘./pants goal bundle ‘ and I get a directory full of stuff under dist/-bundle/ just like I expected.

I’m getting many duplicate classes listed in the output, like:

Duplicate classes and/or resources detected in artifacts: (u'log4j-apache-log4j-extras-1.2.17.jar', u'log4j-log4j-1.2.17.jar', u'org.slf4j-log4j-over-slf4j-1.7.4.jar')

… There are 37 different messages like this …
As a part of the conversion from Maven, I took all of the stantzas in our pom.xml files and turned them into jar().exclude() calls in out Pants BUILD files, but either I missed some or that was not sufficient.
Unfortunately, this isn’t just annoying, it keeps my app from running:

java -jar ./dist/foo-bundle/foo.jar  
SLF4J: Detected both log4j-over-slf4j.jar AND slf4j-log4j12.jar on the class path, preempting StackOverflowError.  
SLF4J: See also http://www.slf4j.org/codes.html#log4jDelegationLoop for more details. 
Exception in thread "main" java.lang.ExceptionInInitializerError 
    at org.apache.log4j.Logger.getLogger(Logger.java:40) 
    at org.apache.log4j.Logger.getLogger(Logger.java:48) 
    at ... 
Caused by: java.lang.IllegalStateException: Detected both log4j-over-slf4j.jar AND slf4j-log4j12.jar on the class path, preempting StackOverflowError. See also http://www.slf4j.org/codes.html#log4jDelegationLoop for more details. 
    at org.apache.log4j.Log4jLoggerFactory.<clinit>(Log4jLoggerFactory.java:50) 
    ... 5 more

In trying to diagnose this, I came across the goad depmap:

$ ./pants goal depmap <name>  > /tmp/depmap.out

$ grep log4j-over-slf4j /tmp/depmap.out 
<nothing>

When I look at depmap.out I see a very nice dependency tree, but I what I don’t see is the transient dependencies that ivy is pulling in, and these are the ones I need to work on filtering out. Do you have any suggestions on how to go about finding these? I was thinking it would be nice to have a flag to add to goal depmap that would show ivy deps embedded with the rest of the depmap.

It would be nice to merge the dependency metadata goals into 1.  Right now for deps represented directly in BUILDs there are 2: `depmap` and `dependencies`.  For transitive jvm dependencies there is `resolve --ivy-open`.  I think you want the latter here.

Also, maybe related, there is some output that I don’t understand:

                      Missing BUILD dependency testing/src/main/java:lib -> 3rdparty:com.sun.jersey.jersey-core because: 
                           testing/src/main/java/com/squareup/testing/integration/ProtoJsonHttpClient.java uses .pants.d/ivy/jars/com.sun.jersey/jersey-core/jars/jersey-core-1.18.1.jar 
                           testing/src/main/java/com/squareup/testing/http/MockHttpHeaders.java uses .pants.d/ivy/jars/com.sun.jersey/jersey-core/jars/jersey-core-1.18.1.jar 
                       Missing BUILD dependency common/card/src/main/java:lib -> .pants.d/ivy/jars/com.squareup.common/common-foo/jars/common-foo-d6ed88d6-a279fe02.jar 
                       ... about 306 of these ...

This is code that attempts to find source -> class dependencies not present in the corresponding BUILD.  Is it true that testing/src/main/java/com/squareup/testing/http/MockHttpHeaders.java uses jerser-core apis? If so the message is trying to nudge you to add these to the BUILD.

Thanks!
-Eric.

--
John Sirois
303-512-3301

[Benjy Weinberger]

The latter errors indicate real-world dependencies (that we figured out from JMake/Zinc analysis files) that aren't reflected in BUILD files. We have to check for these because it's possible for compiles to succeed in such cases - e.g., if some other target you happen to also be compiling brings in that dep independently.

However these are currently warnings and not errors because we're not yet 100% convinced we always get that detection right. 

In this case, are you indeed missing those deps in your BUILD files? Also, if it wasn't obvious what those message meant then we should probably change how they're phrased. What phrasing would have made this output's meaning obvious?

~ Benjy

PS Note that we allow indirect dependencies, i.e., if code in A depends on code in C it's fine if the BUILD file dep is just A -> B -> C and not A -> C. This is important in the Scala world. For example, A.scala might infer a type in C.scala via some code in B.scala, but never mention that type explicitly anywhere. It's not reasonable to force the author of A to figure out that implicit dependency on C, and then figure it out all over again if the author of B.scala changes the implementation to use some D.scala.

[Eric Ayers]

I am pretty sure I did not leave out 300 dependencies, bit I'll have to dig deeper.   I used our Maven pom.xml files to determine them and generate the BUILD files from them at the moment is there some reason that I would have to be more specific with Pants? 

For better or for worse, it is picking up log4j-over-slf4j which we do not want at all. It has some classes that are also in one of the log4j jar files. 

Is there a way to turn off this feature as an experiment?

[Benjy Weinberger]

There's a cmd-line flag: --compile-java-something (I don't remember off hand, but run your full command but add --help/-h to see the actual flag name)

[Eric Ayers]

I think I know why I'm seeing hundreds of "Missing BUILD dependency..." messages now.

 Missing BUILD dependency webservice/session/src/main/java:lib -> .pants.d/ivy/jars/com.squareup/common/jars/common-c807010a-ec1445af.jar

 Missing BUILD dependency webservice/session/src/main/java:lib -> .pants.d/ivy/jars/com.squareup/crypto/jars/crypto-3f97f4a2-a279fe02.jar

 Missing BUILD dependency webservice/client/src/main/java:lib -> .pants.d/ivy/jars/com.squareup/common/jars/common-c807010a-ec1445af.jar

...

But Tien doesn't see the same messages.  It turns out that  we have a plugin that is creating artifacts used for incremental builds that creates lots of the strangely named .jar files in our .ivy2 directory.  I'm guessing it also mangled some of the dependencies there. I'm going to clean out my .ivy2 directory and try again.