Skip to content

Upload failure using --experimental_remote_cache_async and flaky test retries #14008

@brentleyjones

Description

@brentleyjones

Description of the problem / feature request:

When using the new --experimental_remote_cache_async flag, we get upload failures that don't happen without the flag. It seems to be related to how the test log for flaky tests are generated.

Bugs: what's the simplest, easiest way to reproduce this bug? Please provide a minimal example if possible.

(07:53:16) FAIL: //Modules/CanvasUI:CanvasUITests (see /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test_attempts/attempt_1.log)
(07:53:16) WARNING: Writing to Remote Cache: /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test.xml (No such file or directory)
  | com.google.devtools.build.lib.remote.common.BulkTransferException: /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test.xml (No such file or directory)
  | at com.google.devtools.build.lib.remote.util.RxUtils$BulkTransferExceptionCollector.onResult(RxUtils.java:91)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableCollectSingle$CollectSubscriber.onNext(FlowableCollectSingle.java:93)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableFlatMapSingle$FlatMapSingleSubscriber.innerSuccess(FlowableFlatMapSingle.java:173)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableFlatMapSingle$FlatMapSingleSubscriber$InnerObserver.onSuccess(FlowableFlatMapSingle.java:342)
  | at io.reactivex.rxjava3.internal.observers.ResumeSingleObserver.onSuccess(ResumeSingleObserver.java:46)
  | at io.reactivex.rxjava3.internal.operators.single.SingleJust.subscribeActual(SingleJust.java:30)
  | at io.reactivex.rxjava3.core.Single.subscribe(Single.java:4813)
  | at io.reactivex.rxjava3.internal.operators.single.SingleResumeNext$ResumeMainSingleObserver.onError(SingleResumeNext.java:80)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableToSingle$ToSingle.onError(CompletableToSingle.java:73)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableCreate$Emitter.tryOnError(CompletableCreate.java:91)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableCreate$Emitter.onError(CompletableCreate.java:77)
  | at com.google.devtools.build.lib.remote.util.RxFutures$OnceCompletableOnSubscribe$1.onFailure(RxFutures.java:102)
  | at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1074)
  | at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
  | at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1213)
  | at com.google.common.util.concurrent.AbstractFuture.addListener(AbstractFuture.java:724)
  | at com.google.common.util.concurrent.Futures.addCallback(Futures.java:1047)
  | at com.google.devtools.build.lib.remote.util.RxFutures$OnceCompletableOnSubscribe.subscribe(RxFutures.java:80)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableCreate.subscribeActual(CompletableCreate.java:40)
  | at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2856)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableToSingle.subscribeActual(CompletableToSingle.java:37)
  | at io.reactivex.rxjava3.core.Single.subscribe(Single.java:4813)
  | at io.reactivex.rxjava3.internal.operators.single.SingleResumeNext.subscribeActual(SingleResumeNext.java:39)
  | at io.reactivex.rxjava3.core.Single.subscribe(Single.java:4813)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableFlatMapSingle$FlatMapSingleSubscriber.onNext(FlowableFlatMapSingle.java:131)
  | at io.reactivex.rxjava3.internal.operators.single.SingleFlatMapPublisher$SingleFlatMapPublisherObserver.onNext(SingleFlatMapPublisher.java:107)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableFromIterable$IteratorSubscription.fastPath(FlowableFromIterable.java:185)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableFromIterable$BaseRangeSubscription.request(FlowableFromIterable.java:129)
  | at io.reactivex.rxjava3.internal.subscriptions.SubscriptionHelper.deferredSetOnce(SubscriptionHelper.java:202)
  | at io.reactivex.rxjava3.internal.operators.single.SingleFlatMapPublisher$SingleFlatMapPublisherObserver.onSubscribe(SingleFlatMapPublisher.java:102)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableFromIterable.subscribe(FlowableFromIterable.java:69)
  | at io.reactivex.rxjava3.internal.operators.flowable.FlowableFromIterable.subscribeActual(FlowableFromIterable.java:47)
  | at io.reactivex.rxjava3.core.Flowable.subscribe(Flowable.java:15838)
  | at io.reactivex.rxjava3.core.Flowable.subscribe(Flowable.java:15784)
  | at io.reactivex.rxjava3.internal.operators.single.SingleFlatMapPublisher$SingleFlatMapPublisherObserver.onSuccess(SingleFlatMapPublisher.java:96)
  | at io.reactivex.rxjava3.internal.operators.single.SingleCreate$Emitter.onSuccess(SingleCreate.java:68)
  | at com.google.devtools.build.lib.remote.util.RxFutures$OnceSingleOnSubscribe$1.onSuccess(RxFutures.java:156)
  | at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1080)
  | at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
  | at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1213)
  | at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:983)
  | at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:746)
  | at com.google.common.util.concurrent.AbstractCatchingFuture.run(AbstractCatchingFuture.java:110)
  | at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
  | at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1213)
  | at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:983)
  | at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:746)
  | at com.google.common.util.concurrent.CombinedFuture$CallableInterruptibleTask.setValue(CombinedFuture.java:188)
  | at com.google.common.util.concurrent.CombinedFuture$CombinedFutureInterruptibleTask.afterRanInterruptibly(CombinedFuture.java:134)
  | at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:133)
  | at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
  | at com.google.common.util.concurrent.CombinedFuture$CombinedFutureInterruptibleTask.execute(CombinedFuture.java:104)
  | at com.google.common.util.concurrent.CombinedFuture.handleAllCompleted(CombinedFuture.java:62)
  | at com.google.common.util.concurrent.AggregateFuture.processCompleted(AggregateFuture.java:283)
  | at com.google.common.util.concurrent.AggregateFuture.decrementCountAndMaybeComplete(AggregateFuture.java:265)
  | at com.google.common.util.concurrent.AggregateFuture.access$200(AggregateFuture.java:42)
  | at com.google.common.util.concurrent.AggregateFuture$1.run(AggregateFuture.java:147)
  | at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
  | at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1213)
  | at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:983)
  | at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:746)
  | at com.google.common.util.concurrent.AbstractCatchingFuture.run(AbstractCatchingFuture.java:110)
  | at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
  | at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1213)
  | at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:983)
  | at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:746)
  | at com.google.common.util.concurrent.AbstractCatchingFuture.run(AbstractCatchingFuture.java:110)
  | at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
  | at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1213)
  | at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:983)
  | at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:746)
  | at io.grpc.stub.ClientCalls$GrpcFuture.set(ClientCalls.java:558)
  | at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose(ClientCalls.java:531)
  | at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
  | at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
  | at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
  | at com.google.devtools.build.lib.remote.NetworkTimeInterceptor$NetworkTimeCall$1.onClose(NetworkTimeInterceptor.java:81)
  | at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
  | at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
  | at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
  | at com.google.devtools.build.lib.remote.ReferenceCountedChannel$ConnectionCleanupCall$1.onClose(ReferenceCountedChannel.java:90)
  | at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
  | at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
  | at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
  | at com.google.devtools.build.lib.remote.logging.LoggingInterceptor$LoggingForwardingCall$1.onClose(LoggingInterceptor.java:157)
  | at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:617)
  | at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70)
  | at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:803)
  | at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:782)
  | at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
  | at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
  | at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
  | at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
  | at java.base/java.lang.Thread.run(Unknown Source)
  | Suppressed: java.io.FileNotFoundException: /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test.xml (No such file or directory)
  | at java.base/java.io.FileInputStream.open0(Native Method)
  | at java.base/java.io.FileInputStream.open(Unknown Source)
  | at java.base/java.io.FileInputStream.<init>(Unknown Source)
  | at com.google.devtools.build.lib.unix.UnixFileSystem.createFileInputStream(UnixFileSystem.java:470)
  | at com.google.devtools.build.lib.vfs.AbstractFileSystem.createMaybeProfiledInputStream(AbstractFileSystem.java:82)
  | at com.google.devtools.build.lib.vfs.AbstractFileSystem.getInputStream(AbstractFileSystem.java:51)
  | at com.google.devtools.build.lib.vfs.Path.getInputStream(Path.java:779)
  | at com.google.devtools.build.lib.remote.Chunker$Builder.lambda$setInput$2(Chunker.java:268)
  | at com.google.devtools.build.lib.remote.Chunker.maybeInitialize(Chunker.java:229)
  | at com.google.devtools.build.lib.remote.Chunker.seek(Chunker.java:148)
  | at com.google.devtools.build.lib.remote.ByteStreamUploader$AsyncUpload.call(ByteStreamUploader.java:511)
  | at com.google.devtools.build.lib.remote.ByteStreamUploader$AsyncUpload.callAndQueryOnFailure(ByteStreamUploader.java:433)
  | at com.google.devtools.build.lib.remote.ByteStreamUploader$AsyncUpload.lambda$start$0(ByteStreamUploader.java:399)
  | at com.google.devtools.build.lib.remote.Retrier.executeAsync(Retrier.java:277)
  | at com.google.devtools.build.lib.remote.ByteStreamUploader$AsyncUpload.lambda$start$1(ByteStreamUploader.java:396)
  | at com.google.devtools.build.lib.remote.util.Utils.refreshIfUnauthenticatedAsync(Utils.java:462)
  | at com.google.devtools.build.lib.remote.ByteStreamUploader$AsyncUpload.start(ByteStreamUploader.java:394)
  | at com.google.devtools.build.lib.remote.ByteStreamUploader.startAsyncUpload(ByteStreamUploader.java:328)
  | at com.google.devtools.build.lib.remote.ByteStreamUploader.uploadBlobAsync(ByteStreamUploader.java:249)
  | at com.google.devtools.build.lib.remote.GrpcCacheClient.uploadFile(GrpcCacheClient.java:402)
  | at com.google.devtools.build.lib.remote.RemoteCache.lambda$doUploadFile$5(RemoteCache.java:174)
  | at com.google.devtools.build.lib.remote.util.RxFutures$OnceCompletableOnSubscribe.subscribe(RxFutures.java:79)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableCreate.subscribeActual(CompletableCreate.java:40)
  | at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2856)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableUsing.subscribeActual(CompletableUsing.java:83)
  | at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2856)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableToSingle.subscribeActual(CompletableToSingle.java:37)
  | at io.reactivex.rxjava3.core.Single.subscribe(Single.java:4813)
  | at com.google.devtools.build.lib.remote.util.AsyncTaskCache$Execution.subscribeActual(AsyncTaskCache.java:156)
  | at io.reactivex.rxjava3.core.Single.subscribe(Single.java:4813)
  | at com.google.devtools.build.lib.remote.util.AsyncTaskCache.lambda$execute$1(AsyncTaskCache.java:291)
  | at io.reactivex.rxjava3.internal.operators.single.SingleCreate.subscribeActual(SingleCreate.java:40)
  | at io.reactivex.rxjava3.core.Single.subscribe(Single.java:4813)
  | at io.reactivex.rxjava3.internal.operators.completable.CompletableFromSingle.subscribeActual(CompletableFromSingle.java:29)
  | at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2856)
  | at com.google.devtools.build.lib.remote.util.RxFutures.toListenableFuture(RxFutures.java:196)
  | at com.google.devtools.build.lib.remote.RemoteCache.uploadFile(RemoteCache.java:196)
  | at com.google.devtools.build.lib.remote.UploadManifest.lambda$upload$0(UploadManifest.java:358)
  | at com.google.devtools.build.lib.remote.util.RxFutures$OnceCompletableOnSubscribe.subscribe(RxFutures.java:79)
  | ... 76 more
(07:54:20) WARNING: /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test.log was modified during execution
(07:54:20) FAIL: //Modules/CanvasUI:CanvasUITests (see /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test_attempts/attempt_2.log)
(07:55:03) FAIL: //Modules/CanvasUI:CanvasUITests (see /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test.log)
--
  |  
  | FAILED: //Modules/CanvasUI:CanvasUITests (Summary)
  | /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test.log
  | /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test_attempts/attempt_1.log
  | /private/var/tmp/_bazel_iosci/4e42b9deccb34ad74b7f834bbab2cb1e/execroot/project/bazel-out/darwin-fastbuild/testlogs/Modules/CanvasUI/CanvasUITests/test_attempts/attempt_2.log

What operating system are you running Bazel on?

macOS 11.6

What's the output of bazel info release?

release 5.0.0-pre.20210907.1

Metadata

Metadata

Assignees

Labels

P1I'll work on this now. (Assignee required)team-Remote-ExecIssues and PRs for the Execution (Remote) teamtype: bug

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions