timeout in GCS+gRPC samples

[devbww]

Step #3: * GCB: https://console.cloud.google.com/cloud-build/builds;region=us-east1/b59f23f8-b798-4c38-a0b1-2eba12bc627e;tab=detail?project=cloud-cpp-testing-resources
Step #3: * Raw: https://storage.googleapis.com/cloud-cpp-community-publiclogs/logs/google-cloud-cpp/main/48ea59af1a7372a2c541fe68d41e7a817893207a/fedora-37-bazel-gcs-grpc/log-b59f23f8-b798-4c38-a0b1-2eba12bc627e.txt

[7,520 / 7,521] 266 / 267 tests; Testing //google/cloud/storage/examples:storage_lifecycle_management_samples; 300s linux-sandbox

TIMEOUT: //google/cloud/storage/examples:storage_lifecycle_management_samples (Summary)
      /h/.cache/bazel/_bazel_root/eab0d61a99b6696edb3d2aff87b585e8/execroot/google_cloud_cpp/bazel-out/k8-fastbuild/testlogs/google/cloud/storage/examples/storage_lifecycle_management_samples/test.log
INFO: From Testing //google/cloud/storage/examples:storage_lifecycle_management_samples:
==================== Test output for //google/cloud/storage/examples:storage_lifecycle_management_samples:

Creating bucket to run the examples
-- Test timed out at 2023-05-05 18:42:15 UTC --
================================================================================
INFO: Elapsed time: 330.289s, Critical Path: 303.83s
INFO: 7521 processes: 3793 remote cache hit, 3431 internal, 297 linux-sandbox.
INFO: Build completed, 1 test FAILED, 7521 total actions
    :
//google/cloud/storage/examples:storage_lifecycle_management_samples    TIMEOUT in 300.0s

[devbww]

• GCB: https://console.cloud.google.com/cloud-build/builds;region=us-east1/454e1ebd-bf7c-4916-b54d-570a28795abb;tab=detail?project=cloud-cpp-testing-resources
• Raw: https://storage.googleapis.com/cloud-cpp-community-publiclogs/logs/google-cloud-cpp/main/df444d5d65532990314bde1e02ab82cdf0638451/fedora-37-bazel-gcs-grpc/log-454e1ebd-bf7c-4916-b54d-570a28795abb.txt

[7,520 / 7,521] 266 / 267 tests; Testing //google/cloud/storage/examples:storage_bucket_autoclass_samples; 300s linux-sandbox

TIMEOUT: //google/cloud/storage/examples:storage_bucket_autoclass_samples (Summary)
      /h/.cache/bazel/_bazel_root/eab0d61a99b6696edb3d2aff87b585e8/execroot/google_cloud_cpp/bazel-out/k8-fastbuild/testlogs/google/cloud/storage/examples/storage_bucket_autoclass_samples/test.log
==================== Test output for //google/cloud/storage/examples:storage_bucket_autoclass_samples:

Creating buckets to run the example:
Enabled Autoclass: gcs-grpc-team-cloud-cpp-testing-examples-2023-05-07_z4ewntuuh64
Disabled Autoclass: gcs-grpc-team-cloud-cpp-testing-examples-2023-05-07_jypwgo0ewg4
-- Test timed out at 2023-05-07 22:12:33 UTC --
================================================================================
INFO: From Testing //google/cloud/storage/examples:storage_bucket_autoclass_samples:
INFO: Elapsed time: 325.301s, Critical Path: 304.15s
INFO: 7521 processes: 3792 remote cache hit, 3432 internal, 297 linux-sandbox.
INFO: Build completed, 1 test FAILED, 7521 total actions
    :
//google/cloud/storage/examples:storage_bucket_autoclass_samples        TIMEOUT in 300.0s

[devbww]

• GCB: https://console.cloud.google.com/cloud-build/builds;region=us-east1/db1cc516-5ae9-4986-941e-48291a268c97;tab=detail?project=cloud-cpp-testing-resources
• Raw: https://storage.googleapis.com/cloud-cpp-community-publiclogs/logs/google-cloud-cpp/main/30f2d3566125aa5c9d9792d8dd81c617a64e1804/fedora-37-bazel-gcs-grpc/log-db1cc516-5ae9-4986-941e-48291a268c97.txt

