steveloughran commented on PR #7882: URL: https://github.com/apache/hadoop/pull/7882#issuecomment-3304013014
I've attached a log of a test run against an s3 express bucket where the test `ITestAWSStatisticCollection.testSDKMetricsCostOfGetFileStatusOnFile()` is failing because the AWS SDK stats report 2 http requests for the probe. I'd thought it was create-session related but it isn't: it looks like somehow the stream is broken. This happens reliably on every test runs. The relevant stuff is at line 564 where a HEAD request fails because the stream is broken "end of stream". ``` 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "HEAD /test/testSDKMetricsCostOfGetFileStatusOnFile HTTP/1.1[\r][\n]" 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "Host: stevel--usw2-az1--x-s3.s3express-usw2-az1.us-west-2.amazonaws.com[\r][\n]" 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "amz-sdk-invocation-id: 1804bbcd-04de-cba8-8055-6a09917ca20d[\r][\n]" 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "amz-sdk-request: attempt=1; max=3[\r][\n]" 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "Authorization: AWS4-HMAC-SHA256 Credential=AKIA/20250917/us-west-2/s3express/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;referer;x-amz-content-sha256;x-amz-date, Signature=228a46bb1d008468d38afd0da0ed7b4c354ab12631a63bf4283cb23dc02527a3[\r][\n]" 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "Referer: https://audit.example.org/hadoop/1/op_get_file_status/cf739331-1f2e-42dd-a5d9-f564d6023a23-00000008/?op=op_get_file_status&p1=test/testSDKMetricsCostOfGetFileStatusOnFile&pr=stevel&ps=282e3c5d-c1bd-4859-94b9-82e77ff225d1&id=cf739331-1f2e-42dd-a5d9-f564d6023a23-00000008&t0=1&fs=cf739331-1f2e-42dd-a5d9-f564d6023a23&t1=1&ts=1758131029311[\r][\n]"; 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "User-Agent: Hadoop 3.5.0-SNAPSHOT aws-sdk-java/2.33.8 md/io#sync md/http#Apache ua/2.1 api/S3#2.33.x os/Mac_OS_X#15.6.1 lang/java#17.0.8 md/OpenJDK_64-Bit_Server_VM#17.0.8+7-LTS md/vendor#Amazon.com_Inc. md/en_GB m/F,G hll/cross-region[\r][\n]" 2025-09-17 18:43:49,313 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "x-amz-content-sha256: UNSIGNED-PAYLOAD[\r][\n]" 2025-09-17 18:43:49,314 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "X-Amz-Date: 20250917T174349Z[\r][\n]" 2025-09-17 18:43:49,314 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "Connection: Keep-Alive[\r][\n]" 2025-09-17 18:43:49,314 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-1 >> "[\r][\n]" 2025-09-17 18:43:49,314 [setup] DEBUG http.wire (Wire.java:wire(87)) - http-outgoing-1 << "end of stream" 2025-09-17 18:43:49,314 [setup] DEBUG awssdk.request (LoggerAdapter.java:debug(125)) - Retryable error detected. Will retry in 51ms. Request attempt number 1 software.amazon.awssdk.core.exception.SdkClientException: Unable to execute HTTP request: The target server failed to respond at software.amazon.awssdk.core.exception.SdkClientException$BuilderImpl.build(SdkClientException.java:130) at software.amazon.awssdk.core.exception.SdkClientException.create(SdkClientException.java:47) ``` The second request always works. ``` 2025-09-17 18:43:49,672 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "HEAD /test/testSDKMetricsCostOfGetFileStatusOnFile HTTP/1.1[\r][\n]" 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "Host: stevel--usw2-az1--x-s3.s3express-usw2-az1.us-west-2.amazonaws.com[\r][\n]" 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "amz-sdk-invocation-id: 1804bbcd-04de-cba8-8055-6a09917ca20d[\r][\n]" 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "amz-sdk-request: attempt=2; max=3[\r][\n]" 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "Authorization: AWS4-HMAC-SHA256 Credential=AKIA/20250917/us-west-2/s3express/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;referer;x-amz-content-sha256;x-amz-date, Signature=920d981fad319228c969f5df7f5c1a3c7e4d3c0e2f45ff53bba73e6cf47c5871[\r][\n]" 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "Referer: https://audit.example.org/hadoop/1/op_get_file_status/cf739331-1f2e-42dd-a5d9-f564d6023a23-00000008/?op=op_get_file_status&p1=test/testSDKMetricsCostOfGetFileStatusOnFile&pr=stevel&ps=282e3c5d-c1bd-4859-94b9-82e77ff225d1&id=cf739331-1f2e-42dd-a5d9-f564d6023a23-00000008&t0=1&fs=cf739331-1f2e-42dd-a5d9-f564d6023a23&t1=1&ts=1758131029311[\r][\n]"; 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "User-Agent: Hadoop 3.5.0-SNAPSHOT aws-sdk-java/2.33.8 md/io#sync md/http#Apache ua/2.1 api/S3#2.33.x os/Mac_OS_X#15.6.1 lang/java#17.0.8 md/OpenJDK_64-Bit_Server_VM#17.0.8+7-LTS md/vendor#Amazon.com_Inc. md/en_GB m/F,G hll/cross-region[\r][\n]" 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "x-amz-content-sha256: UNSIGNED-PAYLOAD[\r][\n]" 2025-09-17 18:43:49,673 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "X-Amz-Date: 20250917T174349Z[\r][\n]" 2025-09-17 18:43:49,674 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "Connection: Keep-Alive[\r][\n]" 2025-09-17 18:43:49,674 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 >> "[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "HTTP/1.1 200 OK[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "server: AmazonS3[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "x-amz-request-id: 01869434dd00019958c6871b05090b3f875a3c90[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "x-amz-id-2: 9GqfbNyMyUs6[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "etag: "6036aaaf62444466bf0a21cc7518f738"[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "accept-ranges: bytes[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "last-modified: Wed, 17 Sep 2025 17:43:49 GMT[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "x-amz-storage-class: EXPRESS_ONEZONE[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "content-type: application/octet-stream[\r][\n]" 2025-09-17 18:43:49,859 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "x-amz-server-side-encryption: AES256[\r][\n]" 2025-09-17 18:43:49,860 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "content-length: 0[\r][\n]" 2025-09-17 18:43:49,860 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "x-amz-expiration: NotImplemented[\r][\n]" 2025-09-17 18:43:49,860 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "date: Wed, 17 Sep 2025 17:43:48 GMT[\r][\n]" 2025-09-17 18:43:49,860 [setup] DEBUG http.wire (Wire.java:wire(73)) - http-outgoing-2 << "[\r][\n]" 2025-09-17 18:43:49,860 [setup] DEBUG awssdk.request (LoggerAdapter.java:debug(105)) - Received successful response: 200, Request ID: ``` Either the request is being rejected (why?) or the connection has gone stale. But why should it happen at exactly the same place on every single test run? [org.apache.hadoop.fs.s3a.statistics.ITestAWSStatisticCollection-output.txt](https://github.com/user-attachments/files/22391405/org.apache.hadoop.fs.s3a.statistics.ITestAWSStatisticCollection-output.txt) -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
