See <https://ci-beam.apache.org/job/beam_python_mongoio_load_test/4148/display/redirect>
Changes: ------------------------------------------ [...truncated 38.47 KB...] Using cached oauthlib-3.2.2-py3-none-any.whl (151 kB) Building wheels for collected packages: apache-beam Building wheel for apache-beam (setup.py): started Building wheel for apache-beam (setup.py): finished with status 'done' Created wheel for apache-beam: filename=apache_beam-2.44.0.dev0-py3-none-any.whl size=2904788 sha256=7ea0cf15cfd13e14c85b34b332e5868b76738f45baf9c6bdde9e4d6f82c0ec08 Stored in directory: /home/jenkins/.cache/pip/wheels/31/63/74/6fb38e74fff3954a4c3f4997593b9c08658cb7935c4cd90455 Successfully built apache-beam Installing collected packages: sortedcontainers, pytz, pyasn1, parameterized, iniconfig, docopt, crcmod, zstandard, wrapt, websocket-client, urllib3, typing-extensions, tomli, threadpoolctl, tenacity, sqlparse, scipy, rsa, regex, pyyaml, python-dateutil, pymysql, pymongo, pyhamcrest, pydot, pycparser, pyasn1-modules, pyarrow, psycopg2-binary, proto-plus, pbr, overrides, orjson, objsize, oauthlib, joblib, jmespath, isodate, idna, httplib2, greenlet, googleapis-common-protos, google-crc32c, fasteners, fastavro, execnet, exceptiongroup, dill, cloudpickle, charset-normalizer, certifi, cachetools, attrs, sqlalchemy, scikit-learn, requests, pandas, oauth2client, mock, hypothesis, grpcio-status, google-resumable-media, google-auth, freezegun, deprecation, cffi, botocore, s3transfer, requests-oauthlib, requests_mock, pytest, hdfs, grpc-google-iam-v1, google-auth-httplib2, google-apitools, google-api-core, docker, cryptography, azure-core, testcontainers, pytest-timeout, pytest-forked, msrest, google-cloud-core, boto3, apache-beam, pytest-xdist, google-cloud-vision, google-cloud-videointelligence, google-cloud-spanner, google-cloud-recommendations-ai, google-cloud-pubsub, google-cloud-language, google-cloud-dlp, google-cloud-datastore, google-cloud-bigtable, google-cloud-bigquery-storage, azure-storage-blob, google-cloud-pubsublite, google-cloud-bigquery Successfully installed apache-beam-2.44.0.dev0 attrs-22.1.0 azure-core-1.26.0 azure-storage-blob-12.14.1 boto3-1.25.4 botocore-1.28.4 cachetools-4.2.4 certifi-2022.9.24 cffi-1.15.1 charset-normalizer-2.1.1 cloudpickle-2.2.0 crcmod-1.7 cryptography-38.0.1 deprecation-2.1.0 dill-0.3.1.1 docker-6.0.0 docopt-0.6.2 exceptiongroup-1.0.0 execnet-1.9.0 fastavro-1.7.0 fasteners-0.18 freezegun-1.2.2 google-api-core-2.10.2 google-apitools-0.5.31 google-auth-2.13.0 google-auth-httplib2-0.1.0 google-cloud-bigquery-3.3.5 google-cloud-bigquery-storage-2.13.2 google-cloud-bigtable-1.7.2 google-cloud-core-2.3.2 google-cloud-datastore-1.15.5 google-cloud-dlp-3.9.2 google-cloud-language-1.3.2 google-cloud-pubsub-2.13.10 google-cloud-pubsublite-1.6.0 google-cloud-recommendations-ai-0.7.1 google-cloud-spanner-3.22.2 google-cloud-videointelligence-1.16.3 google-cloud-vision-3.1.4 google-crc32c-1.5.0 google-resumable-media-2.4.0 googleapis-common-protos-1.56.4 greenlet-1.1.3.post0 grpc-google-iam-v1-0.12.4 grpcio-status-1.48.2 hdfs-2.7.0 httplib2-0.20.4 hypothesis-6.56.4 idna-3.4 iniconfig-1.1.1 isodate-0.6.1 jmespath-1.0.1 joblib-1.2.0 mock-2.0.0 msrest-0.7.1 oauth2client-4.1.3 oauthlib-3.2.2 objsize-0.5.2 orjson-3.8.1 overrides-6.5.0 pandas-1.3.5 parameterized-0.8.1 pbr-5.11.0 proto-plus-1.22.1 psycopg2-binary-2.9.5 pyarrow-9.0.0 pyasn1-0.4.8 pyasn1-modules-0.2.8 pycparser-2.21 pydot-1.4.2 pyhamcrest-1.10.1 pymongo-3.12.3 pymysql-1.0.2 pytest-7.2.0 pytest-forked-1.4.0 pytest-timeout-2.1.0 pytest-xdist-2.5.0 python-dateutil-2.8.2 pytz-2022.5 pyyaml-6.0 regex-2022.9.13 requests-2.28.1 requests-oauthlib-1.3.1 requests_mock-1.10.0 rsa-4.9 s3transfer-0.6.0 scikit-learn-1.0.2 scipy-1.7.3 sortedcontainers-2.4.0 sqlalchemy-1.4.42 sqlparse-0.4.3 tenacity-5.1.5 testcontainers-3.7.0 threadpoolctl-3.1.0 tomli-2.0.1 typing-extensions-4.4.0 urllib3-1.26.12 websocket-client-1.4.1 wrapt-1.14.1 zstandard-0.19.0 > Task :sdks:python:test-suites:dataflow:py37:mongodbioIT INFO:__main__:Writing 1000000 documents to mongodb <https://ci-beam.apache.org/job/beam_python_mongoio_load_test/ws/src/build/gradleenv/-1734967052/lib/python3.7/site-packages/apache_beam/io/mongodbio_it_test.py>:80: FutureWarning: WriteToMongoDB is experimental. known_args.batch_size)) INFO:apache_beam.runners.portability.stager:Copying Beam SDK "<https://ci-beam.apache.org/job/beam_python_mongoio_load_test/ws/src/sdks/python/build/apache-beam.tar.gz";> to staging location. INFO:root:Default Python SDK image for environment is apache/beam_python3.7_sdk:2.44.0.dev INFO:root:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/python37:beam-master-20221021 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/python37:beam-master-20221021" for Docker environment INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function pack_combiners at 0x7fb41e774560> ==================== INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function sort_stages at 0x7fb41e774d40> ==================== INFO:apache_beam.runners.dataflow.internal.apiclient:Defaulting to the temp_location as staging_location: gs://temp-storage-for-perf-tests/loadtests 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/loadtests/beamapp-jenkins-1030144509-222738-t4aai4bb.1667141109.223100/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/loadtests/beamapp-jenkins-1030144509-222738-t4aai4bb.1667141109.223100/dataflow_python_sdk.tar in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/loadtests/beamapp-jenkins-1030144509-222738-t4aai4bb.1667141109.223100/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/loadtests/beamapp-jenkins-1030144509-222738-t4aai4bb.1667141109.223100/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20221030144509223989-4267' createTime: '2022-10-30T14:45:10.317026Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2022-10-30_07_45_09-17007307604871309625' location: 'us-central1' name: 'beamapp-jenkins-1030144509-222738-t4aai4bb' projectId: 'apache-beam-testing' stageStates: [] startTime: '2022-10-30T14:45:10.317026Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_BATCH, 1)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2022-10-30_07_45_09-17007307604871309625] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2022-10-30_07_45_09-17007307604871309625 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-10-30_07_45_09-17007307604871309625?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-10-30_07_45_09-17007307604871309625 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:09.929Z: JOB_MESSAGE_BASIC: Dataflow Runner V2 auto-enabled. Use --experiments=disable_runner_v2 to opt out. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:10.665Z: JOB_MESSAGE_DETAILED: Autoscaling is enabled for job 2022-10-30_07_45_09-17007307604871309625. The number of workers will be between 1 and 1000. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:10.715Z: JOB_MESSAGE_DETAILED: Autoscaling was automatically enabled for job 2022-10-30_07_45_09-17007307604871309625. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:12.681Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-b. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.603Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.630Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.707Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.742Z: JOB_MESSAGE_DEBUG: Combiner lifting skipped for step WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey: GroupByKey not followed by a combiner. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.777Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.805Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.837Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.863Z: JOB_MESSAGE_DETAILED: Fusing consumer Create/FlatMap(<lambda at core.py:3481>) into Create/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.895Z: JOB_MESSAGE_DETAILED: Fusing consumer Create/Map(decode) into Create/FlatMap(<lambda at core.py:3481>) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.928Z: JOB_MESSAGE_DETAILED: Fusing consumer Create documents into Create/Map(decode) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.965Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/ParDo(_GenerateObjectIdFn) into Create documents INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:13.990Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/Reshuffle/AddRandomKeys into WriteToMongoDB/ParDo(_GenerateObjectIdFn) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.020Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/Reshuffle/ReshufflePerKey/Map(reify_timestamps) into WriteToMongoDB/Reshuffle/AddRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.044Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Reify into WriteToMongoDB/Reshuffle/ReshufflePerKey/Map(reify_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.071Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Write into WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Reify INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.097Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/GroupByWindow into WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Read INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.120Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/Reshuffle/ReshufflePerKey/FlatMap(restore_timestamps) into WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/GroupByWindow INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.153Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/Reshuffle/RemoveRandomKeys into WriteToMongoDB/Reshuffle/ReshufflePerKey/FlatMap(restore_timestamps) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.175Z: JOB_MESSAGE_DETAILED: Fusing consumer WriteToMongoDB/ParDo(_WriteMongoFn) into WriteToMongoDB/Reshuffle/RemoveRandomKeys INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.204Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.232Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.267Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.299Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.430Z: JOB_MESSAGE_DEBUG: Executing wait step start13 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.494Z: JOB_MESSAGE_BASIC: Executing operation WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.537Z: JOB_MESSAGE_DEBUG: Starting worker pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.559Z: JOB_MESSAGE_BASIC: Starting 5 workers in us-central1-b... INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:14.982Z: JOB_MESSAGE_BASIC: Finished operation WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Create INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:15.039Z: JOB_MESSAGE_DEBUG: Value "WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Session" materialized. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:15.093Z: JOB_MESSAGE_BASIC: Executing operation Create/Impulse+Create/FlatMap(<lambda at core.py:3481>)+Create/Map(decode)+Create documents+WriteToMongoDB/ParDo(_GenerateObjectIdFn)+WriteToMongoDB/Reshuffle/AddRandomKeys+WriteToMongoDB/Reshuffle/ReshufflePerKey/Map(reify_timestamps)+WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Reify+WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Write INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-10-30_07_45_09-17007307604871309625 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:37.800Z: 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-10-30T14:45:56.902Z: JOB_MESSAGE_DETAILED: Autoscaling: Raised the number of workers to 1 based on the rate of progress in the currently running stage(s). INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:45:56.927Z: JOB_MESSAGE_DETAILED: Autoscaling: Resized worker pool to 1, though goal was 5. This could be a quota issue. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:46:07.193Z: JOB_MESSAGE_DETAILED: Autoscaling: Raised the number of workers to 5 based on the rate of progress in the currently running stage(s). INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:46:07.212Z: JOB_MESSAGE_DETAILED: Autoscaling: Would further reduce the number of workers but reached the minimum number allowed for the job. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:46:28.839Z: JOB_MESSAGE_DETAILED: Workers have started successfully. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:48:44.661Z: JOB_MESSAGE_DETAILED: Autoscaling: Reduced the number of workers to 1 based on the rate of progress in the currently running stage(s). INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:48:44.685Z: JOB_MESSAGE_DETAILED: Autoscaling: Would further reduce the number of workers but reached the minimum number allowed for the job. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:48:49.714Z: JOB_MESSAGE_DETAILED: Autoscaling: Resizing worker pool from 5 to 1. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:50:25.645Z: JOB_MESSAGE_BASIC: Finished operation Create/Impulse+Create/FlatMap(<lambda at core.py:3481>)+Create/Map(decode)+Create documents+WriteToMongoDB/ParDo(_GenerateObjectIdFn)+WriteToMongoDB/Reshuffle/AddRandomKeys+WriteToMongoDB/Reshuffle/ReshufflePerKey/Map(reify_timestamps)+WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Reify+WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Write INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:50:25.690Z: JOB_MESSAGE_BASIC: Executing operation WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:50:25.743Z: JOB_MESSAGE_BASIC: Finished operation WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Close INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:50:25.781Z: JOB_MESSAGE_BASIC: Executing operation WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Read+WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/GroupByWindow+WriteToMongoDB/Reshuffle/ReshufflePerKey/FlatMap(restore_timestamps)+WriteToMongoDB/Reshuffle/RemoveRandomKeys+WriteToMongoDB/ParDo(_WriteMongoFn) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:52:13.532Z: JOB_MESSAGE_BASIC: Finished operation WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/Read+WriteToMongoDB/Reshuffle/ReshufflePerKey/GroupByKey/GroupByWindow+WriteToMongoDB/Reshuffle/ReshufflePerKey/FlatMap(restore_timestamps)+WriteToMongoDB/Reshuffle/RemoveRandomKeys+WriteToMongoDB/ParDo(_WriteMongoFn) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:52:13.574Z: JOB_MESSAGE_DEBUG: Executing success step success11 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:52:13.622Z: JOB_MESSAGE_DETAILED: Cleaning up. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:52:13.660Z: JOB_MESSAGE_DEBUG: Starting worker pool teardown. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:52:13.686Z: JOB_MESSAGE_BASIC: Stopping worker pool... INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:26.262Z: JOB_MESSAGE_DETAILED: Autoscaling: Resized worker pool from 1 to 0. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:26.301Z: JOB_MESSAGE_BASIC: Worker pool stopped. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:26.322Z: JOB_MESSAGE_DEBUG: Tearing down pending resources... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-10-30_07_45_09-17007307604871309625 is in state JOB_STATE_DONE INFO:__main__:Writing 1000000 documents to mongodb finished in 567.080 seconds INFO:__main__:================================================================================ INFO:__main__:Reading from mongodb beam_mongodbio_it_db:integration_test_1667141108 INFO:__main__:reader params : {'projection': ['number']} INFO:__main__:expected results: {'number_sum': 499999500000, 'docs_count': 1000000} <https://ci-beam.apache.org/job/beam_python_mongoio_load_test/ws/src/build/gradleenv/-1734967052/lib/python3.7/site-packages/apache_beam/io/mongodbio_it_test.py>:153: FutureWarning: ReadFromMongoDB is experimental. | 'Map' >> beam.Map(lambda doc: doc['number'])) INFO:apache_beam.runners.portability.stager:Copying Beam SDK "<https://ci-beam.apache.org/job/beam_python_mongoio_load_test/ws/src/sdks/python/build/apache-beam.tar.gz";> to staging location. INFO:root:Default Python SDK image for environment is apache/beam_python3.7_sdk:2.44.0.dev INFO:root:Using provided Python SDK container image: gcr.io/cloud-dataflow/v1beta3/python37:beam-master-20221021 INFO:root:Python SDK container image set to "gcr.io/cloud-dataflow/v1beta3/python37:beam-master-20221021" for Docker environment INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function pack_combiners at 0x7fb41e774560> ==================== INFO:apache_beam.runners.portability.fn_api_runner.translations:==================== <function sort_stages at 0x7fb41e774d40> ==================== INFO:apache_beam.runners.dataflow.internal.apiclient:Defaulting to the temp_location as staging_location: gs://temp-storage-for-perf-tests/loadtests INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/loadtests/beamapp-jenkins-1030145437-026210-q7nym3yc.1667141677.026561/dataflow_python_sdk.tar... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/loadtests/beamapp-jenkins-1030145437-026210-q7nym3yc.1667141677.026561/dataflow_python_sdk.tar in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Starting GCS upload to gs://temp-storage-for-perf-tests/loadtests/beamapp-jenkins-1030145437-026210-q7nym3yc.1667141677.026561/pipeline.pb... INFO:apache_beam.runners.dataflow.internal.apiclient:Completed GCS upload to gs://temp-storage-for-perf-tests/loadtests/beamapp-jenkins-1030145437-026210-q7nym3yc.1667141677.026561/pipeline.pb in 0 seconds. INFO:apache_beam.runners.dataflow.internal.apiclient:Create job: <Job clientRequestId: '20221030145437027386-2712' createTime: '2022-10-30T14:54:38.423501Z' currentStateTime: '1970-01-01T00:00:00Z' id: '2022-10-30_07_54_37-3904492405727000119' location: 'us-central1' name: 'beamapp-jenkins-1030145437-026210-q7nym3yc' projectId: 'apache-beam-testing' stageStates: [] startTime: '2022-10-30T14:54:38.423501Z' steps: [] tempFiles: [] type: TypeValueValuesEnum(JOB_TYPE_BATCH, 1)> INFO:apache_beam.runners.dataflow.internal.apiclient:Created job with id: [2022-10-30_07_54_37-3904492405727000119] INFO:apache_beam.runners.dataflow.internal.apiclient:Submitted job: 2022-10-30_07_54_37-3904492405727000119 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-10-30_07_54_37-3904492405727000119?project=apache-beam-testing INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-10-30_07_54_37-3904492405727000119 is in state JOB_STATE_PENDING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:38.003Z: JOB_MESSAGE_BASIC: Dataflow Runner V2 auto-enabled. Use --experiments=disable_runner_v2 to opt out. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:38.844Z: JOB_MESSAGE_DETAILED: Autoscaling is enabled for job 2022-10-30_07_54_37-3904492405727000119. The number of workers will be between 1 and 1000. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:38.972Z: JOB_MESSAGE_DETAILED: Autoscaling was automatically enabled for job 2022-10-30_07_54_37-3904492405727000119. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:40.997Z: JOB_MESSAGE_BASIC: Worker configuration: e2-standard-2 in us-central1-b. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.100Z: JOB_MESSAGE_DETAILED: Expanding SplittableParDo operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.124Z: JOB_MESSAGE_DETAILED: Expanding CollectionToSingleton operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.205Z: JOB_MESSAGE_DETAILED: Expanding CoGroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.243Z: JOB_MESSAGE_DEBUG: Combiner lifting skipped for step assert_that/Group/CoGroupByKeyImpl/GroupByKey: GroupByKey not followed by a combiner. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.348Z: JOB_MESSAGE_DETAILED: Expanding GroupByKey operations into optimizable parts. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.377Z: JOB_MESSAGE_DEBUG: Annotating graph with Autotuner information. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.416Z: JOB_MESSAGE_DETAILED: Fusing adjacent ParDo, Read, Write, and Flatten operations INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.436Z: JOB_MESSAGE_DEBUG: Inserted coder converter before flatten ref_AppliedPTransform_Flatten_34 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.472Z: JOB_MESSAGE_DEBUG: Inserted coder converter after flatten ref_AppliedPTransform_assert_that-Group-CoGroupByKeyImpl-Flatten_47 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.506Z: JOB_MESSAGE_DETAILED: Unzipping flatten ref_AppliedPTransform_assert_that-Group-CoGroupByKeyImpl-Flatten_47 for input ref_AppliedPTransform_assert_that-Group-CoGroupByKeyImpl-Tag-0-_45.None INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.534Z: JOB_MESSAGE_DETAILED: Fusing unzipped copy of assert_that/Group/CoGroupByKeyImpl/Flatten/OutputIdentity, through flatten assert_that/Group/CoGroupByKeyImpl/Flatten, into producer assert_that/Group/CoGroupByKeyImpl/Tag[0] INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.571Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Group/CoGroupByKeyImpl/MapTuple(collect_values) into assert_that/Group/CoGroupByKeyImpl/GroupByKey/Read INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.598Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Group/RestoreTags into assert_that/Group/CoGroupByKeyImpl/MapTuple(collect_values) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.623Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Unkey into assert_that/Group/RestoreTags INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.649Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Match into assert_that/Unkey INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.673Z: JOB_MESSAGE_DETAILED: Unzipping flatten ref_AppliedPTransform_assert_that-Group-CoGroupByKeyImpl-Flatten_47-u47 for input ref_AppliedPTransform_assert_that-Group-CoGroupByKeyImpl-Flatten_47.None-c45 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.709Z: JOB_MESSAGE_DETAILED: Fusing unzipped copy of assert_that/Group/CoGroupByKeyImpl/GroupByKey/Write, through flatten assert_that/Group/CoGroupByKeyImpl/Flatten/Unzipped-1, into producer assert_that/Group/CoGroupByKeyImpl/Flatten/OutputIdentity INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.741Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Group/CoGroupByKeyImpl/Flatten/OutputIdentity into assert_that/Group/CoGroupByKeyImpl/Tag[1] INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.766Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Group/CoGroupByKeyImpl/GroupByKey/Write into assert_that/Group/CoGroupByKeyImpl/Flatten/OutputIdentity INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.791Z: JOB_MESSAGE_DETAILED: Unzipping flatten ref_AppliedPTransform_Flatten_34 for input ref_AppliedPTransform_Combine-InjectDefault_20.None INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.828Z: JOB_MESSAGE_DETAILED: Fusing unzipped copy of assert_that/WindowInto(WindowIntoFn), through flatten Flatten, into producer Combine/InjectDefault INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.863Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Group/CoGroupByKeyImpl/Tag[1] into assert_that/ToVoidKey INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.899Z: JOB_MESSAGE_DETAILED: Unzipping flatten ref_AppliedPTransform_Flatten_34-u54 for input ref_AppliedPTransform_assert_that-WindowInto-WindowIntoFn-_41.None-c52 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.935Z: JOB_MESSAGE_DETAILED: Fusing unzipped copy of assert_that/ToVoidKey, through flatten Flatten/Unzipped-1, into producer assert_that/WindowInto(WindowIntoFn) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:42.967Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/KeyWithVoid into Map INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.002Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/KeyWithVoid into Map INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.033Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/WindowInto(WindowIntoFn) into Flatten/InputIdentity INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.065Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/ToVoidKey into assert_that/WindowInto(WindowIntoFn) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.092Z: JOB_MESSAGE_DETAILED: Fusing consumer ReadFromMongoDB/Read/Map(<lambda at iobase.py:908>) into ReadFromMongoDB/Read/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.120Z: JOB_MESSAGE_DETAILED: Fusing consumer ref_AppliedPTransform_ReadFromMongoDB-Read-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_7/PairWithRestriction into ReadFromMongoDB/Read/Map(<lambda at iobase.py:908>) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.153Z: JOB_MESSAGE_DETAILED: Fusing consumer ref_AppliedPTransform_ReadFromMongoDB-Read-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_7/SplitWithSizing into ref_AppliedPTransform_ReadFromMongoDB-Read-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_7/PairWithRestriction INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.187Z: JOB_MESSAGE_DETAILED: Fusing consumer Map into ref_AppliedPTransform_ReadFromMongoDB-Read-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_7/ProcessElementAndRestrictionWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.224Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/CombinePerKey/GroupByKey+Combine/CombinePerKey/Combine/Partial into Combine/KeyWithVoid INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.259Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/CombinePerKey/GroupByKey/Write into Combine/CombinePerKey/GroupByKey+Combine/CombinePerKey/Combine/Partial INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.297Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/CombinePerKey/Combine into Combine/CombinePerKey/GroupByKey/Read INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.331Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/CombinePerKey/Combine/Extract into Combine/CombinePerKey/Combine INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.361Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/UnKey into Combine/CombinePerKey/Combine/Extract INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.390Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/CombinePerKey/GroupByKey+Count/CombineGlobally(CountCombineFn)/CombinePerKey/Combine/Partial into Count/CombineGlobally(CountCombineFn)/KeyWithVoid INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.417Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/CombinePerKey/GroupByKey/Write into Count/CombineGlobally(CountCombineFn)/CombinePerKey/GroupByKey+Count/CombineGlobally(CountCombineFn)/CombinePerKey/Combine/Partial INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.442Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/CombinePerKey/Combine into Count/CombineGlobally(CountCombineFn)/CombinePerKey/GroupByKey/Read INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.474Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/CombinePerKey/Combine/Extract into Count/CombineGlobally(CountCombineFn)/CombinePerKey/Combine INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.501Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/UnKey into Count/CombineGlobally(CountCombineFn)/CombinePerKey/Combine/Extract INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.524Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/DoOnce/FlatMap(<lambda at core.py:3481>) into Combine/DoOnce/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.556Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/DoOnce/Map(decode) into Combine/DoOnce/FlatMap(<lambda at core.py:3481>) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.582Z: JOB_MESSAGE_DETAILED: Fusing consumer Combine/InjectDefault into Combine/DoOnce/Map(decode) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.606Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/DoOnce/FlatMap(<lambda at core.py:3481>) into Count/CombineGlobally(CountCombineFn)/DoOnce/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.630Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/DoOnce/Map(decode) into Count/CombineGlobally(CountCombineFn)/DoOnce/FlatMap(<lambda at core.py:3481>) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.654Z: JOB_MESSAGE_DETAILED: Fusing consumer Count/CombineGlobally(CountCombineFn)/InjectDefault into Count/CombineGlobally(CountCombineFn)/DoOnce/Map(decode) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.681Z: JOB_MESSAGE_DETAILED: Fusing consumer Flatten/InputIdentity into Count/CombineGlobally(CountCombineFn)/InjectDefault INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.717Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Create/FlatMap(<lambda at core.py:3481>) into assert_that/Create/Impulse INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.750Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Create/Map(decode) into assert_that/Create/FlatMap(<lambda at core.py:3481>) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.788Z: JOB_MESSAGE_DETAILED: Fusing consumer assert_that/Group/CoGroupByKeyImpl/Tag[0] into assert_that/Create/Map(decode) INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.850Z: JOB_MESSAGE_DEBUG: Workflow config is missing a default resource spec. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.881Z: JOB_MESSAGE_DEBUG: Adding StepResource setup and teardown to workflow graph. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.915Z: JOB_MESSAGE_DEBUG: Adding workflow start and stop steps. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:43.953Z: JOB_MESSAGE_DEBUG: Assigning stage ids. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:44.114Z: JOB_MESSAGE_DEBUG: Executing wait step start73 INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:44.187Z: JOB_MESSAGE_BASIC: Executing operation ReadFromMongoDB/Read/Impulse+ReadFromMongoDB/Read/Map(<lambda at iobase.py:908>)+ref_AppliedPTransform_ReadFromMongoDB-Read-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_7/PairWithRestriction+ref_AppliedPTransform_ReadFromMongoDB-Read-SDFBoundedSourceReader-ParDo-SDFBoundedSourceDoFn-_7/SplitWithSizing INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:44.233Z: JOB_MESSAGE_DEBUG: Starting worker pool setup. INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:44.267Z: JOB_MESSAGE_BASIC: Starting 5 workers in us-central1-b... INFO:apache_beam.runners.dataflow.dataflow_runner:Job 2022-10-30_07_54_37-3904492405727000119 is in state JOB_STATE_RUNNING INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:54:54.327Z: 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-10-30T14:55:25.753Z: JOB_MESSAGE_DETAILED: Autoscaling: Raised the number of workers to 5 based on the rate of progress in the currently running stage(s). INFO:apache_beam.runners.dataflow.dataflow_runner:2022-10-30T14:55:52.055Z: JOB_MESSAGE_DETAILED: Workers have started successfully. Terminated > Task :sdks:python:test-suites:dataflow:py37:mongodbioIT FAILED The message received from the daemon indicates that the daemon has disappeared. Build request sent: Build{id=cf6a6554-64c1-4ed2-8a21-7767d0e728c7, currentDir=<https://ci-beam.apache.org/job/beam_python_mongoio_load_test/ws/src}> Attempting to read last messages from the daemon log... Daemon pid: 745193 log file: /home/jenkins/.gradle/daemon/7.5.1/daemon-745193.out.log ----- Last 20 lines from daemon log file - daemon-745193.out.log ----- * What went wrong: Execution failed for task ':sdks:python:test-suites:dataflow:py37:mongodbioIT'. > Process 'command 'sh'' finished with non-zero exit value 143 * 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 12m 15 actionable tasks: 9 executed, 4 from cache, 2 up-to-date Daemon vm is shutting down... The daemon has exited normally or was terminated in response to a user interrupt. ----- End of the daemon log ----- FAILURE: Build failed with an exception. * What went wrong: Gradle build daemon disappeared unexpectedly (it may have been killed or may have crashed) * Try: > Run with --stacktrace option to get the stack trace. > Run with --info or --debug option to get more log output. > Run with --scan to get full insights. * Get more help at https://help.gradle.org 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]
