search

abdolence / sbt-gcs-resolver

SBT plugin for Google Cloud Storage (GCS) and Google Artifact Registry with Coursier support
Apache License 2.0
28 stars 7 forks source link

unable to upload jar to GCP Artifact Registry due to IOException #43

Closed i10416 closed 1 year ago

i10416 commented 1 year ago

Solved: I was so stupid that I overlooked my mistake.

https://github.com/abdolence/sbt-gcs-resolver/issues/43#issuecomment-1505547355

I ran into error when I tried to upload package to GCP Artifact Registry. As I mention later, however, manually uploading jar works. So, I guess UrlConnection and/or UrlHandler are/is the culprit

Perhaps, we need connection.setFixedLengthStreamingMode(size) to send a larger file

environment and full stacktrace

[error] java.io.IOException: Error writing request body to server
[error]         at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(HttpURLConnection.java:3820)
[error]         at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(HttpURLConnection.java:3802)
[error]         at java.base/java.io.InputStream.transferTo(InputStream.java:783)
[error]         at java.base/java.nio.file.Files.copy(Files.java:3213)
[error]         at org.latestbit.sbt.gcs.artifactregistry.GcsArtifactRegistryIvyUrlHandler$$anon$1.writeTo(GcsArtifactRegistryIvyUrlHandler.scala:93)
[error]         at com.google.api.client.http.javanet.NetHttpRequest$DefaultOutputWriter.write(NetHttpRequest.java:76)
[error]         at com.google.api.client.http.javanet.NetHttpRequest.writeContentToOutputStream(NetHttpRequest.java:174)
[error]         at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:117)
[error]         at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:84)
[error]         at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
[error]         at org.latestbit.sbt.gcs.artifactregistry.GcsArtifactRegistryIvyUrlHandler.upload(GcsArtifactRegistryIvyUrlHandler.scala:98)
[error]         at org.apache.ivy.util.url.URLHandlerDispatcher.upload(URLHandlerDispatcher.java:82)
[error]         at org.apache.ivy.util.FileUtil.copy(FileUtil.java:150)
[error]         at org.apache.ivy.plugins.repository.url.URLRepository.put(URLRepository.java:84)
[error]         at sbt.internal.librarymanagement.ConvertResolver$LocalIfFileRepo.put(ConvertResolver.scala:368)
[error]         at org.apache.ivy.plugins.repository.AbstractRepository.put(AbstractRepository.java:130)
[error]         at sbt.internal.librarymanagement.ConvertResolver$ChecksumFriendlyURLResolver.put(ConvertResolver.scala:118)
[error]         at sbt.internal.librarymanagement.ConvertResolver$ChecksumFriendlyURLResolver.put$(ConvertResolver.scala:105)
[error]         at sbt.internal.librarymanagement.ConvertResolver$$anonfun$defaultConvert$lzycompute$1$PluginCapableResolver$1.put(ConvertResolver.scala:165)
[error]         at org.apache.ivy.plugins.resolver.RepositoryResolver.publish(RepositoryResolver.java:216)
[error]         at sbt.internal.librarymanagement.IvyActions$.$anonfun$publish$5(IvyActions.scala:504)
[error]         at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
[error]         at scala.util.Try$.apply(Try.scala:213)
[error]         at sbt.internal.librarymanagement.IvyUtil$.retryWithBackoff(IvyUtil.scala:22)
[error]         at sbt.internal.librarymanagement.IvyActions$.$anonfun$publish$4(IvyActions.scala:503)
[error]         at sbt.internal.librarymanagement.IvyActions$.$anonfun$publish$4$adapted(IvyActions.scala:501)
[error]         at scala.collection.Iterator.foreach(Iterator.scala:943)
[error]         at scala.collection.Iterator.foreach$(Iterator.scala:943)
[error]         at scala.collection.AbstractIterator.foreach(Iterator.scala:1431)
[error]         at scala.collection.IterableLike.foreach(IterableLike.scala:74)
[error]         at scala.collection.IterableLike.foreach$(IterableLike.scala:73)
[error]         at scala.collection.AbstractIterable.foreach(Iterable.scala:56)
[error]         at sbt.internal.librarymanagement.IvyActions$.publish(IvyActions.scala:501)
[error]         at sbt.internal.librarymanagement.IvyActions$.$anonfun$publish$3(IvyActions.scala:143)
[error]         at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
[error]         at sbt.internal.librarymanagement.IvyActions$.withChecksums(IvyActions.scala:157)
[error]         at sbt.internal.librarymanagement.IvyActions$.withChecksums(IvyActions.scala:150)
[error]         at sbt.internal.librarymanagement.IvyActions$.$anonfun$publish$1(IvyActions.scala:143)
[error]         at sbt.internal.librarymanagement.IvyActions$.$anonfun$publish$1$adapted(IvyActions.scala:133)
[error]         at sbt.internal.librarymanagement.IvySbt$Module.$anonfun$withModule$1(Ivy.scala:245)
[error]         at sbt.internal.librarymanagement.IvySbt.$anonfun$withIvy$1(Ivy.scala:209)
[error]         at sbt.internal.librarymanagement.IvySbt.sbt$internal$librarymanagement$IvySbt$$action$1(Ivy.scala:72)
[error]         at sbt.internal.librarymanagement.IvySbt$$anon$1.call(Ivy.scala:82)
[error]         at xsbt.boot.Locks$GlobalLock.withChannel$1(Locks.scala:113)
[error]         at xsbt.boot.Locks$GlobalLock.withChannelRetries$1(Locks.scala:91)
[error]         at xsbt.boot.Locks$GlobalLock.$anonfun$withFileLock$1(Locks.scala:119)
[error]         at xsbt.boot.Using$.withResource(Using.scala:12)
[error]         at xsbt.boot.Using$.apply(Using.scala:9)
[error]         at xsbt.boot.Locks$GlobalLock.withFileLock(Locks.scala:119)
[error]         at xsbt.boot.Locks$GlobalLock.ignoringDeadlockAvoided(Locks.scala:71)
[error]         at xsbt.boot.Locks$GlobalLock.withLock(Locks.scala:59)
[error]         at xsbt.boot.Locks$.apply0(Locks.scala:47)
[error]         at xsbt.boot.Locks$.apply(Locks.scala:36)
[error]         at sbt.internal.librarymanagement.IvySbt.withDefaultLogger(Ivy.scala:82)
[error]         at sbt.internal.librarymanagement.IvySbt.withIvy(Ivy.scala:203)
[error]         at sbt.internal.librarymanagement.IvySbt.withIvy(Ivy.scala:200)
[error]         at sbt.internal.librarymanagement.IvySbt$Module.withModule(Ivy.scala:244)
[error]         at sbt.internal.librarymanagement.IvyActions$.publish(IvyActions.scala:133)
[error]         at sbt.Classpaths$.$anonfun$publishTask$4(Defaults.scala:3553)
[error]         at sbt.Classpaths$.$anonfun$publishTask$4$adapted(Defaults.scala:3546)
[error]         at scala.Function1.$anonfun$compose$1(Function1.scala:49)
[error]         at sbt.internal.util.$tilde$greater.$anonfun$$u2219$1(TypeFunctions.scala:62)
[error]         at sbt.std.Transform$$anon$4.work(Transform.scala:68)
[error]         at sbt.Execute.$anonfun$submit$2(Execute.scala:282)
[error]         at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:23)
[error]         at sbt.Execute.work(Execute.scala:291)
[error]         at sbt.Execute.$anonfun$submit$1(Execute.scala:282)
[error]         at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:265)
[error]         at sbt.CompletionService$$anon$2.call(CompletionService.scala:64)
[error]         at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[error]         at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
[error]         at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[error]         at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
[error]         at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[error]         at java.base/java.lang.Thread.run(Thread.java:833)

