google / java-photoslibrary

Java client library for the Google Photos Library API
http://developers.google.com/photos
Apache License 2.0
107 stars 64 forks source link

When deprecated UploadMediaItemRequest.fileName is omitted, Google responds with HTTP 500 #42

Closed ylexus closed 3 years ago

ylexus commented 3 years ago

uploadMediaItem fails if the deprecated UploadMediaItemRequest.fileName is omitted. Workaround is to supply some value there, and then also specify the file name in NewMediaItem too - that last one is then used, and UploadMediaItemRequest.fileName is ignored.

Here's the DEBUG level request and response:

2021-01-23T22:27:10,742 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "POST /v1/uploads HTTP/1.1[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "Authorization: Bearer <censored>[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "X-Goog-Upload-Protocol: resumable[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "X-Goog-Upload-Command: start[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "X-Goog-Upload-Raw-Size: 29416[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "Content-Length: 0[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "Host: photoslibrary.googleapis.com[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.12 (Java/14.0.2)[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
2021-01-23T22:27:10,743 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 >> "[\r][\n]"
2021-01-23T22:27:10,796 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "HTTP/1.1 500 Internal Server Error[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "X-GUploader-UploadID: <censored>[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "X-Goog-Upload-Status: final[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "Content-Length: 60[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "Date: Sat, 23 Jan 2021 22:27:11 GMT[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "Server: UploadServer[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "Alt-Svc: h3-29=":443"; ma=2592000,h3-T051=":443"; ma=2592000,h3-Q050=":443"; ma=2592000,h3-Q046=":443"; ma=2592000,h3-Q043=":443"; ma=2592000,quic=":443"; ma=2592000; v="46,43"[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "[\r][\n]"
2021-01-23T22:27:10,797 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "{[\n]"
2021-01-23T22:27:10,798 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "  "code": 13,[\n]"
2021-01-23T22:27:10,798 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "  "message": "Internal error encountered."[\n]"
2021-01-23T22:27:10,798 DEBUG [Gax-2] o.a.h.i.c.Wire http-outgoing-0 << "}"
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << HTTP/1.1 500 Internal Server Error
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << X-GUploader-UploadID: ABg5-UyfTegj2uYUwTskwNDFqj_-Mh8BV2OC7mUEZ0xjGUGdUaDB1fLw3BFv2WvxAszzsWjus70BG5D0SJctaWkyOdk
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << X-Goog-Upload-Status: final
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << Content-Length: 60
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << Date: Sat, 23 Jan 2021 22:27:11 GMT
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << Server: UploadServer
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << Content-Type: text/html; charset=UTF-8
2021-01-23T22:27:10,800 DEBUG [Gax-2] o.a.h.i.c.LoggingManagedHttpClientConnection http-outgoing-0 << Alt-Svc: h3-29=":443"; ma=2592000,h3-T051=":443"; ma=2592000,h3-Q050=":443"; ma=2592000,h3-Q046=":443"; ma=2592000,h3-Q043=":443"; ma=2592000,quic=":443"; ma=2592000; v="46,43"
jfschmakeit commented 3 years ago

I haven't been able to reproduce this. Calling only setFileName on a NewMediaItem and omitting the file name from the UploadMediaItemRequest seems to work as expected. (Per the documentation and the sample app.)

Could you post a code snippets that shows the calls to the API and the construction of the relevant request objects?

Thanks!

ylexus commented 3 years ago

The code is in https://github.com/ylexus/jiotty/blob/master/jiotty-connector-google/jiotty-connector-google-photos/src/main/java/net/yudichev/jiotty/connector/google/photos/GooglePhotosClientImpl.java, methods uploadMediaData and createMediaItems. Particularly, line 62. If you need a reproducible scenario, then

  1. ensure JAVA_HOME points to jdk 14.
  2. clone https://github.com/ylexus/jiotty
  3. in jiotty, execute mvn clean install
  4. clone https://github.com/ylexus/jiotty-photos-uploader
  5. change jiotty-photos-uploader/buld.gradle, replace version in ext.netYudichevJiottyVersion to the one in jiotty/pom.xml
  6. in jiotty-photos-uploader, execute ./gradlew run
  7. when the app starts, login to the google account, select some folder with photos and click start
  8. it will error, the error will be in ~/.jiottyphotosuploader/logs/main.log
ylexus commented 3 years ago

Just tried and it' still perfectly reproducible. In jiotty photos uploader above, the full stack trace looks like this:

2021-02-10T20:03:47,288 ERROR [JavaFX Application Thread] n.y.g.u.UploadPaneControllerImpl Upload failed
java.util.concurrent.CompletionException: java.lang.RuntimeException: java.util.concurrent.CompletionException: java.lang.RuntimeException: Failed uploading /Users/alexey/Library/Mobile Documents/com~apple~CloudDocs/jiotty-test-roots/order-test/album-name/DSC00126.JPG
    at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314) ~[?:?]
    at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319) ~[?:?]
    at java.util.concurrent.CompletableFuture$UniComposeExceptionally.tryFire(CompletableFuture.java:1045) ~[?:?]
    at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1769) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[?:?]
    at java.lang.Thread.run(Thread.java:832) ~[?:?]
Caused by: java.lang.RuntimeException: java.util.concurrent.CompletionException: java.lang.RuntimeException: Failed uploading /Users/alexey/Library/Mobile Documents/com~apple~CloudDocs/jiotty-test-roots/order-test/album-name/DSC00126.JPG
    at net.yudichev.googlephotosupload.core.GooglePhotosUploaderImpl.lambda$createMediaData$28(GooglePhotosUploaderImpl.java:263) ~[main/:?]
    at java.util.Optional.orElseGet(Optional.java:362) ~[?:?]
    at net.yudichev.googlephotosupload.core.GooglePhotosUploaderImpl.lambda$createMediaData$29(GooglePhotosUploaderImpl.java:258) ~[main/:?]
    at java.util.concurrent.CompletableFuture$UniComposeExceptionally.tryFire(CompletableFuture.java:1036) ~[?:?]
    ... 5 more
Caused by: java.util.concurrent.CompletionException: java.lang.RuntimeException: Failed uploading /Users/alexey/Library/Mobile Documents/com~apple~CloudDocs/jiotty-test-roots/order-test/album-name/DSC00126.JPG
    at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314) ~[?:?]
    at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319) ~[?:?]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1766) ~[?:?]
    ... 3 more
