See <https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/100/display/redirect>
Changes: ------------------------------------------ [...truncated 94.05 KB...] INFO:apache_beam.utils.subprocess_server:Mar 19, 2023 11:55:40 AM org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader payloadToConfig INFO:apache_beam.utils.subprocess_server:WARNING: Configuration class 'org.apache.beam.sdk.io.kafka.KafkaIO$Write$External$Configuration' has no schema registered. Attempting to construct with setter approach. INFO:apache_beam.runners.dataflow.dataflow_runner:Automatically enabling Dataflow Runner V2 since the pipeline used cross-language transforms. INFO:apache_beam.runners.portability.stager:Copying Beam SDK "<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/python/build/apache-beam.tar.gz";> to staging location. INFO:apache_beam.runners.dataflow.dataflow_runner:Pipeline has additional dependencies to be installed in SDK **** container, consider using the SDK container image pre-building workflow to avoid repetitive installations. Learn more on https://cloud.google.com/dataflow/docs/guides/using-custom-containers#prebuild INFO:root:Default Python SDK image for environment is apache/beam_python3.7_sdk:2.47.0.dev INFO:root:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20230126 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20230126" for Docker environment INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function pack_combiners at 0x7fb0f4481440> ==================== INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function sort_stages at 0x7fb0f4481c20> ==================== INFO:apache_beam.runners.dataflow.internal.apiclient:Defaulting to the temp_location as staging_location: gs://temp-storage-for-perf-tests/ INFO:apache_beam.internal.gcp.auth:Setting socket default timeout to 60 seconds. INFO:apache_beam.internal.gcp.auth:socket default timeout is 60.0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319115543-534717-56sflvd6.1679226943.535035/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT-cGeHlh9eyoq3cqvkXmDyXVYOLYP3iCO2ribK2aMVcnI.jar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319115543-534717-56sflvd6.1679226943.535035/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT-cGeHlh9eyoq3cqvkXmDyXVYOLYP3iCO2ribK2aMVcnI.jar in 2 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319115543-534717-56sflvd6.1679226943.535035/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319115543-534717-56sflvd6.1679226943.535035/dataflow_python_sdk.tar in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319115543-534717-56sflvd6.1679226943.535035/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319115543-534717-56sflvd6.1679226943.535035/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20230319115543537450-3032' createTime: '2023-03-19T11:55:47.336984Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2023-03-19_04_55_46-10404120417669153169' location: 'us-central1' name: 'beamapp-jenkins-0319115543-534717-56sflvd6' projectId: 'apache-beam-testing' stageStates: [] startTime: '2023-03-19T11:55:47.336984Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_BATCH, 1)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2023-03-19_04_55_46-10404120417669153169] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2023-03-19_04_55_46-10404120417669153169 INFO:apache_beam.runners.dataflow.internal.apiclient:To access the Dataflow monitoring console, please navigate to https://console.cloud.google.com/dataflow/jobs/us-central1/2023-03-19_04_55_46-10404120417669153169?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-03-19_04_55_46-10404120417669153169 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:52.010Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-b. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.018Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.043Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.106Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.146Z: JOB_MESSAGE_DEBUG: Combiner lifting skipped for step Avoid Fusion/ReshufflePerKey/GroupByKey: GroupByKey not followed by a combiner. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.195Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.221Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.253Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.279Z: JOB_MESSAGE_DETAILED: Fusing consumer Generate records/Map(<lambda at iobase.py:908>) into Generate records/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.299Z: JOB_MESSAGE_DETAILED: Fusing consumer ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/PairWithRestriction into Generate records/Map(<lambda at iobase.py:908>) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.319Z: JOB_MESSAGE_DETAILED: Fusing consumer ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/SplitWithSizing into ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/PairWithRestriction INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.343Z: JOB_MESSAGE_DETAILED: Fusing consumer Count records into ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/ProcessElementAndRestrictionWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.367Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/AddRandomKeys into Count records INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.387Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/Map(reify_timestamps) into Avoid Fusion/AddRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.412Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/Reify into Avoid Fusion/ReshufflePerKey/Map(reify_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.432Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/Write into Avoid Fusion/ReshufflePerKey/GroupByKey/Reify INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.453Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/GroupByWindow into Avoid Fusion/ReshufflePerKey/GroupByKey/Read INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.475Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps) into Avoid Fusion/ReshufflePerKey/GroupByKey/GroupByWindow INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.499Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/RemoveRandomKeys into Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.521Z: JOB_MESSAGE_DETAILED: Fusing consumer Measure time into Avoid Fusion/RemoveRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.542Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToKafka/Kafka ProducerRecord/Map/ParMultiDo(Anonymous) into Measure time INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.563Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToKafka/KafkaIO.WriteRecords/ParDo(KafkaWriter)/ParMultiDo(KafkaWriter) into WriteToKafka/Kafka ProducerRecord/Map/ParMultiDo(Anonymous) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.609Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.628Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.651Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.681Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.840Z: JOB_MESSAGE_DEBUG: Executing wait step start20 INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.898Z: JOB_MESSAGE_BASIC: Executing operation Generate records/Impulse+Generate records/Map(<lambda at iobase.py:908>)+ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/PairWithRestriction+ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/SplitWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.936Z: JOB_MESSAGE_DEBUG: Starting **** pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:55:53.965Z: JOB_MESSAGE_BASIC: Starting 5 ****s in us-central1-b... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-03-19_04_55_46-10404120417669153169 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:56:01.660Z: JOB_MESSAGE_BASIC: Your project already contains 100 Dataflow-created metric descriptors, so new user metrics of the form custom.googleapis.com/* will not be created. However, all user metrics are also available in the metric dataflow.googleapis.com/job/user_counter. If you rely on the custom metrics, you can delete old / unused metric descriptors. See https://developers.google.com/apis-explorer/#p/monitoring/v3/monitoring.projects.metricDescriptors.list and https://developers.google.com/apis-explorer/#p/monitoring/v3/monitoring.projects.metricDescriptors.delete INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:56:31.783Z: JOB_MESSAGE_DETAILED: Autoscaling: Raised the number of ****s to 5 based on the rate of progress in the currently running stage(s). INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T11:58:11.090Z: JOB_MESSAGE_DETAILED: Workers have started successfully. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:02:19.451Z: JOB_MESSAGE_DETAILED: All ****s have finished the startup processes and began to receive work requests. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:02:21.136Z: JOB_MESSAGE_BASIC: Finished operation Generate records/Impulse+Generate records/Map(<lambda at iobase.py:908>)+ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/PairWithRestriction+ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/SplitWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:02:21.237Z: JOB_MESSAGE_DEBUG: Value "ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6-split-with-sizing-out3" materialized. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:02:21.322Z: JOB_MESSAGE_BASIC: Executing operation Avoid Fusion/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:02:23.116Z: JOB_MESSAGE_BASIC: Finished operation Avoid Fusion/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:02:23.214Z: JOB_MESSAGE_DEBUG: Value "Avoid Fusion/ReshufflePerKey/GroupByKey/Session" materialized. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:02:23.282Z: JOB_MESSAGE_BASIC: Executing operation ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/ProcessElementAndRestrictionWithSizing+Count records+Avoid Fusion/AddRandomKeys+Avoid Fusion/ReshufflePerKey/Map(reify_timestamps)+Avoid Fusion/ReshufflePerKey/GroupByKey/Reify+Avoid Fusion/ReshufflePerKey/GroupByKey/Write INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:16:03.676Z: JOB_MESSAGE_BASIC: Finished operation ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/ProcessElementAndRestrictionWithSizing+Count records+Avoid Fusion/AddRandomKeys+Avoid Fusion/ReshufflePerKey/Map(reify_timestamps)+Avoid Fusion/ReshufflePerKey/GroupByKey/Reify+Avoid Fusion/ReshufflePerKey/GroupByKey/Write INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:16:03.781Z: JOB_MESSAGE_BASIC: Executing operation Avoid Fusion/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:16:03.923Z: JOB_MESSAGE_BASIC: Finished operation Avoid Fusion/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:16:03.986Z: JOB_MESSAGE_BASIC: Executing operation Avoid Fusion/ReshufflePerKey/GroupByKey/Read+Avoid Fusion/ReshufflePerKey/GroupByKey/GroupByWindow+Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps)+Avoid Fusion/RemoveRandomKeys+Measure time+WriteToKafka/Kafka ProducerRecord/Map/ParMultiDo(Anonymous)+WriteToKafka/KafkaIO.WriteRecords/ParDo(KafkaWriter)/ParMultiDo(KafkaWriter) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:22:12.093Z: JOB_MESSAGE_BASIC: Finished operation Avoid Fusion/ReshufflePerKey/GroupByKey/Read+Avoid Fusion/ReshufflePerKey/GroupByKey/GroupByWindow+Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps)+Avoid Fusion/RemoveRandomKeys+Measure time+WriteToKafka/Kafka ProducerRecord/Map/ParMultiDo(Anonymous)+WriteToKafka/KafkaIO.WriteRecords/ParDo(KafkaWriter)/ParMultiDo(KafkaWriter) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:22:12.155Z: JOB_MESSAGE_DEBUG: Executing success step success18 INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:22:12.239Z: JOB_MESSAGE_DETAILED: Cleaning up. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:22:12.295Z: JOB_MESSAGE_DEBUG: Starting **** pool teardown. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:22:12.325Z: JOB_MESSAGE_BASIC: Stopping **** pool... INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:22.173Z: JOB_MESSAGE_DETAILED: Autoscaling: Resized **** pool from 5 to 0. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:22.230Z: JOB_MESSAGE_BASIC: Worker pool stopped. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:22.257Z: JOB_MESSAGE_DEBUG: Tearing down pending resources... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-03-19_04_55_46-10404120417669153169 is in state JOB_STATE_DONE INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Load test results for test: 190c2730397448a5a24562bd0366f771 and timestamp: 1679228669.0245152: INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: write_count_records_total_messages Value: 100000000 INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: write_runtime Value: 367 INFO:apache_beam.utils.subprocess_server:Using pre-built snapshot at <https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/java/io/expansion-service/build/libs/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT.jar> INFO:root:Starting a JAR-based expansion service from JAR <https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/java/io/expansion-service/build/libs/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT.jar> INFO:apache_beam.utils.subprocess_server:Starting service with ['java' '-jar' '<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/java/io/expansion-service/build/libs/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT.jar'> '42753' '--filesToStage=<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/java/io/expansion-service/build/libs/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT.jar']> INFO:apache_beam.utils.subprocess_server:Starting expansion service at localhost:42753 INFO:apache_beam.utils.subprocess_server:Mar 19, 2023 12:24:30 PM org.apache.beam.sdk.expansion.service.ExpansionService loadRegisteredTransforms INFO:apache_beam.utils.subprocess_server:INFO: Registering external transforms: [beam:transform:org.apache.beam:kafka_read_with_metadata:v1, beam:transform:org.apache.beam:kafka_read_without_metadata:v1, beam:transform:org.apache.beam:kafka_write:v1, beam:external:java:generate_sequence:v1] INFO:apache_beam.utils.subprocess_server: INFO:apache_beam.utils.subprocess_server:Registered transforms: INFO:apache_beam.utils.subprocess_server: beam:transform:org.apache.beam:kafka_read_with_metadata:v1: org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader$1@e50a6f6 INFO:apache_beam.utils.subprocess_server: beam:transform:org.apache.beam:kafka_read_without_metadata:v1: org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader$1@14ec4505 INFO:apache_beam.utils.subprocess_server: beam:transform:org.apache.beam:kafka_write:v1: org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader$1@53ca01a2 INFO:apache_beam.utils.subprocess_server: beam:external:java:generate_sequence:v1: org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader$1@358c99f5 INFO:apache_beam.utils.subprocess_server: INFO:apache_beam.utils.subprocess_server:Registered SchemaTransformProviders: INFO:apache_beam.utils.subprocess_server: beam:schematransform:org.apache.beam:kafka_read:v1 INFO:apache_beam.utils.subprocess_server: beam:schematransform:org.apache.beam:kafka_write:v1 INFO:apache_beam.utils.subprocess_server:Mar 19, 2023 12:24:31 PM org.apache.beam.sdk.expansion.service.ExpansionService expand INFO:apache_beam.utils.subprocess_server:INFO: Expanding 'ReadFromKafka' with URN 'beam:transform:org.apache.beam:kafka_read_without_metadata:v1' INFO:apache_beam.utils.subprocess_server:Mar 19, 2023 12:24:32 PM org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader payloadToConfig INFO:apache_beam.utils.subprocess_server:WARNING: Configuration class 'org.apache.beam.sdk.io.kafka.KafkaIO$Read$External$Configuration' has no schema registered. Attempting to construct with setter approach. INFO:apache_beam.utils.subprocess_server:Mar 19, 2023 12:24:32 PM org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader payloadToConfig INFO:apache_beam.utils.subprocess_server:WARNING: Configuration class 'org.apache.beam.sdk.io.kafka.KafkaIO$Read$External$Configuration' has no schema registered. Attempting to construct with setter approach. INFO:apache_beam.runners.dataflow.dataflow_runner:Automatically enabling Dataflow Runner V2 since the pipeline used cross-language transforms. INFO:apache_beam.runners.portability.stager:Copying Beam SDK "<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/python/build/apache-beam.tar.gz";> to staging location. INFO:apache_beam.runners.dataflow.dataflow_runner:Pipeline has additional dependencies to be installed in SDK **** container, consider using the SDK container image pre-building workflow to avoid repetitive installations. Learn more on https://cloud.google.com/dataflow/docs/guides/using-custom-containers#prebuild INFO:root:Default Python SDK image for environment is apache/beam_python3.7_sdk:2.47.0.dev INFO:root:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20230126 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20230126" for Docker environment INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function pack_combiners at 0x7fb0f4481440> ==================== INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function sort_stages at 0x7fb0f4481c20> ==================== INFO:apache_beam.runners.dataflow.internal.apiclient:Defaulting to the temp_location as staging_location: gs://temp-storage-for-perf-tests/ INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319122435-316465-qixj6f8m.1679228675.316834/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT-cGeHlh9eyoq3cqvkXmDyXVYOLYP3iCO2ribK2aMVcnI.jar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319122435-316465-qixj6f8m.1679228675.316834/beam-sdks-java-io-expansion-service-2.47.0-SNAPSHOT-cGeHlh9eyoq3cqvkXmDyXVYOLYP3iCO2ribK2aMVcnI.jar in 2 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319122435-316465-qixj6f8m.1679228675.316834/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319122435-316465-qixj6f8m.1679228675.316834/dataflow_python_sdk.tar in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319122435-316465-qixj6f8m.1679228675.316834/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0319122435-316465-qixj6f8m.1679228675.316834/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20230319122435317955-8470' createTime: '2023-03-19T12:24:38.640685Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2023-03-19_05_24_38-17310498042071246757' location: 'us-central1' name: 'beamapp-jenkins-0319122435-316465-qixj6f8m' projectId: 'apache-beam-testing' stageStates: [] startTime: '2023-03-19T12:24:38.640685Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_BATCH, 1)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2023-03-19_05_24_38-17310498042071246757] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2023-03-19_05_24_38-17310498042071246757 INFO:apache_beam.runners.dataflow.internal.apiclient:To access the Dataflow monitoring console, please navigate to https://console.cloud.google.com/dataflow/jobs/us-central1/2023-03-19_05_24_38-17310498042071246757?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-03-19_05_24_38-17310498042071246757 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:42.649Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-b. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:43.809Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:43.844Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:43.896Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:43.924Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:43.960Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.001Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.025Z: JOB_MESSAGE_DETAILED: Fusing consumer ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/ParDo(GenerateKafkaSourceDescriptor)/ParMultiDo(GenerateKafkaSourceDescriptor) into ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.049Z: JOB_MESSAGE_DETAILED: Fusing consumer external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/PairWithRestriction into ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/ParDo(GenerateKafkaSourceDescriptor)/ParMultiDo(GenerateKafkaSourceDescriptor) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.083Z: JOB_MESSAGE_DETAILED: Fusing consumer external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/SplitWithSizing into external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/PairWithRestriction INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.106Z: JOB_MESSAGE_DETAILED: Fusing consumer ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/KafkaIO.ReadSourceDescriptors/MapElements/Map/ParMultiDo(Anonymous) into external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/ProcessElementAndRestrictionWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.138Z: JOB_MESSAGE_DETAILED: Fusing consumer ReadFromKafka/Remove Kafka Metadata/ParMultiDo(Anonymous) into ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/KafkaIO.ReadSourceDescriptors/MapElements/Map/ParMultiDo(Anonymous) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.166Z: JOB_MESSAGE_DETAILED: Fusing consumer Count records into ReadFromKafka/Remove Kafka Metadata/ParMultiDo(Anonymous) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.219Z: JOB_MESSAGE_DETAILED: Fusing consumer Measure time into Count records INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.252Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.280Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.306Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.329Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.456Z: JOB_MESSAGE_DEBUG: Executing wait step start10 INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.523Z: JOB_MESSAGE_BASIC: Executing operation ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/Impulse+ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/ParDo(GenerateKafkaSourceDescriptor)/ParMultiDo(GenerateKafkaSourceDescriptor)+external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/PairWithRestriction+external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/SplitWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.572Z: JOB_MESSAGE_DEBUG: Starting **** pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:24:44.604Z: JOB_MESSAGE_BASIC: Starting 5 ****s in us-central1-b... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-03-19_05_24_38-17310498042071246757 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:25:21.154Z: JOB_MESSAGE_BASIC: Your project already contains 100 Dataflow-created metric descriptors, so new user metrics of the form custom.googleapis.com/* will not be created. However, all user metrics are also available in the metric dataflow.googleapis.com/job/user_counter. If you rely on the custom metrics, you can delete old / unused metric descriptors. See https://developers.google.com/apis-explorer/#p/monitoring/v3/monitoring.projects.metricDescriptors.list and https://developers.google.com/apis-explorer/#p/monitoring/v3/monitoring.projects.metricDescriptors.delete INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:25:34.096Z: JOB_MESSAGE_DETAILED: Autoscaling: Raised the number of ****s to 5 based on the rate of progress in the currently running stage(s). INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:27:18.608Z: JOB_MESSAGE_DETAILED: Workers have started successfully. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:31:46.831Z: JOB_MESSAGE_DETAILED: All ****s have finished the startup processes and began to receive work requests. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:31:51.064Z: JOB_MESSAGE_BASIC: Finished operation ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/Impulse+ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/ParDo(GenerateKafkaSourceDescriptor)/ParMultiDo(GenerateKafkaSourceDescriptor)+external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/PairWithRestriction+external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/SplitWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:31:51.124Z: JOB_MESSAGE_DEBUG: Value "external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo-split-with-sizing-out3" materialized. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:31:51.171Z: JOB_MESSAGE_BASIC: Executing operation external_2ReadFromKafka-KafkaIO-Read-KafkaIO-Read-ReadFromKafkaViaSDF-KafkaIO-ReadSourceDescriptors-ParDo-Unbo/ProcessElementAndRestrictionWithSizing+ReadFromKafka/KafkaIO.Read/KafkaIO.Read.ReadFromKafkaViaSDF/KafkaIO.ReadSourceDescriptors/MapElements/Map/ParMultiDo(Anonymous)+ReadFromKafka/Remove Kafka Metadata/ParMultiDo(Anonymous)+Count records+Measure time INFO:apache_beam.runners.dataflow.dataflow_runner:2023-03-19T12:36:13.785Z: JOB_MESSAGE_ERROR: java.lang.IllegalStateException: Last attempted offset should not be null. No work was claimed in non-empty range [99998575, 9223372036854775807). at org.apache.beam.vendor.guava.v26_0_jre.com.google.common.base.Preconditions.checkState(Preconditions.java:588) at org.apache.beam.sdk.transforms.splittabledofn.OffsetRangeTracker.checkDone(OffsetRangeTracker.java:113) at org.apache.beam.sdk.fn.splittabledofn.RestrictionTrackers$RestrictionTrackerObserver.checkDone(RestrictionTrackers.java:80) at org.apache.beam.fn.harness.FnApiDoFnRunner.processElementForWindowObservingSizedElementAndRestriction(FnApiDoFnRunner.java:1100) at org.apache.beam.fn.harness.FnApiDoFnRunner.access$1500(FnApiDoFnRunner.java:142) at org.apache.beam.fn.harness.FnApiDoFnRunner$4.accept(FnApiDoFnRunner.java:656) at org.apache.beam.fn.harness.FnApiDoFnRunner$4.accept(FnApiDoFnRunner.java:651) at org.apache.beam.fn.harness.data.PCollectionConsumerRegistry$MetricTrackingFnDataReceiver.accept(PCollectionConsumerRegistry.java:313) at org.apache.beam.fn.harness.data.PCollectionConsumerRegistry$MetricTrackingFnDataReceiver.accept(PCollectionConsumerRegistry.java:245) at org.apache.beam.fn.harness.BeamFnDataReadRunner.forwardElementToConsumer(BeamFnDataReadRunner.java:213) at org.apache.beam.sdk.fn.data.BeamFnDataInboundObserver.multiplexElements(BeamFnDataInboundObserver.java:158) at org.apache.beam.fn.harness.control.ProcessBundleHandler.processBundle(ProcessBundleHandler.java:537) at org.apache.beam.fn.harness.control.BeamFnControlClient.delegateOnInstructionRequestType(BeamFnControlClient.java:151) at org.apache.beam.fn.harness.control.BeamFnControlClient$InboundObserver.lambda$onNext$0(BeamFnControlClient.java:116) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.beam.sdk.util.UnboundedScheduledExecutorService$ScheduledFutureTask.run(UnboundedScheduledExecutorService.java:163) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:750) WARNING:apache_beam.runners.dataflow.dataflow_runner:Timing out on waiting for job 2023-03-19_05_24_38-17310498042071246757 after 1501 seconds INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Load test results for test: 5e7383a08b8a4bb1ac176b5e98db59c9 and timestamp: 1679230185.159959: INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: read_count_records_total_messages Value: 99998575 INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: read_runtime Value: 292 Traceback (most recent call last): File "/usr/lib/python3.7/runpy.py", line 193, in _run_module_as_main "__main__", mod_spec) File "/usr/lib/python3.7/runpy.py", line 85, in _run_code exec(code, run_globals) File "<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/python/apache_beam/io/external/xlang_kafkaio_perf_test.py";,> line 139, in <module> getattr(sys.modules[__name__], test_options.test_class)().run() File "<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/python/apache_beam/io/external/xlang_kafkaio_perf_test.py";,> line 64, in run read_test.run() File "<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/python/apache_beam/testing/load_tests/load_test.py";,> line 156, in run self.cleanup() File "<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/python/apache_beam/io/external/xlang_kafkaio_perf_test.py";,> line 121, in cleanup assert total_messages == self.input_options['num_records'] AssertionError > Task :sdks:python:apache_beam:testing:load_tests:run FAILED FAILURE: Build failed with an exception. * Where: Build file '<https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/ws/src/sdks/python/apache_beam/testing/load_tests/build.gradle'> line: 63 * What went wrong: Execution failed for task ':sdks:python:apache_beam:testing:load_tests:run'. > error occurred * Try: > Run with --stacktrace option to get the stack trace. > Run with --info or --debug option to get more log output. * Get more help at https://help.gradle.org Deprecated Gradle features were used in this build, making it incompatible with Gradle 8.0. You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins. See https://docs.gradle.org/7.5.1/userguide/command_line_interface.html#sec:command_line_warnings BUILD FAILED in 55m 29s 15 actionable tasks: 5 executed, 10 up-to-date Publishing build scan... https://gradle.com/s/tgwua4rzayhqs 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]