NOTE: To my surprise, uploading jar by hand works

Strangely, I can manually upload jar to ArtifactRegistry by the following code.

//> using lib "com.lihaoyi::requests:0.8.0"
def run = 
    val cred = "Bearer ******************"
    val v = "0.0.0-SNAPSHOT"
    val region = "asia-northeast1"
    val project: String = ???
    val reponame: String = ??? 
    val baseurl = s"https://$region-maven.pkg.dev/$project//$reponame/com/example/packagename_2.12/$v/packagename_2.12-$v."
    val localfilename =  s"/path/to/packagename/target/scala-2.12/packagename_2.12-$v."
    val h = Map("Authorization"->cred)
    val jarurl = baseurl + "jar"
    val jarsrc = new java.io.File(localfilename + "jar")
    val (url,file) = req
    // uploading without multipart also works
    val res = requests.put(
        jarurl,
        data = requests.MultiPart(
        requests.MultiItem("file", jarsrc, jarsrc.getName())
        ),
        headers = h,
    )
    println(res)

I suspected we should use multipart request instead of HttpContent in GcsArtifactRegistryIvyUrlHandler to transfer a large file, but I was wrong.

It turned out that uploading without multipart also works.

 val res = requests.put(
    jarurl,
    data = jarsrc,
    headers = h,
)