Caused by: java.lang.RuntimeException: Failed uploading /Users/alexey/Library/Mobile Documents/com~apple~CloudDocs/jiotty-test-roots/order-test/album-name/DSC00126.JPG
    at net.yudichev.jiotty.connector.google.photos.GooglePhotosClientImpl.lambda$null$1(GooglePhotosClientImpl.java:67) ~[jiotty-connector-google-photos-1.6.3-SNAPSHOT.jar:?]
    at java.util.Optional.ifPresent(Optional.java:176) ~[?:?]
    at net.yudichev.jiotty.connector.google.photos.GooglePhotosClientImpl.lambda$null$2(GooglePhotosClientImpl.java:67) ~[jiotty-connector-google-photos-1.6.3-SNAPSHOT.jar:?]
    at net.yudichev.jiotty.common.inject.BaseLifecycleComponent.lambda$whenStartedAndNotLifecycling$5(BaseLifecycleComponent.java:60) ~[jiotty-common-1.6.3-SNAPSHOT.jar:?]
    at net.yudichev.jiotty.common.lang.Locks.inLock(Locks.java:22) ~[jiotty-common-1.6.3-SNAPSHOT.jar:?]
    at net.yudichev.jiotty.common.inject.BaseLifecycleComponent.whenNotLifecycling(BaseLifecycleComponent.java:54) ~[jiotty-common-1.6.3-SNAPSHOT.jar:?]
    at net.yudichev.jiotty.common.inject.BaseLifecycleComponent.whenStartedAndNotLifecycling(BaseLifecycleComponent.java:58) ~[jiotty-common-1.6.3-SNAPSHOT.jar:?]
    at net.yudichev.jiotty.connector.google.photos.GooglePhotosClientImpl.lambda$uploadMediaData$3(GooglePhotosClientImpl.java:56) ~[jiotty-connector-google-photos-1.6.3-SNAPSHOT.jar:?]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1764) ~[?:?]
    ... 3 more
