See <https://ci-beam.apache.org/job/beam_PerformanceTests_xlang_KafkaIO_Python/6/display/redirect>
Changes: ------------------------------------------ [...truncated 86.82 KB...] 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.45.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.45.0-SNAPSHOT.jar'> '35455' '--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.45.0-SNAPSHOT.jar']> INFO:apache_beam.utils.subprocess_server:Starting expansion service at localhost:35455 INFO:apache_beam.utils.subprocess_server:Dec 23, 2022 6:47:33 AM 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:Dec 23, 2022 6:47:35 AM org.apache.beam.sdk.expansion.service.ExpansionService expand INFO:apache_beam.utils.subprocess_server:INFO: Expanding 'WriteToKafka' with URN 'beam:transform:org.apache.beam:kafka_write:v1' INFO:apache_beam.utils.subprocess_server:Dec 23, 2022 6:47:35 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.utils.subprocess_server:Dec 23, 2022 6:47:36 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.45.0.dev INFO:root:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20221205 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20221205" for Docker environment INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function pack_combiners at 0x7fe8782e8050> ==================== INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function sort_stages at 0x7fe8782e8830> ==================== 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-1223064738-704201-85oucntn.1671778058.704589/beam-sdks-java-io-expansion-service-2.45.0-SNAPSHOT-M9S8eOAlbHU32ueZanc7urT7Ut8avVN9__JqfoDn1k8.jar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223064738-704201-85oucntn.1671778058.704589/beam-sdks-java-io-expansion-service-2.45.0-SNAPSHOT-M9S8eOAlbHU32ueZanc7urT7Ut8avVN9__JqfoDn1k8.jar in 3 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223064738-704201-85oucntn.1671778058.704589/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223064738-704201-85oucntn.1671778058.704589/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-1223064738-704201-85oucntn.1671778058.704589/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223064738-704201-85oucntn.1671778058.704589/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20221223064738706227-2426' createTime: '2022-12-23T06:47:42.807480Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2022-12-22_22_47_42-16506662711389082649' location: 'us-central1' name: 'beamapp-jenkins-1223064738-704201-85oucntn' projectId: 'apache-beam-testing' stageStates: [] startTime: '2022-12-23T06:47:42.807480Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_BATCH, 1)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2022-12-22_22_47_42-16506662711389082649] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2022-12-22_22_47_42-16506662711389082649 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/2022-12-22_22_47_42-16506662711389082649?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-12-22_22_47_42-16506662711389082649 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:44.758Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-f. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:45.864Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:45.897Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:45.962Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:45.998Z: 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:2022-12-23T06:47:46.031Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.062Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.102Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.129Z: JOB_MESSAGE_DETAILED: Fusing consumer Generate records/Map(<lambda at iobase.py:908>) into Generate records/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.163Z: 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:2022-12-23T06:47:46.196Z: 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:2022-12-23T06:47:46.231Z: JOB_MESSAGE_DETAILED: Fusing consumer Count records into ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6/ProcessElementAndRestrictionWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.264Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/AddRandomKeys into Count records INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.298Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/Map(reify_timestamps) into Avoid Fusion/AddRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.323Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/Reify into Avoid Fusion/ReshufflePerKey/Map(reify_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.348Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/Write into Avoid Fusion/ReshufflePerKey/GroupByKey/Reify INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.373Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/GroupByWindow into Avoid Fusion/ReshufflePerKey/GroupByKey/Read INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.408Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps) into Avoid Fusion/ReshufflePerKey/GroupByKey/GroupByWindow INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.442Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/RemoveRandomKeys into Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.477Z: JOB_MESSAGE_DETAILED: Fusing consumer Measure time into Avoid Fusion/RemoveRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.509Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToKafka/Kafka ProducerRecord/Map/ParMultiDo(Anonymous) into Measure time INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.531Z: 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:2022-12-23T06:47:46.568Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.596Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.621Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.654Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.781Z: JOB_MESSAGE_DEBUG: Executing wait step start20 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.825Z: 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:2022-12-23T06:47:46.861Z: JOB_MESSAGE_DEBUG: Starting **** pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:47:46.889Z: JOB_MESSAGE_BASIC: Starting 5 ****s in us-central1-f... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-12-22_22_47_42-16506662711389082649 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:48:02.468Z: 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:2022-12-23T06:48:30.786Z: 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:2022-12-23T06:50:28.138Z: JOB_MESSAGE_DETAILED: Workers have started successfully. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:56:33.321Z: JOB_MESSAGE_DETAILED: All ****s have finished the startup processes and began to receive work requests. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:56:35.074Z: 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:2022-12-23T06:56:35.155Z: JOB_MESSAGE_DEBUG: Value "ref_AppliedPTransform_Generate-records-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_6-split-with-sizing-out3" materialized. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:56:35.209Z: JOB_MESSAGE_BASIC: Executing operation Avoid Fusion/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:56:36.581Z: JOB_MESSAGE_BASIC: Finished operation Avoid Fusion/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:56:36.625Z: JOB_MESSAGE_DEBUG: Value "Avoid Fusion/ReshufflePerKey/GroupByKey/Session" materialized. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T06:56:36.672Z: 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:2022-12-23T07:09:52.962Z: 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:2022-12-23T07:09:53.091Z: JOB_MESSAGE_BASIC: Executing operation Avoid Fusion/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:09:53.272Z: JOB_MESSAGE_BASIC: Finished operation Avoid Fusion/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:09:53.309Z: 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:2022-12-23T07:16:25.252Z: 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:2022-12-23T07:16:25.299Z: JOB_MESSAGE_DEBUG: Executing success step success18 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:16:25.349Z: JOB_MESSAGE_DETAILED: Cleaning up. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:16:25.387Z: JOB_MESSAGE_DEBUG: Starting **** pool teardown. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:16:25.411Z: JOB_MESSAGE_BASIC: Stopping **** pool... INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:18:37.415Z: JOB_MESSAGE_DETAILED: Autoscaling: Resized **** pool from 5 to 0. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:18:37.445Z: JOB_MESSAGE_BASIC: Worker pool stopped. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:18:37.470Z: JOB_MESSAGE_DEBUG: Tearing down pending resources... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-12-22_22_47_42-16506662711389082649 is in state JOB_STATE_DONE INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Load test results for test: 1d19436df9d14ec48acfb49795d4a36b and timestamp: 1671779929.5275652: 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: 391 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.45.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.45.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.45.0-SNAPSHOT.jar'> '42543' '--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.45.0-SNAPSHOT.jar']> INFO:apache_beam.utils.subprocess_server:Starting expansion service at localhost:42543 INFO:apache_beam.utils.subprocess_server:Dec 23, 2022 7:18:50 AM 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:Dec 23, 2022 7:18:52 AM 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:Dec 23, 2022 7:18:52 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$Read$External$Configuration' has no schema registered. Attempting to construct with setter approach. INFO:apache_beam.utils.subprocess_server:Dec 23, 2022 7:18:53 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$Read$External$Configuration' has no schema registered. Attempting to construct with setter approach. 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.45.0.dev INFO:root:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20221205 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/python37-fnapi:beam-master-20221205" for Docker environment 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-1223071856-238568-b2g0ontw.1671779936.238935/beam-sdks-java-io-expansion-service-2.45.0-SNAPSHOT-M9S8eOAlbHU32ueZanc7urT7Ut8avVN9__JqfoDn1k8.jar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223071856-238568-b2g0ontw.1671779936.238935/beam-sdks-java-io-expansion-service-2.45.0-SNAPSHOT-M9S8eOAlbHU32ueZanc7urT7Ut8avVN9__JqfoDn1k8.jar in 2 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223071856-238568-b2g0ontw.1671779936.238935/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223071856-238568-b2g0ontw.1671779936.238935/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-1223071856-238568-b2g0ontw.1671779936.238935/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/beamapp-jenkins-1223071856-238568-b2g0ontw.1671779936.238935/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20221223071856240102-9947' createTime: '2022-12-23T07:18:59.827046Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2022-12-22_23_18_59-6198990085284334689' location: 'us-central1' name: 'beamapp-jenkins-1223071856-238568-b2g0ontw' projectId: 'apache-beam-testing' stageStates: [] startTime: '2022-12-23T07:18:59.827046Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_STREAMING, 2)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2022-12-22_23_18_59-6198990085284334689] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2022-12-22_23_18_59-6198990085284334689 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/2022-12-22_23_18_59-6198990085284334689?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-12-22_23_18_59-6198990085284334689 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:06.372Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-b. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.028Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.189Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.264Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.299Z: 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:2022-12-23T07:19:13.334Z: JOB_MESSAGE_DETAILED: Expanding SplittableProcessKeyed operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.364Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into streaming Read/Write steps INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.430Z: JOB_MESSAGE_DETAILED: Lifting ValueCombiningMappingFns into MergeBucketsMappingFns INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.496Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.528Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.550Z: 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:2022-12-23T07:19:13.571Z: 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:2022-12-23T07:19:13.592Z: 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:2022-12-23T07:19:13.624Z: 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:2022-12-23T07:19:13.656Z: 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:2022-12-23T07:19:13.688Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/AddRandomKeys into ReadFromKafka/Remove Kafka Metadata/ParMultiDo(Anonymous) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.732Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/Map(reify_timestamps) into Avoid Fusion/AddRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.755Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/WriteStream into Avoid Fusion/ReshufflePerKey/Map(reify_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.787Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/GroupByKey/MergeBuckets into Avoid Fusion/ReshufflePerKey/GroupByKey/ReadStream INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.809Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps) into Avoid Fusion/ReshufflePerKey/GroupByKey/MergeBuckets INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.831Z: JOB_MESSAGE_DETAILED: Fusing consumer Avoid Fusion/RemoveRandomKeys into Avoid Fusion/ReshufflePerKey/FlatMap(restore_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.852Z: JOB_MESSAGE_DETAILED: Fusing consumer Count records into Avoid Fusion/RemoveRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.883Z: JOB_MESSAGE_DETAILED: Fusing consumer Measure time into Count records INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:13.979Z: JOB_MESSAGE_BASIC: Running job using Streaming Engine INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:14.021Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:14.050Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:14.082Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:14.116Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-12-22_23_18_59-6198990085284334689 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:15.188Z: JOB_MESSAGE_DEBUG: Starting **** pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:15.223Z: JOB_MESSAGE_DEBUG: Starting **** pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:15.244Z: JOB_MESSAGE_BASIC: Starting 5 ****s in us-central1-b... INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:39.672Z: 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:2022-12-23T07:19:48.365Z: JOB_MESSAGE_DETAILED: Autoscaling: Raised the number of ****s to 2 so that the pipeline can catch up with its backlog and keep up with its input rate. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:48.399Z: JOB_MESSAGE_DETAILED: Autoscaling: Resized **** pool to 2, though goal was 5. This could be a quota issue. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:19:57.992Z: JOB_MESSAGE_DETAILED: Autoscaling: Raised the number of ****s to 5 so that the pipeline can catch up with its backlog and keep up with its input rate. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:21:48.343Z: JOB_MESSAGE_DETAILED: Workers have started successfully. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-12-23T07:21:48.397Z: JOB_MESSAGE_DETAILED: All ****s have finished the startup processes and began to receive work requests. WARNING:apache_beam.runners.dataflow.dataflow_runner:Timing out on waiting for job 2022-12-22_23_18_59-6198990085284334689 after 1503 seconds INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Load test results for test: a2d4e8fd81504900bb084976fab6c732 and timestamp: 1671781446.4988072: INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: read_count_records_total_messages Value: 1270022 INFO:apache_beam.testing.load_tests.load_test_metrics_utils:Metric: read_runtime Value: 933 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 144, 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 65, 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 126, 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 58m 5s 15 actionable tasks: 5 executed, 10 up-to-date Publishing build scan... https://gradle.com/s/glkoebicd3szq 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]