There is another strange behavior, which may or may not be relevant to this error. The size of my jar before upload is 575928, but it increases to 576106 after multipart upload and download while the size of my pom does not change after downloading uploaded one.

val (url,_) = req
val res = requests.get(
    url,
    headers = h,
    autoDecompress=false
)
println(res.contents.size)
i10416 commented 1 year ago

I suspect openConnection for ArtifactRegistry is handled by default URLStreamHandler instead of GcsArtifactRegistryUrlHandler as URLStreamHandler doc says

abstract class URLStreamHandler: URLStreamHandler The abstract class URLStreamHandler is the common superclass for all stream protocol handlers. A stream protocol handler knows how to make a connection for a particular protocol type, such as http or https.

In most cases, an instance of a URLStreamHandler subclass is not created directly by an application. Rather, the first time a protocol name is encountered when constructing a URL, the appropriate stream protocol handler is automatically loaded

So, it would be possible that GcsArtifactRegistryUrlConnection does not work properly.

abdolence commented 1 year ago

Hm, this is interesting. So I assume this happens only for relatively big files? Let me test it in my env first.

i10416 commented 1 year ago

I was able to load GcsArtifactRegistryUrlHandler properly by the following change, thus GcsArtifactRegistryUrlConnection#getOutputStream is properly called. It seems that registered custom Url handler is loaded when it tries to open connection for "artifact-registry://" protocol.