Caused by: com.google.api.gax.rpc.ApiException: java.lang.IllegalArgumentException: The upload url is either finalized or rejected by the server.
    at com.google.photos.library.v1.upload.PhotosLibraryUploadExceptionMappingFn.apply(PhotosLibraryUploadExceptionMappingFn.java:48) ~[google-photos-library-client-1.5.0.jar:1.5.0]
    at com.google.photos.library.v1.upload.PhotosLibraryUploadExceptionMappingFn.apply(PhotosLibraryUploadExceptionMappingFn.java:29) ~[google-photos-library-client-1.5.0.jar:1.5.0]
    at com.google.api.core.ApiFutures$GaxFunctionToGuavaFunction.apply(ApiFutures.java:204) ~[api-common-1.8.1.jar:?]
    at com.google.common.util.concurrent.AbstractCatchingFuture$CatchingFuture.doFallback(AbstractCatchingFuture.java:223) ~[guava-29.0-jre.jar:?]
    at com.google.common.util.concurrent.AbstractCatchingFuture$CatchingFuture.doFallback(AbstractCatchingFuture.java:211) ~[guava-29.0-jre.jar:?]
    at com.google.common.util.concurrent.AbstractCatchingFuture.run(AbstractCatchingFuture.java:124) ~[guava-29.0-jre.jar:?]
    at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30) ~[guava-29.0-jre.jar:?]
    at com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:141) ~[guava-29.0-jre.jar:?]
    at com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:130) ~[guava-29.0-jre.jar:?]
    at com.google.common.util.concurrent.ListenableFutureTask.done(ListenableFutureTask.java:86) ~[guava-29.0-jre.jar:?]
    at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:381) ~[?:?]
    at java.util.concurrent.FutureTask.setException(FutureTask.java:250) ~[?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:269) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
    ... 3 more
Caused by: java.lang.IllegalArgumentException: The upload url is either finalized or rejected by the server.
    at com.google.photos.library.v1.upload.PhotosLibraryUploadCallable.getUploadUrl(PhotosLibraryUploadCallable.java:232) ~[google-photos-library-client-1.5.0.jar:1.5.0]
    at com.google.photos.library.v1.upload.PhotosLibraryUploadCallable.call(PhotosLibraryUploadCallable.java:110) ~[google-photos-library-client-1.5.0.jar:1.5.0]
    at com.google.photos.library.v1.upload.PhotosLibraryUploadCallable.call(PhotosLibraryUploadCallable.java:45) ~[google-photos-library-client-1.5.0.jar:1.5.0]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
    ... 3 more
jfschmakeit commented 3 years ago

The issue is that you are not supplying a mime type in your UploadMediaItemRequest. You need to call .setMimeType(..) with the mime type of the file you are uploading. When this property is set, you do not need to include the deprecated filename property for the upload call to work.

(I have confirmed that I'm getting the same error when making an upload call without setting the mime type.)

I'm closing this issue for now, but please reopen if you are still seeing this even after setting the mime type on your upload request.

ylexus commented 3 years ago

@jfschmakeit according to https://developers.google.com/photos/library/guides/upload-media#uploading-bytes, "X-Goog-Upload-Content-Type" is recommended, but not mandatory.

Apparently, in practice either "X-Goog-Upload-Content-Type" or "X-Goog-Upload-File-Name" is required. Sounds like an undocumented feature, or is indeed a bug on the Google server side. Anything we can do to let them know?