[8,441 / 8,443] 265 / 267 tests; Testing //google/cloud/storage/examples:storage_bucket_requester_pays_samples; 300s linux-sandbox ... (2 actions running) 

TIMEOUT: //google/cloud/storage/examples:storage_bucket_requester_pays_samples (Summary)
      /h/.cache/bazel/_bazel_root/eab0d61a99b6696edb3d2aff87b585e8/execroot/google_cloud_cpp/bazel-out/k8-fastbuild/testlogs/google/cloud/storage/examples/storage_bucket_requester_pays_samples/test.log
INFO: From Testing //google/cloud/storage/examples:storage_bucket_requester_pays_samples:
==================== Test output for //google/cloud/storage/examples:storage_bucket_requester_pays_samples:

Creating bucket to run the example (gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_9p1or8j2qp5)
-- Test timed out at 2023-05-31 02:00:28 UTC --
================================================================================
    :
//google/cloud/storage/examples:storage_bucket_requester_pays_samples   TIMEOUT in 300.0s
  /h/.cache/bazel/_bazel_root/eab0d61a99b6696edb3d2aff87b585e8/execroot/google_cloud_cpp/bazel-out/k8-fastbuild/testlogs/google/cloud/storage/examples/storage_bucket_requester_pays_samples/test.log

Executed 267 out of 267 tests: 266 tests pass and 1 fails locally.

[coryan]

Judging from the logs the tests are timing out while trying to create the buckets. The failure on #11512 (comment) happens after this log line:

google-cloud-cpp/google/cloud/storage/examples/storage_bucket_autoclass_samples.cc

Lines 92 to 94 in 4a0ab4e

	std::cout << "\nCreating buckets to run the example:"
	<< "\nEnabled Autoclass: " << bucket_name_enabled
	<< "\nDisabled Autoclass: " << bucket_name_disabled << std::endl;

The failure earlier today (#11512 (comment)) happens after this log line:

google-cloud-cpp/google/cloud/storage/examples/storage_bucket_requester_pays_samples.cc

Lines 187 to 188 in 4a0ab4e

	std::cout << "\nCreating bucket to run the example (" << bucket_name << ")"
	<< std::endl;

There are calls to CreateBucketForProject() immediately after each log line, and log lines immediately after that function returns.

[coryan]

I think this is unrelated to GCS+gRPC. It just happens that the GCS+gRPC build uses production for these builds. The examples always use REST. I also suspect this may have something to do with the bucket creation rate limits. I was able to repro locally using 16 parallel runs of one sample:

Creating buckets to run the example:
Enabled Autoclass: gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu
Disabled Autoclass: gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_u0l31bczfa4
2023-05-31T20:52:24.905417229Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:52:25.106388415Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
2023-05-31T20:52:26.957754900Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:52:27.036144069Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
2023-05-31T20:52:29.491506050Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:52:29.561417539Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
2023-05-31T20:52:33.565773726Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:52:33.654731505Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
2023-05-31T20:52:48.205089555Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:52:48.279673173Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
2023-05-31T20:53:10.579041247Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:53:10.651556634Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
2023-05-31T20:53:52.081911824Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:53:52.180532650Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
2023-05-31T20:55:41.448903181Z [INFO] <140300068895488> CreateBucket() << CreateBucketRequest={project_id=coryan-test, metadata=BucketMetadata={name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, acl=[], autoclass={enabled=true, toggle_time=1970-01-01T00:00:00Z}, cors=[], default_event_based_hold=false, default_acl=[], etag=, id=, kind=, location=, location_type=, metageneration=0, name=gcs-grpc-team-cloud-cpp-testing-examples-2023-05-31_dhclh7q3uxu, project_number=0, self_link=, storage_class=, time_created=1970-01-01T00:00:00Z, updated=1970-01-01T00:00:00Z, rpo=}} (google/cloud/storage/internal/logging_client.cc:44)
2023-05-31T20:55:41.530007376Z [INFO] <140300068895488> CreateBucket() >> status={UNAVAILABLE: Create Bucket quota limit limit exceeded on the Google Cloud project. Please slow down execution and try again. error_info={reason=rateLimitExceeded, domain=usageLimits, metadata={http_status_code=429}}} (google/cloud/storage/internal/logging_client.cc:49)
-- Test timed out at 2023-05-31 20:57:24 UTC --

[coryan]

No repeats in 90d, closing.