Multiple downloads of the same libs in every build

avently commented 6 years ago

I noticed that Kobalt tries to download several artifacts 3 times for one ./kobalw assemble. So it tries to download them every time I build the app. Compilation time increases to ~ minute.

Downloading: https://clojars.org/repo/org/eclipse/collections/eclipse-collections-api/maven-metadata.xml
Downloading: https://maven.google.com/org/eclipse/collections/eclipse-collections-api/maven-metadata.xml
Downloading: https://mvnrepository.com/org/eclipse/collections/eclipse-collections-api/maven-metadata.xml
Downloading: https://jitpack.io/org/eclipse/collections/eclipse-collections-api/maven-metadata.xml
Downloading: https://clojars.org/repo/org/eclipse/collections/eclipse-collections/maven-metadata.xml
Downloading: https://maven.google.com/org/eclipse/collections/eclipse-collections/maven-metadata.xml
Downloading: https://jitpack.io/org/eclipse/collections/eclipse-collections/maven-metadata.xml
Downloading: https://mvnrepository.com/org/eclipse/collections/eclipse-collections/maven-metadata.xml
Downloading: https://maven.google.com/org/eclipse/collections/eclipse-collections-forkjoin/maven-metadata.xml
Downloading: https://jitpack.io/org/eclipse/collections/eclipse-collections-forkjoin/maven-metadata.xml
Downloading: https://clojars.org/repo/org/eclipse/collections/eclipse-collections-forkjoin/maven-metadata.xml
Downloading: https://mvnrepository.com/org/eclipse/collections/eclipse-collections-forkjoin/maven-metadata.xml
Downloading: https://clojars.org/repo/com/google/guava/guava/maven-metadata.xml
Downloading: https://jitpack.io/com/google/guava/guava/maven-metadata.xml
Downloading: https://maven.google.com/com/google/guava/guava/maven-metadata.xml
Downloading: https://mvnrepository.com/com/google/guava/guava/maven-metadata.xml

The problem happens only with this line in build.kt: compile("org.telegram:telegrambots-abilities:3.6") I can comment all artifacts in build.kt and leave this one alone and the problem persists.

A pom file for this artifact is here: https://github.com/rubenlagus/TelegramBots/blob/master/telegrambots-abilities/pom.xml

I don't know it is the problem with pom file or not but i think this situation should be handled somehow.

There is no need to download 3 times in one build proccess
There is no need to download it more than one time
There is no need to download it from all maven sources instead of from one

How to reproduce?

copy contents of test gist https://gist.github.com/avently/af5d26c99d7783680616826f9353bc3f
paste it into any blank project
run ./kobaltw assemble --log 3 more than one time
see how the same lines "Downloading..." repeats with every build

cbeust commented 6 years ago

I've seen that happen now and then. Sometimes it was caused by external networking factors but I think there is something not quite right in the way Kobalt manages maven-metadata.xml, which might be due by either my incorrect use of Maven Resolver or a bug in Maven Resolver itself (much less likely).

avently commented 6 years ago

@cbeust so what can i do while there is no solution? Maybe i missed some option that can help to ignore this artifacts. Exclude doesn't work for some reason. I even ok to hardcode Kobalt's code to ignore just this dependencies because i'm loosing my time while waiting every build to finish.

cbeust commented 6 years ago

Excluding the dependency should work. Do you have a project I can install so I can reproduce the issue?

avently commented 6 years ago

@cbeust no, sorry. I cannot share a code of that project. In the provided gist file you can test the behavior of the dependency resolver. Excluding dependency also removes excluded lib from jar file so it breaks the app. And it doesn't stop Kobalt from redownloading. Maybe I should make "clean" the project before excluding the lib, I didn't try that. But anyway without the excluded libs app will not work.

Can I help somehow to find a piece of code that cause such strange behaviur? Maybe logging or something else

cbeust commented 6 years ago

No luck reproducing so far. I added the dependency:

compile("org.telegram:telegrambots-abilities:3.6")

I compile after removing the cached artifacts, I see the downloads:

$ rm -rf ~/.kobalt/cache/org/telegram/
$ k clean compile

───── klaxon:clean
───── klaxon:compile
Downloaded artifact org.telegram:telegrambots-abilities:pom:3.6 from Maven (http://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.telegram:telegrambots:pom:3.6 from Maven (http://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.telegram:telegrambots-meta:pom:3.6 from Maven (http://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.telegram:telegrambots-abilities:jar:3.6 from Maven (http://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.telegram:telegrambots:jar:3.6 from Maven (http://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.telegram:telegrambots-meta:jar:3.6 from Maven (http://repo1.maven.org/maven2/, default, releases+snapshots)
  Kotlin 1.2.10 compiling 27 files

I compile again, and I don't see the downloads:

───── klaxon:clean
───── klaxon:compile
  Kotlin 1.2.10 compiling 27 files
  Regular compilation time: 11081 ms
  Java compiling 1 file
warning: [options] bootstrap class path not set in conjunction with -source 1.7
1 warning

avently commented 6 years ago

@cbeust that's because you call "compile". Try "assemble"

cbeust commented 6 years ago

This made no difference, as I expected. The dependency download phase happens before Kobalt does anything, the tasks being run will have no impact on it.

avently commented 6 years ago

Are you sure? Please, take a look at the log from my app. I uploaded it here: https://gist.github.com/avently/ea7a9972124e3394359df4a5cddf6386

You'll see that it happens in assemble task

cbeust commented 6 years ago

Indeed. Odd. Are you using versionless dependencies in your build? (e.g. no version number, ending with a colon)

avently commented 6 years ago

Nope. Every dependency has a version number. Numerical. Like 1.2.3. The problem exists only with this one - https://github.com/rubenlagus/TelegramBots/blob/master/telegrambots-abilities/pom.xml

So maybe you'll see something wrong with it.

cbeust commented 6 years ago

Any way you could create a small project that reproduces the issue? You could start with the default Kobalt project (./kobaltw --init kotlin) and then modify it until you can reproduce the issue?

Then I could look into it.

avently commented 6 years ago

Test.zip

This zip file contains sample project (Build.kt I already placed in Gist and other files including kobaltBuild directory). I can reproduce the issue with it. If you unable to do it just tell me what lines of code should be trace'd and I'll modify the code of Kobalt, will build it and will use it to get relevant logs for you.

avently commented 6 years ago

Maybe this is usefull. Here we see what Kobal do in assemble task

Downloading: https://clojars.org/repo/log4j/log4j/1.2.17/log4j-1.2.17.pom
org.eclipse.aether.transfer.ArtifactNotFoundException: Could not find artifact log4j:log4j:pom:1.2.17 in https___clojars.org_repo (https://clojars.org/repo/)
    at org.eclipse.aether.connector.basic.ArtifactTransportListener.transferFailed(ArtifactTransportListener.java:48)
    at org.eclipse.aether.connector.basic.BasicRepositoryConnector$TaskRunner.run(BasicRepositoryConnector.java:365)
    at org.eclipse.aether.util.concurrency.RunnableErrorForwarder$1.run(RunnableErrorForwarder.java:75)
    at org.eclipse.aether.connector.basic.BasicRepositoryConnector$DirectExecutor.execute(BasicRepositoryConnector.java:583)
    at org.eclipse.aether.connector.basic.BasicRepositoryConnector.get(BasicRepositoryConnector.java:259)
    at org.eclipse.aether.internal.impl.DefaultArtifactResolver.performDownloads(DefaultArtifactResolver.java:498)
    at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:399)
    at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:224)
    at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifact(DefaultArtifactResolver.java:201)
    at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.loadPom(DefaultArtifactDescriptorReader.java:267)
    at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.readArtifactDescriptor(DefaultArtifactDescriptorReader.java:198)
    at org.eclipse.aether.internal.impl.DefaultDependencyCollector.resolveCachedArtifactDescriptor(DefaultDependencyCollector.java:539)
    at org.eclipse.aether.internal.impl.DefaultDependencyCollector.getArtifactDescriptorResult(DefaultDependencyCollector.java:522)
    at org.eclipse.aether.internal.impl.DefaultDependencyCollector.processDependency(DefaultDependencyCollector.java:411)
    at org.eclipse.aether.internal.impl.DefaultDependencyCollector.processDependency(DefaultDependencyCollector.java:365)
    at org.eclipse.aether.internal.impl.DefaultDependencyCollector.process(DefaultDependencyCollector.java:353)
    at org.eclipse.aether.internal.impl.DefaultDependencyCollector.collectDependencies(DefaultDependencyCollector.java:256)
    at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:307)
    at com.beust.kobalt.maven.aether.KobaltMavenResolver.resolve(KobaltMavenResolver.kt:92)
    at com.beust.kobalt.maven.aether.KobaltMavenResolver.resolve$default(KobaltMavenResolver.kt:72)
    at com.beust.kobalt.maven.aether.KobaltMavenResolver.resolveToIds(KobaltMavenResolver.kt:105)
    at com.beust.kobalt.maven.aether.KobaltMavenResolver.resolveToIds(KobaltMavenResolver.kt:116)
    at com.beust.kobalt.maven.aether.KobaltMavenResolver.resolveToIds(KobaltMavenResolver.kt:116)
    at com.beust.kobalt.maven.aether.KobaltMavenResolver.resolveToIds(KobaltMavenResolver.kt:116)
    at com.beust.kobalt.maven.aether.KobaltMavenResolver.resolveToIds$default(KobaltMavenResolver.kt:104)
    at com.beust.kobalt.maven.DependencyManager.transitiveClosure(DependencyManager.kt:188)
    at com.beust.kobalt.maven.DependencyManager.calculateDependencies(DependencyManager.kt:136)
    at com.beust.kobalt.api.IDependencyManager$DefaultImpls.calculateDependencies$default(IDependencyManager.kt:46)
    at com.beust.kobalt.JarGenerator.findIncludedFiles(JarGenerator.kt:107)
    at com.beust.kobalt.plugin.packaging.PackagingPlugin$assemble$benchmark$1.invoke(PackagingPlugin.kt:104)
    at com.beust.kobalt.plugin.packaging.PackagingPlugin$assemble$benchmark$1.invoke(PackagingPlugin.kt:24)
    at com.beust.kobalt.misc.BenchmarksKt.benchmarkMillis(Benchmarks.kt:5)
    at com.beust.kobalt.plugin.packaging.PackagingPlugin.assemble(PackagingPlugin.kt:78)
    at com.beust.kobalt.plugin.packaging.PackagingPlugin.doTaskAssemble(PackagingPlugin.kt:172)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.beust.kobalt.internal.TaskManager$toTaskAnnotation$1.invoke(TaskManager.kt:200)
    at com.beust.kobalt.internal.TaskManager$toTaskAnnotation$1.invoke(TaskManager.kt:18)
    at com.beust.kobalt.internal.TaskManager$addTask$1.call(TaskManager.kt:274)
    at com.beust.kobalt.internal.TaskManager$addTask$1.call(TaskManager.kt:272)
    at com.beust.kobalt.internal.ParallelProjectRunner$runProjects$ProjectTask.call(ParallelProjectRunner.kt:57)
    at com.beust.kobalt.internal.ParallelProjectRunner$runProjects$factory$1$createWorkers$result$1$1.call(ParallelProjectRunner.kt:84)
    at com.beust.kobalt.internal.ParallelProjectRunner$runProjects$factory$1$createWorkers$result$1$1.call(ParallelProjectRunner.kt:80)
    at com.beust.kobalt.internal.DynamicGraphExecutor$run2$$inlined$map$lambda$1.call(DynamicGraph.kt:223)
    at com.beust.kobalt.internal.DynamicGraphExecutor$run2$$inlined$map$lambda$1.call(DynamicGraph.kt:213)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

