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
Description of the problem / feature request:
When using the new
--experimental_remote_cache_asyncflag, 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.
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