I think it was too early to convert "artifact-registry://" to "https://" in current codebase.

 override def upload( src: File, dest: URL, l: CopyProgressListener ): Unit = {
    logger.info(
      s"Publishing artifact to '${dest}'..."
    )
    val event = new CopyProgressEvent()
    Option( l ).foreach( _.start( event ) )
-    val genericUrl  = GcsArtifactRegistryGenericUrlFactory.createFromUrl( dest )
    val contentType = getContentType( dest )
    val httpRequest = googleHttpRequestFactory.buildPutRequest(
-     genericUrl, 
+     new GenericUrl(dest),
      new HttpContent() {
        override def getLength: Long           = src.length()
        override def getType: String           = contentType
        override def retrySupported(): Boolean = true

        override def writeTo( out: OutputStream ): Unit = {
          println(s"[DEBUG] start transfering data from ${src} to ${out}")
          Files.copy( src.toPath, out )
          out.close()
        }
      }
    )
abdolence commented 1 year ago

This change is not clear why would help you, since GenericUrl is just dumb data class without side effects. Probably there is some race condition issue, and it just changes timing for you and there is still a problem if it exists.

abdolence commented 1 year ago

Ah, you didn't just change the order, but also the URL still pointing to previous scheme. 🤔

abdolence commented 1 year ago

I suspect openConnection for ArtifactRegistry is handled by default URLStreamHandler instead of GcsArtifactRegistryUrlHandler

This was actually even designed like that: GcsArtifactRegistryIvyUrlHandler didn't have to use GcsArtifactRegistryUrlConnection anymore since it also uses googleHttpRequestFactory and common HTTPS is enough.

abdolence commented 1 year ago

Please clarify a bit more your case:

i10416 commented 1 year ago

Does it happen all the time (100% reproducible?)

"java.io.IOException: Error writing request body to server" always happen when I run publish command.

Does it happen regardless of the file sizes?

I'm not sure it depends on file sizes. Sorry.

At first, I suspected that changing HttpConnection settings like setFixedLengthStreamingMode would solve the issue, but in vain.

abdolence commented 1 year ago 
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.pom'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.pom.sha1'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.pom.md5'...
[info]  published sbt-gcs-plugin-playground-artifact-publish_2.12 to artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.pom
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.jar'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.jar.sha1'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.jar.md5'...
[info]  published sbt-gcs-plugin-playground-artifact-publish_2.12 to artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT.jar
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-sources.jar'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-sources.jar.sha1'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-sources.jar.md5'...
[info]  published sbt-gcs-plugin-playground-artifact-publish_2.12 to artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-sources.jar
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-javadoc.jar'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-javadoc.jar.sha1'...
[info] Publishing artifact to 'artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-javadoc.jar.md5'...
[info]  published sbt-gcs-plugin-playground-artifact-publish_2.12 to artifactregistry://europe-north1-maven.pkg.dev/latestbit/latestbit-artifacts-snapshots/org/latestbit/sbt-gcs-plugin-playground-artifact-publish_2.12/0.0.12-SNAPSHOT/sbt-gcs-plugin-playground-artifact-publish_2.12-0.0.12-SNAPSHOT-javadoc.jar
[success] Total time: 28 s, completed 12 Apr 2023, 17:47:15

I just tested publishing 100Mb jar file for my test registry and it worked.

Can you reproduce this issue with:

abdolence commented 1 year ago

My environment:

java -version 
openjdk version "11.0.18" 2023-01-17 LTS
OpenJDK Runtime Environment Corretto-11.0.18.10.1 (build 11.0.18+10-LTS)
OpenJDK 64-Bit Server VM Corretto-11.0.18.10.1 (build 11.0.18+10-LTS, mixed mode)
sbt version in this project:    1.8.2
sbt script version: 1.8.2
abdolence commented 1 year ago

Also, I have multiple pipelines using this plugin, and they never failed. We have some differences that we need to find.

i10416 commented 1 year ago

Also, I have multiple pipelines using this plugin, and they never failed. We have some differences that we need to find.

On reading this, I looked again and I found I made a silly mistake 😰

So sorry, I found my artifact registry path was wrong, which resulted in "Error writing request body to server" 😅

This solves my issue.

-  "My Maven Artifact Registry" at "artifactregistry://asia-northeast1-maven.pkg.dev/<project>//<registry>"
+  "My Maven Artifact Registry" at "artifactregistry://asia-northeast1-maven.pkg.dev/<project>/<registry>"

Thanks for taking your time to identify error causes.

abdolence commented 1 year ago

On reading this, I looked again and I found I made a silly mistake cold_sweat

Great you found the problem. Probably I need to think about error handling to make it obvious when it fails with cryptic errors like this.

i10416 commented 1 year ago

Yeah, and I don't think GcsArtifactRegistryUrlConnection needs concrete implementation, does it?

https://github.com/abdolence/sbt-gcs-resolver/pull/44