Later if will find artifact in other place but here we can see stack trace

cbeust commented 6 years ago

Ah, you're using clojars.org, that's a detail you hadn't mentioned until now. It's possible that clojars is publishing invalid metadata XML files.

What happens if you remove that repo?

avently commented 6 years ago

Problematic artifacts (eclipse-*) located in https://repo1.maven.org/maven2 not in clojars. So after removing clojars there is no difference. I wrote this stack trace just to let you know where "Downloading:" method are called in assemble task.

cbeust commented 6 years ago

I unzipped your project and ./kobaltw assemble, and here is what I see:

~/t/Test $ k assemble
            _  __          _               _   _
           | |/ /   ___   | |__     __ _  | | | |_
           | ' /   / _ \  | '_ \   / _` | | | | __|
           | . \  | (_) | | |_) | | (_| | | | | |_
           |_|\_\  \___/  |_.__/   \__,_| |_|  \__|  1.0.113

  Regular compilation time: 3298 ms
Parallel build starting
     ╔══════════════╗
     ║ Building app ║
     ╚══════════════╝
───── app:compile
Downloaded artifact org.jetbrains.kotlin:kotlin-stdlib-jdk8:pom:1.2.30 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.jetbrains.kotlin:kotlin-stdlib-jdk7:pom:1.2.30 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.jetbrains.kotlin:kotlin-stdlib-jdk8:jar:1.2.30 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.jetbrains.kotlin:kotlin-stdlib-jdk7:jar:1.2.30 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.eclipse.collections:eclipse-collections-api:jar:7.1.1 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.eclipse.collections:eclipse-collections:jar:7.1.1 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)
Downloaded artifact org.eclipse.collections:eclipse-collections-forkjoin:jar:7.1.1 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)
  Kotlin 1.2.10 compiling 1 file
  Kotlin incremental compilation is enabled
  Incremental compilation time: 2731 ms
───── app:assemble
  Created .\kobaltBuild\libs\app.jar

Thread report
╔════════════════════════════════════════╗
║  Time (sec) ║ Thread 14                ║
╠════════════════════════════════════════╣
║  0          ║ app                      ║
║  23         ║ app (23)                 ║
╚════════════════════════════════════════╝
          ╔═════════════════════════════════════════════════════════╗
          ║  Project                       ║ Build status║ Time     ║
          ╠═════════════════════════════════════════════════════════╣
          ║  app                           ║ SUCCESS     ║ 23.33    ║
          ╚═════════════════════════════════════════════════════════╝
PARALLEL BUILD SUCCESSFUL (23 SECONDS), sequential build would have taken 23 seconds

Next I deleted ~/.kobalt/cache/org/log4j:

              __ __           __              __   __
             / //_/  ____    / /_   ____ _   / /  / /_
            / ,<    / __ \  / __ \ / __ `/  / /  / __/
           / /| |  / /_/ / / /_/ // /_/ /  / /  / /_
          /_/ |_|  \____/ /_.___/ \__,_/  /_/   \__/  1.0.113

  Regular compilation time: 2591 ms
Parallel build starting
     ╔══════════════╗
     ║ Building app ║
     ╚══════════════╝
───── app:compile
───── app:assemble
Downloaded artifact log4j:log4j:pom:1.2.17 from https___repo1.maven.org_maven2 (https://repo1.maven.org/maven2/, default, releases+snapshots)

Thread report
╔════════════════════════════════════════╗
║  Time (sec) ║ Thread 14                ║
╠════════════════════════════════════════╣
║  0          ║ app                      ║
║  8          ║ app (8)                  ║
╚════════════════════════════════════════╝
          ╔═════════════════════════════════════════════════════════╗
          ║  Project                       ║ Build status║ Time     ║
          ╠═════════════════════════════════════════════════════════╣
          ║  app                           ║ SUCCESS     ║ 8.31     ║
          ╚═════════════════════════════════════════════════════════╝
PARALLEL BUILD SUCCESSFUL (8 SECONDS), sequential build would have taken 8 seconds

Another asssemble right away, no download:

───── app:compile
───── app:assemble

Thread report

avently commented 6 years ago

@cbeust you didn't type --log 3, did you?

avently commented 6 years ago

@cbeust I didn't tell you about --log 3, I thought I did. Sorry. You can see these lines only with --log 3. That's why you couldn't reproduce it. Until now I hope

cbeust commented 6 years ago

Oh, ok. Then yes I see the download, but it's only a download of maven-metadata.xml, which is perfectly normal. I suspect that one of the transitive dependencies of the telegram jar file uses a version range somewhere, so Maven Resolver has to download all the maven-metadata.xml files to locate the correct artifact.

Note that this specific "Downloading:" message does not come from Kobalt (I couldn't find it in the Kobalt code base).

avently commented 6 years ago

@cbeust without that lib Kobalt builds the app ~7 seconds. With it ~1 minute ±. It is not normal. Please, do something helpful in this situation. Maybe something like --ignore-version-range or --resolve false or --offline true. Anything that will help to disable such behaviour.

Also here is the place of "Downloading" message: https://github.com/cbeust/kobalt/blob/fecf4324dd8124c1e174158ab43efec75fb56f27/modules/kobalt-plugin-api/src/main/kotlin/com/beust/kobalt/maven/aether/ConsoleTransferListener.kt#L28

cbeust commented 6 years ago

One culprit is mapdb, which depends on the following version ranges:

        <!--eclipse collections-->
        <ec.version>[7.0.0,7.20.0)</ec.version>
        <guava.version>[15.0,19.20)</guava.version>

What you can do is edit ~/.kobalt/cache/org/mapdb/mapdb/3.0.4/mapdb-3.0.4.pom and hardcode versions instead:

        <!--eclipse collections-->
        <ec.version>9.2.0.M1</ec.version>
        <guava.version>24.1-jre</guava.version>

But obviously, the problem will pop in again if that cache gets wiped.

avently commented 6 years ago

I did:

<ec.version>7.1.1</ec.version>
<guava.version>19.0</guava.version>

It helped. Thank you! I'll try to find another way to improve Kobalt's code. Maybe it is possible to tell to Maven resolver to exclude some versions from range. But for now your solution is good

cbeust commented 6 years ago

Maven Resolver (the library that Kobalt uses) is pretty flexible from my experience, you can set up all kinds of customizations for resolutions, filters, etc...

I wouldn't be surprised if it's possible to install an interceptor that would replace such range versions with a hardcoded one or something like that.

avently commented 6 years ago

Will you accept PR for that issue if I'll find something usefull?

cbeust commented 6 years ago

Maybe :-)

I'm not sure how much of a universal feature this can be turned into and how you'd specify this kind of thing in a build file. You are subverting the way Maven Resolver works because of your slow build (which is suspicious, by the way, downloading these XML files shouldn't take that long)

But if you do some research on how this could be achieved, feel free to share your findings, at least verbally. It's always useful to learn more about Maven Resolver.

avently commented 6 years ago

The solution here is to add after this line: https://github.com/cbeust/kobalt/blob/master/modules/kobalt-plugin-api/src/main/kotlin/com/beust/kobalt/maven/aether/Booter.kt#L36

this code:

session.isOffline = true

And there are no external downloads now. Trying to figure out how to send --offline option which will replace true value like this:

session.isOffline = args.offline

avently commented 6 years ago

I made PR #478 Please, don't forget to upload on Github your commits related to 1.0.113 release. You fixed red warning that was shown when Kobalt couldn't parse version string

cbeust / kobalt

Multiple downloads of the same libs in every build #477