SpringBoot 3.2, JDK 17, Localstack Testcontainer 1.18.3
In the process of upgrading the AWS SQS Client from version 1 to version 2, I can am getting Service returned HTTP status code 500 (Service: Sqs, Status Code: 500, Request ID: null)
Localstack container successfully starts and creates the test queues:
08:45:13.655 [main] INFO tc.localstack/localstack:0.14.3 -- HOSTNAME_EXTERNAL environment variable set to localhost (to match host-routable address for container)
08:45:13.656 [main] INFO tc.localstack/localstack:0.14.3 -- Creating container for image: localstack/localstack:0.14.3
08:45:14.532 [main] INFO tc.localstack/localstack:0.14.3 -- Container localstack/localstack:0.14.3 is starting: ddb6279ac6016f44a9ce38a854abed2eb02cede9f0b998ed55c94d7035c666bf
08:45:14.912 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: Waiting for all LocalStack services to be ready
08:45:15.058 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: 2023-12-06 15:45:15,057 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message.
08:45:15.059 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: 2023-12-06 15:45:15,059 INFO supervisord started with pid 14
08:45:16.065 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: 2023-12-06 15:45:16,063 INFO spawned: 'infra' with pid 19
08:45:17.066 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: 2023-12-06 15:45:17,065 INFO success: infra entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
08:45:17.910 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT:
08:45:17.910 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: LocalStack version: 0.14.3.1
08:45:17.910 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: LocalStack Docker container id: ddb6279ac601
08:45:17.910 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: LocalStack build date: 2022-05-25
08:45:17.910 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: LocalStack build git hash: 496e6015
08:45:17.910 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT:
08:45:17.910 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: Starting edge router (https port 4566)...
08:45:18.909 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: Ready.
08:45:18.909 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: [2023-12-06 15:45:18 +0000] [19] [INFO] Running on https://0.0.0.0:4566 (CTRL + C to quit)
08:45:18.909 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: 2023-12-06T15:45:18.252:INFO:hypercorn.error: Running on https://0.0.0.0:4566 (CTRL + C to quit)
08:45:18.909 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: 2023-12-06T15:45:18.400:INFO:bootstrap.py: Execution of "start_runtime_components" took 1204.98ms
08:45:23.095 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: /usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initaws.d/credential.properties
08:45:23.095 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT:
08:45:23.095 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initaws.d/init.sh
08:45:23.478 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: {
08:45:23.478 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: "QueueUrl": "http://localhost:4566/000000000000/TEST-inbound-q"
08:45:23.478 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: }
08:45:23.869 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: {
08:45:23.869 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: "QueueUrl": "http://localhost:4566/000000000000/TEST-inbound-dlq"
08:45:23.869 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: }
08:45:24.246 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: {
08:45:24.246 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: "QueueUrl": "http://localhost:4566/000000000000/TEST-outbound-q"
08:45:24.246 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: }
08:45:24.632 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: {
08:45:24.632 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: "QueueUrl": "http://localhost:4566/000000000000/TEST-outbound-dlq"
08:45:24.632 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: }
08:45:24.675 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT: Initialized.
08:45:24.675 [docker-java-stream--94567791] INFO ContainerTest -- STDOUT:
08:45:24.675 [main] INFO tc.localstack/localstack:0.14.3 -- Container localstack/localstack:0.14.3 started in PT11.0188006S
The client is configured but fails to list queues:
@BeforeAll
public void beforeAllTests() throws URISyntaxException {
String localstackUrl = LOCAL_STACK.getEndpoint().toString();
String localstackRegion = LOCAL_STACK.getRegion();
log.info("LOCALSTACK URL {}, region {}", localstackUrl, localstackRegion);
consumerConfig.setQueue(INBOUND_QUEUE);
publishConfig.setQueue(OUTBOUND_QUEUE);
publishConfig.setDlq(OUTBOUND_DLQ);
sqsClient = SqsClient
.builder()
.region(Region.of(localstackRegion))
.endpointOverride(new URI(localstackUrl))
.credentialsProvider(AwsCredentialsConfig.testingCredentialProvider())
.build();
ListQueuesResponse listQueuesResponse = sqsClient.listQueues();
assertNotNull(listQueuesResponse);
assertEquals(4, listQueuesResponse.queueUrls().size());
}
Failure listing queues:
... Creating an interceptor chain that will apply interceptors in the following order: [software.amazon.awssdk.core.internal.interceptor.HttpChecksumValidationInterceptor@5c807e6b, software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@49bcd90d, software.amazon.awssdk.awscore.eventstream.EventStreamInitialRequestInterceptor@1bb6bc81, software.amazon.awssdk.awscore.interceptor.TraceIdExecutionInterceptor@26c6be2d, software.amazon.awssdk.services.sqs.endpoints.internal.SqsResolveEndpointInterceptor@796affb8, software.amazon.awssdk.services.sqs.endpoints.internal.SqsRequestSetEndpointInterceptor@56313529, software.amazon.awssdk.services.sqs.internal.MessageMD5ChecksumInterceptor@784dd9da]
... Interceptor 'software.amazon.awssdk.services.sqs.endpoints.internal.SqsRequestSetEndpointInterceptor@56313529' modified the message with its modifyHttpRequest method.
... Old: DefaultSdkHttpFullRequest(httpMethod=POST, protocol=http, host=127.0.0.1, port=57717, encodedPath=/, headers=[Content-Length, Content-Type, X-Amz-Target], queryParameters=[])
New: DefaultSdkHttpFullRequest(httpMethod=POST, protocol=http, host=127.0.0.1, port=57717, encodedPath=/, headers=[Content-Length, Content-Type, X-Amz-Target], queryParameters=[])
... Sending Request: DefaultSdkHttpFullRequest(httpMethod=POST, protocol=http, host=127.0.0.1, port=57717, encodedPath=/, headers=[amz-sdk-invocation-id, Content-Length, Content-Type, User-Agent, X-Amz-Target], queryParameters=[])
... Specified InputStream length of 2 has been reached. Returning EOF.
... AWS4 Canonical Request: POST
/
amz-sdk-invocation-id:35415087-6ac5-a478-d62a-ad3491e95abd
amz-sdk-request:attempt=1; max=4
content-length:2
content-type:application/x-amz-json-1.0
host:127.0.0.1:57717
x-amz-date:20231206T154619Z
x-amz-target:AmazonSQS.ListQueues
amz-sdk-invocation-id;amz-sdk-request;content-length;content-type;host;x-amz-date;x-amz-target
44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a
... AWS4 String to sign: AWS4-HMAC-SHA256
20231206T154619Z
20231206/us-east-1/sqs/aws4_request
0586abf345e9ae63408064f5a43f52d51d001c3b5f30ff8d05243663f4c85859
... Generating a new signing key as the signing key not available in the cache for the date: 1701877579077
... NoSuchMethodException was thrown when disabling normalizeUri. This indicates you are using an old version (< 4.5.8) of Apache http client. It is recommended to use http client version >= 4.5.9 to avoid the breaking change introduced in apache client 4.5.7 and the latency in exception handling. See https://github.com/aws/aws-sdk-java/issues/1919 for more information
... Received failed response: 500, Request ID: not available, Extended Request ID: not available
... Received failed response: 500, Request ID: not available, Extended Request ID: not available
... Successfully acquired token bucket capacity to retry this request. Acquired: 5. Remaining: 495
... Retryable error detected. Will retry in 84ms. Request attempt number 2
software.amazon.awssdk.services.sqs.model.SqsException: Service returned HTTP status code 500 (Service: Sqs, Status Code: 500, Request ID: null)
at software.amazon.awssdk.core.internal.http.CombinedResponseHandler.handleErrorResponse(CombinedResponseHandler.java:125)
... Retrying Request: DefaultSdkHttpFullRequest(httpMethod=POST, protocol=http, host=127.0.0.1, port=57717, encodedPath=/, headers=[amz-sdk-invocation-id, Content-Length, Content-Type, User-Agent, X-Amz-Target], queryParameters=[])
... Specified InputStream length of 2 has been reached. Returning EOF.
... AWS4 Canonical Request: POST
/
amz-sdk-invocation-id:35415087-6ac5-a478-d62a-ad3491e95abd
amz-sdk-request:attempt=2; max=4
content-length:2
content-type:application/x-amz-json-1.0
host:127.0.0.1:57717
x-amz-date:20231206T154619Z
x-amz-target:AmazonSQS.ListQueues
amz-sdk-invocation-id;amz-sdk-request;content-length;content-type;host;x-amz-date;x-amz-target
44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a
... AWS4 String to sign: AWS4-HMAC-SHA256
20231206T154619Z
20231206/us-east-1/sqs/aws4_request
6c6bee7d43c0854e6e294b74b4b99d3d3ca00e52be73e4b1569ca991e52c34fa
... Received failed response: 500, Request ID: not available, Extended Request ID: not available
... Received failed response: 500, Request ID: not available, Extended Request ID: not available
... Successfully acquired token bucket capacity to retry this request. Acquired: 5. Remaining: 490
... Retryable error detected. Will retry in 34ms. Request attempt number 3
... STDOUT: 2023-12-06T15:46:19.366:WARNING:localstack.utils.server.http2_server: Error in proxy handler for request POST http://127.0.0.1:57717/: Operation detection failed. Missing Action in request for query-protocol service ServiceModel(sqs). Traceback (most recent call last):
... STDOUT: localstack.aws.protocol.parser.ProtocolParserError: Operation detection failed. Missing Action in request for query-protocol service ServiceModel(sqs).
This is the second microservice that is being upgraded. I did not have this issue with the first microservice which is only a publisher. This microservice is a consumer and publisher. The only difference in the two microservices is the way the container is started.
Publisher only microservice used the @Container to start the localstack container. This microservice statically started the localstack container.
public static LocalStackContainer LOCAL_STACK;
static {
LOCAL_STACK = new LocalStackContainer(DockerImageName.parse("localstack/localstack:0.14.3"))
.withClasspathResourceMapping("/localstack", "/docker-entrypoint-initaws.d", BindMode.READ_ONLY)
.withServices(LocalStackContainer.Service.SQS)
.waitingFor(Wait.forLogMessage(".*Initialized\\.\n", 1))
.withLogConsumer(new Slf4jLogConsumer(log));
LOCAL_STACK.start();
}
@DynamicPropertySource
static void properties(DynamicPropertyRegistry registry) {
registry.add("cloud.aws.sqs.endpoint", () -> LOCAL_STACK.getEndpointOverride(LocalStackContainer.Service.SQS).toString());
registry.add("cloud.aws.credentials.access-key", () -> "foo");
registry.add("cloud.aws.credentials.secret-key", () -> "bar");
registry.add("cloud.aws.region.static", () -> LOCAL_STACK.getRegion());
registry.add("order-queue-name", () -> "test-order-queue");
registry.add(RESOURCE_SERVER + ISSUER_PROP,
() -> String.format(ISSUER_URI, KEYCLOAK_CONTAINER.getHost(), KEYCLOAK_CONTAINER.getHttpPort()));
registry.add(RESOURCE_SERVER + JWK_PROP,
() -> String.format(JWK_URI, KEYCLOAK_CONTAINER.getHost(), KEYCLOAK_CONTAINER.getHttpPort()));
registry.add("aws.localstack-url", () -> LOCAL_STACK.getEndpoint().toString());
registry.add("aws.region", () -> LOCAL_STACK.getRegion());
registry.add("aws.accessKey", () -> LOCAL_STACK.getAccessKey());
registry.add("aws.accessSecret", () -> LOCAL_STACK.getSecretKey());
}
After side by side debugging and some maven forestry, I found that I missed the bom dependency for which I downgraded to client to 2.20.63 to match working microservice.
Of note, I also had to override the endpoint with the localstack URL when building the client. Otherwise, it got a connections to real AWS for getQueueUrl and receiveMessage with a real JWT token.