See <https://builds.apache.org/job/beam_PostCommit_Python2/1034/display/redirect?page=changes>
Changes: [katarzyna.kucharczyk] [BEAM-6335] Added streaming GroupByKey Test that reads SyntheticSource [katarzyna.kucharczyk] [BEAM-6335] Changed SyntheticDataPublisher to publish String UTF values [katarzyna.kucharczyk] [BEAM-6335] Added custom PubSub Matcher that stops pipeline after ------------------------------------------ [...truncated 1.54 MB...] [flink-akka.actor.default-dispatcher-7] INFO org.apache.flink.runtime.executiongraph.ExecutionGraph - ref_AppliedPTransform_write/Write/WriteImpl/FinalizeWrite_43-side2 -> Map (1/2) (a48e4663cb97beced307079d73c9d836) switched from RUNNING to FINISHED. [flink-akka.actor.default-dispatcher-7] INFO org.apache.flink.runtime.executiongraph.ExecutionGraph - [1]write/Write/WriteImpl/FinalizeWrite (1/2) (48e34bcd1d4ab73cad4a5bd0deef3c09) switched from RUNNING to FINISHED. INFO:apache_beam.io.filebasedsink:Starting finalize_write threads with num_shards: 2 (skipped: 0), batches: 2, num_threads: 2 INFO:apache_beam.io.filebasedsink:Renamed 2 shards in 0.12 seconds. [[1]write/Write/WriteImpl/FinalizeWrite (2/2)] INFO org.apache.beam.runners.fnexecution.control.DefaultJobBundleFactory - Closing environment urn: "beam:env:external:v1" payload: "\n\021\022\017localhost:36175" INFO:apache_beam.runners.worker.sdk_worker:No more requests from control plane INFO:apache_beam.runners.worker.sdk_worker:SDK Harness waiting for in-flight requests to complete [[1]write/Write/WriteImpl/FinalizeWrite (2/2)] WARN org.apache.beam.sdk.fn.data.BeamFnDataGrpcMultiplexer - Hanged up for unknown endpoint. [[1]write/Write/WriteImpl/FinalizeWrite (2/2)] INFO org.apache.flink.runtime.taskmanager.Task - [1]write/Write/WriteImpl/FinalizeWrite (2/2) (33f8f0f9dc4111892f7e96d706391cd9) switched from RUNNING to FINISHED. [[1]write/Write/WriteImpl/FinalizeWrite (2/2)] INFO org.apache.flink.runtime.taskmanager.Task - Freeing task resources for [1]write/Write/WriteImpl/FinalizeWrite (2/2) (33f8f0f9dc4111892f7e96d706391cd9). [[1]write/Write/WriteImpl/FinalizeWrite (2/2)] INFO org.apache.flink.runtime.taskmanager.Task - Ensuring all FileSystem streams are closed for task [1]write/Write/WriteImpl/FinalizeWrite (2/2) (33f8f0f9dc4111892f7e96d706391cd9) [FINISHED] [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.TaskExecutor - Un-registering task and sending final execution state FINISHED to JobManager for task [1]write/Write/WriteImpl/FinalizeWrite 33f8f0f9dc4111892f7e96d706391cd9. [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.executiongraph.ExecutionGraph - [1]write/Write/WriteImpl/FinalizeWrite (2/2) (33f8f0f9dc4111892f7e96d706391cd9) switched from RUNNING to FINISHED. [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.executiongraph.ExecutionGraph - Job BeamApp-jenkins-1120164142-3180daea (d5f59023684109783722c5784a3d5e89) switched from state RUNNING to FINISHED. [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.checkpoint.CheckpointCoordinator - Stopping checkpoint coordinator for job d5f59023684109783722c5784a3d5e89. [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.checkpoint.StandaloneCompletedCheckpointStore - Shutting down ERROR:apache_beam.runners.worker.data_plane:Failed to read inputs in the data plane. Traceback (most recent call last): File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/data_plane.py";,> line 272, in _read_inputs for elements in elements_iterator: File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 395, in next return self._next() File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 561, in _next raise self _Rendezvous: <_Rendezvous of RPC that terminated with: status = StatusCode.CANCELLED details = "Multiplexer hanging up" debug_error_string = "{"created":"@1574268157.321946552","description":"Error received from peer ipv4:127.0.0.1:39125","file":"src/core/lib/surface/call.cc","file_line":1055,"grpc_message":"Multiplexer hanging up","grpc_status":1}" > Exception in thread read_grpc_client_inputs: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 754, in run self.__target(*self.__args, **self.__kwargs) File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/data_plane.py";,> line 286, in <lambda> target=lambda: self._read_inputs(elements_iterator), File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/data_plane.py";,> line 272, in _read_inputs for elements in elements_iterator: File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 395, in next return self._next() File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 561, in _next raise self _Rendezvous: <_Rendezvous of RPC that terminated with: status = StatusCode.CANCELLED details = "Multiplexer hanging up" debug_error_string = "{"created":"@1574268157.321946552","description":"Error received from peer ipv4:127.0.0.1:39125","file":"src/core/lib/surface/call.cc","file_line":1055,"grpc_message":"Multiplexer hanging up","grpc_status":1}" > INFO:apache_beam.runners.worker.data_plane:Closing all cached grpc data channels. INFO:apache_beam.runners.worker.sdk_worker:Closing all cached gRPC state handlers. INFO:apache_beam.runners.worker.sdk_worker:Done consuming work. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.dispatcher.StandaloneDispatcher - Job d5f59023684109783722c5784a3d5e89 reached globally terminal state FINISHED. [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.jobmaster.JobMaster - Stopping the JobMaster for job BeamApp-jenkins-1120164142-3180daea(d5f59023684109783722c5784a3d5e89). [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.slot.TaskSlotTable - Free slot TaskSlot(index:0, state:ACTIVE, resource profile: ResourceProfile{cpuCores=1.7976931348623157E308, heapMemoryInMB=2147483647, directMemoryInMB=2147483647, nativeMemoryInMB=2147483647, networkMemoryInMB=2147483647, managedMemoryInMB=8136}, allocationId: 83d63fdbf47788cf810f3c907dc685cc, jobId: d5f59023684109783722c5784a3d5e89). [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.jobmaster.slotpool.SlotPoolImpl - Suspending SlotPool. [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.jobmaster.JobMaster - Close ResourceManager connection 0e3c1543450a84ede7d3d843192521ac: JobManager is shutting down.. [flink-akka.actor.default-dispatcher-11] INFO org.apache.flink.runtime.jobmaster.slotpool.SlotPoolImpl - Stopping SlotPool. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.resourcemanager.StandaloneResourceManager - Disconnect job manager b6e35959b1c03053f43ca88c475844b1@akka://flink/user/jobmanager_1 for job d5f59023684109783722c5784a3d5e89 from the resource manager. [flink-runner-job-invoker] INFO org.apache.flink.runtime.minicluster.MiniCluster - Shutting down Flink Mini Cluster [flink-runner-job-invoker] INFO org.apache.flink.runtime.dispatcher.DispatcherRestEndpoint - Shutting down rest endpoint. [mini-cluster-io-thread-15] INFO org.apache.flink.runtime.taskexecutor.TaskExecutor - JobManager for job d5f59023684109783722c5784a3d5e89 with leader id b6e35959b1c03053f43ca88c475844b1 lost leadership. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.slot.TaskSlotTable - Free slot TaskSlot(index:1, state:ACTIVE, resource profile: ResourceProfile{cpuCores=1.7976931348623157E308, heapMemoryInMB=2147483647, directMemoryInMB=2147483647, nativeMemoryInMB=2147483647, networkMemoryInMB=2147483647, managedMemoryInMB=8136}, allocationId: 1444e90c2b61e8b6a0eeb6abe3c86160, jobId: d5f59023684109783722c5784a3d5e89). [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.JobLeaderService - Remove job d5f59023684109783722c5784a3d5e89 from job leader monitoring. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.TaskExecutor - Close JobManager connection for job d5f59023684109783722c5784a3d5e89. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.TaskExecutor - Close JobManager connection for job d5f59023684109783722c5784a3d5e89. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.JobLeaderService - Cannot reconnect to job d5f59023684109783722c5784a3d5e89 because it is not registered. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.TaskExecutor - Stopping TaskExecutor akka://flink/user/taskmanager_0. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.TaskExecutor - Close ResourceManager connection 0e3c1543450a84ede7d3d843192521ac. [flink-akka.actor.default-dispatcher-15] INFO org.apache.flink.runtime.resourcemanager.StandaloneResourceManager - Closing TaskExecutor connection d95fa5d6-bd35-41ed-a459-fa4003d3780f because: The TaskExecutor is shutting down. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.JobLeaderService - Stop job leader service. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.state.TaskExecutorLocalStateStoresManager - Shutting down TaskExecutorLocalStateStoresManager. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.io.disk.FileChannelManagerImpl - FileChannelManager removed spill file directory /tmp/flink-io-2d37dd04-4102-4175-8eb7-11aeafba45cd [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.io.network.NettyShuffleEnvironment - Shutting down the network environment and its components. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.io.disk.FileChannelManagerImpl - FileChannelManager removed spill file directory /tmp/flink-netty-shuffle-a0309f2c-59a3-4142-9eb1-f5193122bef1 [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.KvStateService - Shutting down the kvState service and its components. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.JobLeaderService - Stop job leader service. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.filecache.FileCache - removed file cache directory /tmp/flink-dist-cache-e0a78b03-1805-44cd-bf19-ac38be9ebe29 [ForkJoinPool.commonPool-worker-9] INFO org.apache.flink.runtime.dispatcher.DispatcherRestEndpoint - Removing cache directory /tmp/flink-web-ui [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.taskexecutor.TaskExecutor - Stopped TaskExecutor akka://flink/user/taskmanager_0. [ForkJoinPool.commonPool-worker-9] INFO org.apache.flink.runtime.dispatcher.DispatcherRestEndpoint - Shut down complete. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.resourcemanager.StandaloneResourceManager - Shut down cluster because application is in CANCELED, diagnostics DispatcherResourceManagerComponent has been closed.. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.dispatcher.StandaloneDispatcher - Stopping dispatcher akka://flink/user/dispatcher. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.resourcemanager.slotmanager.SlotManagerImpl - Closing the SlotManager. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.dispatcher.StandaloneDispatcher - Stopping all currently running jobs of dispatcher akka://flink/user/dispatcher. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.resourcemanager.slotmanager.SlotManagerImpl - Suspending the SlotManager. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.rest.handler.legacy.backpressure.StackTraceSampleCoordinator - Shutting down stack trace sample coordinator. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.dispatcher.StandaloneDispatcher - Stopped dispatcher akka://flink/user/dispatcher. [flink-akka.actor.default-dispatcher-14] INFO org.apache.flink.runtime.rpc.akka.AkkaRpcService - Stopping Akka RPC service. [flink-metrics-2] INFO akka.remote.RemoteActorRefProvider$RemotingTerminator - Shutting down remote daemon. [flink-metrics-2] INFO akka.remote.RemoteActorRefProvider$RemotingTerminator - Remote daemon shut down; proceeding with flushing remote transports. [flink-metrics-2] INFO akka.remote.RemoteActorRefProvider$RemotingTerminator - Remoting shut down. [flink-metrics-2] INFO org.apache.flink.runtime.rpc.akka.AkkaRpcService - Stopping Akka RPC service. [flink-metrics-2] INFO org.apache.flink.runtime.rpc.akka.AkkaRpcService - Stopped Akka RPC service. [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.blob.PermanentBlobCache - Shutting down BLOB cache [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.blob.TransientBlobCache - Shutting down BLOB cache [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.blob.BlobServer - Stopped BLOB server at 0.0.0.0:33803 [flink-akka.actor.default-dispatcher-12] INFO org.apache.flink.runtime.rpc.akka.AkkaRpcService - Stopped Akka RPC service. [flink-runner-job-invoker] INFO org.apache.beam.runners.flink.FlinkPipelineRunner - Execution finished in 51626 msecs [flink-runner-job-invoker] INFO org.apache.beam.runners.flink.FlinkPipelineRunner - Final accumulator values: [flink-runner-job-invoker] INFO org.apache.beam.runners.flink.FlinkPipelineRunner - __metricscontainers : MetricQueryResults(Counters(19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_format_24}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Pair_35}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_9}: 1, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/FlatMap(<lambda at core.py:2532>)_30}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_pair_with_one_18}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_pair_with_one_18}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_29:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_18:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_17:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_18:0}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_pair_with_one_18}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_15:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/PreFinalize_42}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_9:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/FlatMap(<lambda at core.py:2532>)_30}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:user {NAMESPACE=__main__.WordExtractingDoFn, PTRANSFORM=ref_AppliedPTransform_split_17, NAME=words}: 96, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Pair_35}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/Split_5}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_28:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_format_24}: 0, 6format.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WindowInto(WindowIntoFn)_36}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_18:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/InitializeWrite_33}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/Split_5}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_21:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_18:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_15:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/FinalizeWrite_43}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_15:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Pair_35}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_28:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/FinalizeWrite_43}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_count_23}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Extract_41}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_20:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_30}: 2, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/Map(decode)_32}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_20:0}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_split_17}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_17:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_15}: 44, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_10}: 27, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_17:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_16}: 44, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_11}: 96, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_split_17}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_20:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_17}: 44, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_format_24}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_count_23}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_12}: 96, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_17:0}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_2}: 1, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_1}: 1, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WindowInto(WindowIntoFn)_36}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WindowInto(WindowIntoFn)_36}: 0, 6format.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WriteBundles_34}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_2:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/FinalizeWrite_43}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_split_17}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: 1, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_15:0}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Extract_41}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_21:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_29:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_count_23}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_split_17}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Extract_41}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/ReadSplits_16}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_12:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_17:0}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Extract_41}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WindowInto(WindowIntoFn)_36}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_count_23}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_24:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/FlatMap(<lambda at core.py:2532>)_30}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_pair_with_one_18}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_24:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_24:0}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_12:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_17:0}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_1:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: 1, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/ReadSplits_16}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/ReadSplits_16}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/ReadSplits_16}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_27:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_24:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/InitializeWrite_33}: 0, 6format.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_17}: 44, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_27:0}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_2:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/FlatMap(<lambda at core.py:2532>)_30}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/Map(decode)_32}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_20:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_18}: 1, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/InitializeWrite_33}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_9:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_19}: 1, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_9:0}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/Split_5}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_12:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WriteBundles_34}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_9:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_24}: 2, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/PreFinalize_42}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WriteBundles_34}: 0, 6format.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/WriteBundles_34}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_21:0}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_2:0}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_12:0}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_17:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_21:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/InitializeWrite_33}: 0, 6format.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_17:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/Pair_35}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_1:0}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_28:0}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:user {NAMESPACE=__main__.WordExtractingDoFn, PTRANSFORM=ref_AppliedPTransform_split_17, NAME=empty_lines}: 2, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_27:0}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_1:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_21}: 1, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: 1, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_1:0}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_28:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/PreFinalize_42}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/PreFinalize_42}: 0, 6format.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_23}: 2, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_20:0}: 0, 6format.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_22}: 2, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_2:0}: 0, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:user {NAMESPACE=__main__.WordExtractingDoFn, PTRANSFORM=ref_AppliedPTransform_split_17, NAME=word_lengths}: 298, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_27}: 1, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_29:0}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_28}: 2, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/FinalizeWrite_43}: 0, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_format_24}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:finish_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/Map(decode)_32}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: 1, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:element_count:v1 {PCOLLECTION=ref_PCollection_PCollection_29}: 0, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:ptransform_execution_time:total_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_read/Read/Split_5}: 0, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:pardo_execution_time:start_bundle_msecs:v1 {PTRANSFORM=fn/write/ref_PCollection_PCollection_29:0}: 0, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=ref_AppliedPTransform_write/Write/WriteImpl/DoOnce/Map(decode)_32}: 0, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:pardo_execution_time:process_bundle_msecs:v1 {PTRANSFORM=fn/read/ref_PCollection_PCollection_27:0}: 0)Distributions(19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_17}: DistributionResult{sum=671, count=33, min=18, max=24}, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_15}: DistributionResult{sum=847, count=36, min=20, max=29}, 19group/GroupByWindow.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_16}: DistributionResult{sum=598, count=31, min=17, max=23}, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: DistributionResult{sum=14, count=1, min=14, max=14}, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_2}: DistributionResult{sum=685, count=1, min=685, max=685}, 17read/Read/Impulse.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_1}: DistributionResult{sum=13, count=1, min=13, max=13}, 6format.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_17}: DistributionResult{sum=764, count=36, min=19, max=28}, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: DistributionResult{sum=15, count=1, min=15, max=15}, 6format.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_22}: DistributionResult{sum=276, count=2, min=138, max=138}, 6format.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_23}: DistributionResult{sum=278, count=2, min=139, max=139}, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_29}: DistributionResult{sum=0, count=0, min=9223372036854775807, max=-9223372036854775808}, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_18}: DistributionResult{sum=13, count=1, min=13, max=13}, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:user_distribution {NAMESPACE=__main__.WordExtractingDoFn, PTRANSFORM=ref_AppliedPTransform_split_17, NAME=word_len_dist}: DistributionResult{sum=298, count=96, min=1, max=10}, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: DistributionResult{sum=15, count=1, min=15, max=15}, 36write/Write/WriteImpl/DoOnce/Impulse.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_19}: DistributionResult{sum=15, count=1, min=15, max=15}, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:1:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_21}: DistributionResult{sum=81, count=1, min=81, max=81}, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_28}: DistributionResult{sum=276, count=2, min=138, max=138}, 46write/Write/WriteImpl/GroupByKey/GroupByWindow.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_27}: DistributionResult{sum=271, count=1, min=271, max=271}, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_10}: DistributionResult{sum=695, count=18, min=14, max=84}, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_11}: DistributionResult{sum=655, count=40, min=14, max=20}, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_12}: DistributionResult{sum=672, count=36, min=16, max=25}, 36read/Read/Reshuffle/RemoveRandomKeys.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_9}: DistributionResult{sum=685, count=1, min=685, max=685}, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:2:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_30}: DistributionResult{sum=106, count=2, min=53, max=53}, 40write/Write/WriteImpl/DoOnce/Map(decode).None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_20}: DistributionResult{sum=15, count=1, min=15, max=15}, 6format.None/beam:env:external:v1:0:beam:metric:sampled_byte_size:v1 {PCOLLECTION=ref_PCollection_PCollection_24}: DistributionResult{sum=278, count=2, min=139, max=139})) [flink-runner-job-invoker] INFO org.apache.beam.runners.fnexecution.artifact.AbstractArtifactRetrievalService - Manifest at /tmp/beam-tempBmrDnl/artifactsbVEnTq/job_ac626443-77de-45e7-9d89-9278324445fd/MANIFEST has 1 artifact locations [flink-runner-job-invoker] INFO org.apache.beam.runners.fnexecution.artifact.BeamFileSystemArtifactStagingService - Removed dir /tmp/beam-tempBmrDnl/artifactsbVEnTq/job_ac626443-77de-45e7-9d89-9278324445fd/ INFO:apache_beam.runners.portability.portable_runner:Job state changed to DONE [grpc-default-executor-0] INFO org.apache.beam.runners.fnexecution.jobsubmission.InMemoryJobService - Getting job metrics for BeamApp-jenkins-1120164142-3180daea_1c595482-10b8-4ece-93d1-aed867e76bb6 [grpc-default-executor-0] INFO org.apache.beam.runners.fnexecution.jobsubmission.InMemoryJobService - Finished getting job metrics for BeamApp-jenkins-1120164142-3180daea_1c595482-10b8-4ece-93d1-aed867e76bb6 INFO:root:number of empty lines: 2 INFO:root:average word length: 3 > Task :sdks:python:test-suites:portable:py2:portableWordCountSparkRunnerBatch <https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/__init__.py>:84: UserWarning: You are using Apache Beam with Python 2. New releases of Apache Beam will soon support Python 3 only. 'You are using Apache Beam with Python 2. ' No handlers could be found for logger "apache_beam.runners.portability.fn_api_runner_transforms" 19/11/20 16:42:42 INFO org.apache.beam.runners.fnexecution.jobsubmission.JobServerDriver: ArtifactStagingService started on localhost:40149 19/11/20 16:42:42 INFO org.apache.beam.runners.fnexecution.jobsubmission.JobServerDriver: Java ExpansionService started on localhost:43735 19/11/20 16:42:42 INFO org.apache.beam.runners.fnexecution.jobsubmission.JobServerDriver: JobService started on localhost:46045 WARNING:apache_beam.options.pipeline_options:Discarding unparseable args: ['--parallelism=2', '--shutdown_sources_on_final_watermark'] 19/11/20 16:42:44 INFO org.apache.beam.runners.spark.SparkJobInvoker: Invoking job BeamApp-jenkins-1120164244-45604571_73f6bb51-4b54-4341-bf83-5a4dde36c534 19/11/20 16:42:44 INFO org.apache.beam.runners.fnexecution.jobsubmission.JobInvocation: Starting job invocation BeamApp-jenkins-1120164244-45604571_73f6bb51-4b54-4341-bf83-5a4dde36c534 INFO:root:Waiting until the pipeline has finished because the environment "LOOPBACK" has started a component necessary for the execution. INFO:apache_beam.runners.portability.portable_runner:Job state changed to RUNNING 19/11/20 16:42:44 INFO org.apache.beam.runners.spark.SparkPipelineRunner: PipelineOptions.filesToStage was not specified. Defaulting to files from the classpath 19/11/20 16:42:44 INFO org.apache.beam.runners.spark.SparkPipelineRunner: Will stage 1 files. (Enable logging at DEBUG level to see which files will be staged.) 19/11/20 16:42:44 INFO org.apache.beam.runners.spark.translation.SparkContextFactory: Creating a brand new Spark Context. 19/11/20 16:42:44 WARN org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable 19/11/20 16:42:45 INFO org.apache.beam.runners.spark.SparkPipelineRunner: Running job BeamApp-jenkins-1120164244-45604571_73f6bb51-4b54-4341-bf83-5a4dde36c534 on Spark master local[4] 19/11/20 16:42:45 INFO org.apache.beam.runners.spark.aggregators.AggregatorsAccumulator: Instantiated aggregators accumulator: 19/11/20 16:42:45 INFO org.apache.beam.runners.spark.metrics.MetricsAccumulator: Instantiated metrics accumulator: MetricQueryResults() INFO:apache_beam.runners.worker.statecache:Creating state cache with size 0 INFO:apache_beam.runners.worker.sdk_worker:Creating insecure control channel for localhost:33065. INFO:apache_beam.runners.worker.sdk_worker:Control channel established. INFO:apache_beam.runners.worker.sdk_worker:Initializing SDKHarness with unbounded number of workers. 19/11/20 16:42:48 INFO org.apache.beam.runners.fnexecution.control.FnApiControlClientPoolService: Beam Fn Control client connected with id 1-1 INFO:apache_beam.runners.worker.sdk_worker:Creating insecure state channel for localhost:33621. INFO:apache_beam.runners.worker.sdk_worker:State channel established. INFO:apache_beam.runners.worker.data_plane:Creating client data channel for localhost:44437 19/11/20 16:42:48 INFO org.apache.beam.runners.fnexecution.data.GrpcDataService: Beam Fn Data client connected. 19/11/20 16:42:48 WARN org.apache.beam.runners.spark.translation.GroupNonMergingWindowsFunctions: Either coder LengthPrefixCoder(ByteArrayCoder) or GlobalWindow$Coder is not consistent with equals. That might cause issues on some runners. WARNING:apache_beam.io.filebasedsink:Deleting 4 existing files in target path matching: -*-of-%(num_shards)05d 19/11/20 16:43:13 INFO org.apache.beam.runners.spark.SparkPipelineRunner: Job BeamApp-jenkins-1120164244-45604571_73f6bb51-4b54-4341-bf83-5a4dde36c534: Pipeline translated successfully. Computing outputs INFO:apache_beam.io.filebasedsink:Starting finalize_write threads with num_shards: 4 (skipped: 0), batches: 4, num_threads: 4 INFO:apache_beam.io.filebasedsink:Renamed 4 shards in 0.12 seconds. 19/11/20 16:43:37 INFO org.apache.beam.runners.spark.SparkPipelineRunner: Job BeamApp-jenkins-1120164244-45604571_73f6bb51-4b54-4341-bf83-5a4dde36c534 finished. 19/11/20 16:43:37 WARN org.apache.beam.runners.spark.SparkPipelineResult$BatchMode: Collecting monitoring infos is not implemented yet in Spark portable runner. 19/11/20 16:43:37 INFO org.apache.beam.runners.fnexecution.artifact.AbstractArtifactRetrievalService: Manifest at /tmp/beam-temp3JEKDZ/artifactsmPR2bW/job_31ec32b5-cb7b-4489-ae6d-37b0191751eb/MANIFEST has 1 artifact locations 19/11/20 16:43:37 INFO org.apache.beam.runners.fnexecution.artifact.BeamFileSystemArtifactStagingService: Removed dir /tmp/beam-temp3JEKDZ/artifactsmPR2bW/job_31ec32b5-cb7b-4489-ae6d-37b0191751eb/ INFO:apache_beam.runners.portability.portable_runner:Job state changed to DONE 19/11/20 16:43:37 INFO org.apache.beam.runners.fnexecution.jobsubmission.InMemoryJobService: Getting job metrics for BeamApp-jenkins-1120164244-45604571_73f6bb51-4b54-4341-bf83-5a4dde36c534 19/11/20 16:43:37 INFO org.apache.beam.runners.fnexecution.jobsubmission.InMemoryJobService: Finished getting job metrics for BeamApp-jenkins-1120164244-45604571_73f6bb51-4b54-4341-bf83-5a4dde36c534 ERROR:apache_beam.runners.worker.data_plane:Failed to read inputs in the data plane. Traceback (most recent call last): File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/data_plane.py";,> line 272, in _read_inputs for elements in elements_iterator: File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 395, in next return self._next() File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 561, in _next raise self _Rendezvous: <_Rendezvous of RPC that terminated with: status = StatusCode.UNAVAILABLE details = "Socket closed" debug_error_string = "{"created":"@1574268217.765382465","description":"Error received from peer ipv4:127.0.0.1:44437","file":"src/core/lib/surface/call.cc","file_line":1055,"grpc_message":"Socket closed","grpc_status":14}" > Exception in thread read_grpc_client_inputs: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 754, in run self.__target(*self.__args, **self.__kwargs) File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/data_plane.py";,> line 286, in <lambda> target=lambda: self._read_inputs(elements_iterator), File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/data_plane.py";,> line 272, in _read_inputs for elements in elements_iterator: File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 395, in next return self._next() File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 561, in _next raise self _Rendezvous: <_Rendezvous of RPC that terminated with: status = StatusCode.UNAVAILABLE details = "Socket closed" debug_error_string = "{"created":"@1574268217.765382465","description":"Error received from peer ipv4:127.0.0.1:44437","file":"src/core/lib/surface/call.cc","file_line":1055,"grpc_message":"Socket closed","grpc_status":14}" > Exception in thread run_worker_1-1: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 754, in run self.__target(*self.__args, **self.__kwargs) File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/sdk_worker.py";,> line 111, in run for work_request in control_stub.Control(get_responses()): File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 395, in next return self._next() File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 561, in _next raise self _Rendezvous: <_Rendezvous of RPC that terminated with: status = StatusCode.UNAVAILABLE details = "Socket closed" debug_error_string = "{"created":"@1574268217.765881409","description":"Error received from peer ipv4:127.0.0.1:33065","file":"src/core/lib/surface/call.cc","file_line":1055,"grpc_message":"Socket closed","grpc_status":14}" > Exception in thread read_state: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 754, in run self.__target(*self.__args, **self.__kwargs) File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/apache_beam/runners/worker/sdk_worker.py";,> line 532, in pull_responses for response in responses: File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 395, in next return self._next() File "<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,> line 561, in _next raise self _Rendezvous: <_Rendezvous of RPC that terminated with: status = StatusCode.UNAVAILABLE details = "Socket closed" debug_error_string = "{"created":"@1574268217.765390239","description":"Error received from peer ipv4:127.0.0.1:33621","file":"src/core/lib/surface/call.cc","file_line":1055,"grpc_message":"Socket closed","grpc_status":14}" > > Task :sdks:python:test-suites:portable:py2:postCommitPy2 FAILURE: Build failed with an exception. * Where: Build file '<https://builds.apache.org/job/beam_PostCommit_Python2/ws/src/sdks/python/test-suites/dataflow/py2/build.gradle'> line: 85 * What went wrong: Execution failed for task ':sdks:python:test-suites:dataflow:py2:postCommitIT'. > Process 'command 'sh'' finished with non-zero exit value 1 * Try: Run with --stacktrace option to get the stack trace. Run with --info or --debug option to get more log output. Run with --scan to get full insights. * Get more help at https://help.gradle.org Deprecated Gradle features were used in this build, making it incompatible with Gradle 6.0. Use '--warning-mode all' to show the individual deprecation warnings. See https://docs.gradle.org/5.2.1/userguide/command_line_interface.html#sec:command_line_warnings BUILD FAILED in 10m 49s 120 actionable tasks: 94 executed, 23 from cache, 3 up-to-date Publishing build scan... https://gradle.com/s/vwz4qe6arn5sq Build step 'Invoke Gradle script' changed build result to FAILURE Build step 'Invoke Gradle script' marked build as failure --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
