See <https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/199/display/redirect>
Changes: ------------------------------------------ [...truncated 101.74 KB...] 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.utils.subprocess_server:Jun 25, 2023 11:53:45 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:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/beam_python3.8_sdk:beam-master-20230422 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/beam_python3.8_sdk:beam-master-20230422" for Docker environment INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function pack_combiners at 0x7f8c9935b4c0> ==================== INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function sort_stages at 0x7f8c9935bca0> ==================== 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-0625115348-424861-ktlei3sg.1687694028.425201/beam-sdks-java-io-expansion-service-2.49.0-SNAPSHOT-w50PeuPRKj2lhawCI6FEOyYVKntL5Mq-6OUPkpIkeh4.jar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625115348-424861-ktlei3sg.1687694028.425201/beam-sdks-java-io-expansion-service-2.49.0-SNAPSHOT-w50PeuPRKj2lhawCI6FEOyYVKntL5Mq-6OUPkpIkeh4.jar in 2 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625115348-424861-ktlei3sg.1687694028.425201/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625115348-424861-ktlei3sg.1687694028.425201/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-0625115348-424861-ktlei3sg.1687694028.425201/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625115348-424861-ktlei3sg.1687694028.425201/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20230625115348426337-3771' createTime: '2023-06-25T11:53:52.129882Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2023-06-25_04_53_51-16016998447143968848' location: 'us-central1' name: 'beamapp-jenkins-0625115348-424861-ktlei3sg' projectId: 'apache-beam-testing' stageStates: [] startTime: '2023-06-25T11:53:52.129882Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_BATCH, 1)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2023-06-25_04_53_51-16016998447143968848] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2023-06-25_04_53_51-16016998447143968848 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-06-25_04_53_51-16016998447143968848?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-06-25_04_53_51-16016998447143968848 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:54.456Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-a. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.132Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.155Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.229Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.254Z: 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-06-25T11:53:57.282Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.307Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.337Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.355Z: 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-06-25T11:53:57.388Z: 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-06-25T11:53:57.412Z: 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-06-25T11:53:57.446Z: 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-06-25T11:53:57.470Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/AddRandomKeys into Count records INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.503Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/Map(reify_timestamps) into Avoid Fusion/AddRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.526Z: 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-06-25T11:53:57.557Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/Write into Avoid Fusion/ReshufflePerKey/GroupByKey/Reify INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.592Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/GroupByWindow into Avoid Fusion/ReshufflePerKey/GroupByKey/Read INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.627Z: 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-06-25T11:53:57.662Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/RemoveRandomKeys into Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.695Z: JOB_MESSAGE_DETAILED: Fusing consumer Measure time into Avoid Fusion/RemoveRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.711Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToKafka/Kafka ProducerRecord/Map/ParMultiDo(Anonymous) into Measure time INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.745Z: 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-06-25T11:53:57.785Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.802Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.837Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.865Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:57.982Z: JOB_MESSAGE_DEBUG: Executing wait step start20 INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:58.034Z: 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-06-25T11:53:58.074Z: JOB_MESSAGE_DEBUG: Starting **** pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:53:58.099Z: JOB_MESSAGE_BASIC: Starting 5 ****s in us-central1-a... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-06-25_04_53_51-16016998447143968848 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:54:14.401Z: 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-06-25T11:54:39.429Z: 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-06-25T11:56:45.728Z: JOB_MESSAGE_DETAILED: Workers have started successfully. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:58:45.230Z: JOB_MESSAGE_DETAILED: All ****s have finished the startup processes and began to receive work requests. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:58:46.004Z: 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-06-25T11:58:46.057Z: 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-06-25T11:58:46.114Z: JOB_MESSAGE_BASIC: Executing operation Avoid Fusion/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:58:46.647Z: JOB_MESSAGE_BASIC: Finished operation Avoid Fusion/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:58:46.699Z: JOB_MESSAGE_DEBUG: Value "Avoid Fusion/ReshufflePerKey/GroupByKey/Session" materialized. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T11:58:46.744Z: 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-06-25T12:09:15.132Z: 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-06-25T12:09:15.225Z: JOB_MESSAGE_BASIC: Executing operation Avoid Fusion/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:09:15.446Z: JOB_MESSAGE_BASIC: Finished operation Avoid Fusion/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:09:15.489Z: 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-06-25T12:15:20.399Z: 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-06-25T12:15:20.475Z: JOB_MESSAGE_DEBUG: Executing success step success18 INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:15:20.536Z: JOB_MESSAGE_DETAILED: Cleaning up. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:15:20.574Z: JOB_MESSAGE_DEBUG: Starting **** pool teardown. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:15:20.605Z: JOB_MESSAGE_BASIC: Stopping **** pool... INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:17:47.607Z: JOB_MESSAGE_DETAILED: Autoscaling: Resized **** pool from 5 to 0. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:17:47.634Z: JOB_MESSAGE_BASIC: Worker pool stopped. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:17:47.656Z: JOB_MESSAGE_DEBUG: Tearing down pending resources... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-06-25_04_53_51-16016998447143968848 is in state JOB_STATE_DONE INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Load test results for test: 9801bdef3b83447eb5192214b9c708de and timestamp: 1687695478.7303903: 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: 365 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.49.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.49.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.49.0-SNAPSHOT.jar'> '52927' '--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.49.0-SNAPSHOT.jar']> INFO:apache_beam.utils.subprocess_server:Starting expansion service at localhost:52927 INFO:apache_beam.utils.subprocess_server:Jun 25, 2023 12:17:59 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@4b168fa9 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@1a84f40f INFO:apache_beam.utils.subprocess_server: beam:transform:org.apache.beam:kafka_write:v1: org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader$1@23282c25 INFO:apache_beam.utils.subprocess_server: beam:external:java:generate_sequence:v1: org.apache.beam.sdk.expansion.service.ExpansionService$ExternalTransformRegistrarLoader$1@7920ba90 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:Jun 25, 2023 12:18:01 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:Dependencies list: {} INFO:apache_beam.utils.subprocess_server:Jun 25, 2023 12:18:01 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:Jun 25, 2023 12:18:02 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:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/beam_python3.8_sdk:beam-master-20230422 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/beam_python3.8_sdk:beam-master-20230422" for Docker environment INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function pack_combiners at 0x7f8c9935b4c0> ==================== INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function sort_stages at 0x7f8c9935bca0> ==================== 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-0625121804-900480-y9aae5n7.1687695484.900812/beam-sdks-java-io-expansion-service-2.49.0-SNAPSHOT-w50PeuPRKj2lhawCI6FEOyYVKntL5Mq-6OUPkpIkeh4.jar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625121804-900480-y9aae5n7.1687695484.900812/beam-sdks-java-io-expansion-service-2.49.0-SNAPSHOT-w50PeuPRKj2lhawCI6FEOyYVKntL5Mq-6OUPkpIkeh4.jar in 2 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625121804-900480-y9aae5n7.1687695484.900812/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625121804-900480-y9aae5n7.1687695484.900812/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-0625121804-900480-y9aae5n7.1687695484.900812/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-0625121804-900480-y9aae5n7.1687695484.900812/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20230625121804901829-1046' createTime: '2023-06-25T12:18:08.600069Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2023-06-25_05_18_08-6892070133548480831' location: 'us-central1' name: 'beamapp-jenkins-0625121804-900480-y9aae5n7' projectId: 'apache-beam-testing' stageStates: [] startTime: '2023-06-25T12:18:08.600069Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_BATCH, 1)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2023-06-25_05_18_08-6892070133548480831] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2023-06-25_05_18_08-6892070133548480831 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-06-25_05_18_08-6892070133548480831?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-06-25_05_18_08-6892070133548480831 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:12.236Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-a. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:13.649Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:13.676Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:13.740Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:13.801Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:13.828Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:13.869Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:13.900Z: 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-06-25T12:18:13.934Z: 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-06-25T12:18:13.959Z: 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-06-25T12:18:13.993Z: 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-06-25T12:18:14.015Z: 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-06-25T12:18:14.049Z: JOB_MESSAGE_DETAILED: Fusing consumer Count records into ReadFromKafka/Remove Kafka Metadata/ParMultiDo(Anonymous) INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.083Z: JOB_MESSAGE_DETAILED: Fusing consumer Measure time into Count records INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.127Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.158Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.183Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.215Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.338Z: JOB_MESSAGE_DEBUG: Executing wait step start10 INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.394Z: 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-06-25T12:18:14.438Z: JOB_MESSAGE_DEBUG: Starting **** pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:14.469Z: JOB_MESSAGE_BASIC: Starting 5 ****s in us-central1-a... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2023-06-25_05_18_08-6892070133548480831 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:18:32.153Z: 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-06-25T12:19:10.005Z: 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-06-25T12:21:13.905Z: JOB_MESSAGE_DETAILED: Workers have started successfully. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:23:09.318Z: JOB_MESSAGE_DETAILED: All ****s have finished the startup processes and began to receive work requests. INFO:apache_beam.runners.dataflow.dataflow_runner:2023-06-25T12:23:12.964Z: 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-06-25T12:23:13.028Z: 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-06-25T12:23:13.102Z: 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-06-25T12:38:33.187Z: JOB_MESSAGE_ERROR: java.lang.IllegalStateException: Last attempted offset should not be null. No work was claimed in non-empty range [99958934, 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:315) at org.apache.beam.fn.harness.data.PCollectionConsumerRegistry$MetricTrackingFnDataReceiver.accept(PCollectionConsumerRegistry.java:246) 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:150) at org.apache.beam.fn.harness.control.BeamFnControlClient$InboundObserver.lambda$onNext$0(BeamFnControlClient.java:115) 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-06-25_05_18_08-6892070133548480831 after 1504 seconds INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Load test results for test: c8ed9b1b94424ccb8c03ecf8d9298155 and timestamp: 1687696995.1343746: INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: read_count_records_total_messages Value: 99958934 INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: read_runtime Value: 242 Traceback (most recent call last): File "/usr/lib/python3.8/runpy.py", line 194, in _run_module_as_main return _run_code(code, main_globals, None, File "/usr/lib/python3.8/runpy.py", line 87, 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 50m 52s 15 actionable tasks: 5 executed, 10 up-to-date Publishing build scan... https://ge.apache.org/s/pe2qre5filc4m 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]
