search

spring-attic / spring-cloud-aws

All development has moved to https://github.com/awspring/spring-cloud-aws Integration for Amazon Web Services APIs with Spring
https://awspring.io/
Apache License 2.0
589 stars 376 forks source link

SQS Listener is not listening localstack queue #790

Closed renato04 closed 2 years ago

renato04 commented 2 years ago

Type: Bug

Component: SQS

Describe the bug Hi!

I'm trying to list an SQS queue from localstack but I'm receiving a message that said the queue does not exist.

I don't if this is related to this issue #788 If this is not a bug, I'm sorry.

2021-09-30 10:41:15.273  WARN 25992 --- [           main] i.a.c.m.l.SimpleMessageListenerContainer : Ignoring queue with name 'EVENTS_DEV': The queue does not exist.; nested exception is com.amazonaws.services.sqs.model.QueueDoesNotExistException: The specified queue EVENTS_DEV does not exist for this wsdl version. (Service: AmazonSQS; Status Code: 404; Error Code: AWS.SimpleQueueService.NonExistentQueue; Request ID: IKNNYB2ICCTDT6DXQ15RAP5JCY92NVG1H0LZK69WJWMBXZ1YIFKI; Proxy: null)

If I use AWS CLI the queue is there.

> aws --endpoint http://localhost:4566 sqs get-queue-attributes --queue-url  http://localhost:4566/000000000000/MY_QUEUE
{
    "Attributes": {
        "ApproximateNumberOfMessages": "0",
        "ApproximateNumberOfMessagesDelayed": "0",
        "ApproximateNumberOfMessagesNotVisible": "0",
        "CreatedTimestamp": "1633012559.984967",
        "DelaySeconds": "0",
        "LastModifiedTimestamp": "1633012559.984967",
        "MaximumMessageSize": "262144",
        "MessageRetentionPeriod": "345600",
        "QueueArn": "arn:aws:sqs:sa-east-1:000000000000:MY_QUEUE",
        "ReceiveMessageWaitTimeSeconds": "0",
        "VisibilityTimeout": "30"
    }
}

I don't what I'm missing.

Sample Here is my properties file

cloud.aws.credentials.accessKey=
cloud.aws.credentials.secretKey=
cloud.aws.sns.endpoint=http://localhost:4566
cloud.aws.sns.region=sa-east-1
cloud.aws.sqs.endpoint=http://localhost:4566
cloud.aws.sqs.region=sa-east-1
cloud.aws.credentials.instanceProfile=false
cloud.aws.credentials.useDefaultAwsCredentialsChain=false
cloud.aws.stack.auto=false

aws.queues.event=MY_QUEUE

Here is my bean configuration


@Configuration
public class AWSConfig {
    @Bean
    public QueueMessagingTemplate queueMessagingTemplate(AmazonSQSAsync amazonSQSAsync) {
        return new QueueMessagingTemplate(amazonSQSAsync);
    }
}

And here is my listener code

@Component
public class Listener {

    @SqsListener(value = "${aws.queues.event}", deletionPolicy = SqsMessageDeletionPolicy.NEVER)
    public void listen(String message, Acknowledgment acknowledgment) throws ExecutionException, InterruptedException {
        System.out.printf("Message received %s%n", message );
        acknowledgment.acknowledge().get();
    }
}

Thanks!

nickcaballero commented 2 years ago

Maybe increase the logging level to make sure that the AWS client is using the correct endpoint?

renato04 commented 2 years ago

@nickcaballero how can I do that?

nickcaballero commented 2 years ago

Set logger to debug mode.

logging:
  level:
    'org.apache.http.headers': debug
renato04 commented 2 years ago

@nickcaballero I put logging.level.root=DEBUG and the log is 

3351c7257606045b29c98c1cc66f3592b670e213de1dce6f776cc55e2e6737b"
2021-09-30 15:26:40.957 DEBUG 10008 --- [           main] com.amazonaws.auth.AWS4Signer            : Generating a new signing key as the signing key not available in the cache for the date 1632960000000
2021-09-30 15:26:40.987 DEBUG 10008 --- [           main] o.a.h.client.protocol.RequestAddCookies  : CookieSpec selected: default
2021-09-30 15:26:41.003 DEBUG 10008 --- [           main] o.a.h.client.protocol.RequestAuthCache   : Auth cache not set in the context
2021-09-30 15:26:41.004 DEBUG 10008 --- [           main] h.i.c.PoolingHttpClientConnectionManager : Connection request: [route: {}->http://localhost:4566][total available: 0; route allocated: 0 of 50; total allocated: 0 of 50]
2021-09-30 15:26:41.028 DEBUG 10008 --- [           main] h.i.c.PoolingHttpClientConnectionManager : Connection leased: [id: 0][route: {}->http://localhost:4566][total available: 0; route allocated: 1 of 50; total allocated: 1 of 50]
2021-09-30 15:26:41.031 DEBUG 10008 --- [           main] o.a.http.impl.execchain.MainClientExec   : Opening connection {}->http://localhost:4566
2021-09-30 15:26:41.050 DEBUG 10008 --- [           main] .i.c.DefaultHttpClientConnectionOperator : Connecting to localhost/127.0.0.1:4566
2021-09-30 15:26:41.053 DEBUG 10008 --- [           main] .i.c.DefaultHttpClientConnectionOperator : Connection established 127.0.0.1:62910<->127.0.0.1:4566
2021-09-30 15:26:41.054 DEBUG 10008 --- [           main] h.i.c.DefaultManagedHttpClientConnection : http-outgoing-0: set socket timeout to 50000
2021-09-30 15:26:41.054 DEBUG 10008 --- [           main] o.a.http.impl.execchain.MainClientExec   : Executing request POST / HTTP/1.1
2021-09-30 15:26:41.054 DEBUG 10008 --- [           main] o.a.http.impl.execchain.MainClientExec   : Proxy auth state: UNCHALLENGED
2021-09-30 15:26:41.059 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> POST / HTTP/1.1
2021-09-30 15:26:41.059 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> Host: localhost:4566
2021-09-30 15:26:41.059 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> amz-sdk-invocation-id: 70586d2f-a0df-9715-6535-309298b2d871
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> amz-sdk-request: attempt=1;max=4
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> amz-sdk-retry: 0/0/500
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> Authorization: AWS4-HMAC-SHA256 Credential=Akey/us-east-1/sqs/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;host;user-agent;x-amz-date, Signature=d3924026fe75841a0e57fb74c94d21e79360d95ab9c704aabc2a2aa14361a584
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> User-Agent: aws-sdk-java/1.11.951 Windows_10/10.0 OpenJDK_64-Bit_Server_VM/16.0.1+9-24 java/16.0.1 vendor/Oracle_Corporation, spring-cloud-aws/2.3.0 AmazonSQSBufferedAsyncClient/1.11.951
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> X-Amz-Date: 20210930T182640Z
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> Content-Type: application/x-www-form-urlencoded; charset=utf-8
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> Content-Length: 56
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 >> Connection: Keep-Alive
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "POST / HTTP/1.1[\r][\n]"
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "Host: localhost:4566[\r][\n]"
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "amz-sdk-invocation-id: 70586d2f-a0df-9715-6535-309298b2d871[\r][\n]"
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "amz-sdk-request: attempt=1;max=4[\r][\n]"
2021-09-30 15:26:41.060 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "amz-sdk-retry: 0/0/500[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "Authorization: AWS4-HMAC-SHA256 Credential=key/20210930/us-east-1/sqs/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;host;user-agent;x-amz-date, Signature=d3924026fe75841a0e57fb74c94d21e79360d95ab9c704aabc2a2aa14361a584[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "User-Agent: aws-sdk-java/1.11.951 Windows_10/10.0 OpenJDK_64-Bit_Server_VM/16.0.1+9-24 java/16.0.1 vendor/Oracle_Corporation, spring-cloud-aws/2.3.0 AmazonSQSBufferedAsyncClient/1.11.951[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "X-Amz-Date: 20210930T182640Z[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "Content-Type: application/x-www-form-urlencoded; charset=utf-8[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "Content-Length: 56[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "[\r][\n]"
2021-09-30 15:26:41.061 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 >> "Action=GetQueueUrl&Version=2012-11-05&QueueName=MY_QUEUE"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "HTTP/1.1 404 [\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "content-type: application/xml[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "content-length: 337[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "x-amzn-errortype: QueueDoesNotExist[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "status: 404[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "x-amzn-requestid: CMDZGU593IM71PPRCPU94ZY1UEY2TU1JIX4NIGH9AZSS8PUE8BBP[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "x-amz-crc32: 3800740876[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "access-control-allow-origin: *[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "access-control-allow-methods: HEAD,GET,PUT,POST,DELETE,OPTIONS,PATCH[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "access-control-allow-headers: authorization,content-type,content-length,content-md5,cache-control,x-amz-content-sha256,x-amz-date,x-amz-security-token,x-amz-user-agent,x-amz-target,x-amz-acl,x-amz-version-id,x-localstack-target,x-amz-tagging,amz-sdk-invocation-id,amz-sdk-request[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "access-control-expose-headers: x-amz-version-id[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "connection: close[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "date: Thu, 30 Sep 2021 18:26:41 GMT[\r][\n]"
2021-09-30 15:26:41.094 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "server: hypercorn-h11[\r][\n]"
2021-09-30 15:26:41.095 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "[\r][\n]"
2021-09-30 15:26:41.098 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << HTTP/1.1 404 
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << content-type: application/xml
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << content-length: 337
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << x-amzn-errortype: QueueDoesNotExist
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << status: 404
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << x-amzn-requestid: CMDZGU593IM71PPRCPU94ZY1UEY2TU1JIX4NIGH9AZSS8PUE8BBP
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << x-amz-crc32: 3800740876
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << access-control-allow-origin: *
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << access-control-allow-methods: HEAD,GET,PUT,POST,DELETE,OPTIONS,PATCH
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << access-control-allow-headers: authorization,content-type,content-length,content-md5,cache-control,x-amz-content-sha256,x-amz-date,x-amz-security-token,x-amz-user-agent,x-amz-target,x-amz-acl,x-amz-version-id,x-localstack-target,x-amz-tagging,amz-sdk-invocation-id,amz-sdk-request
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << access-control-expose-headers: x-amz-version-id
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << connection: close
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << date: Thu, 30 Sep 2021 18:26:41 GMT
2021-09-30 15:26:41.099 DEBUG 10008 --- [           main] org.apache.http.headers                  : http-outgoing-0 << server: hypercorn-h11
2021-09-30 15:26:41.106 DEBUG 10008 --- [           main] com.amazonaws.retry.ClockSkewAdjuster    : Reported server date (from 'Date' header): Thu, 30 Sep 2021 18:26:41 GMT
2021-09-30 15:26:41.116 DEBUG 10008 --- [           main] org.apache.http.wire                     : http-outgoing-0 << "<ErrorResponse xmlns="http://queue.amazonaws.com/doc/2012-11-05/"><Error><Type>Sender</Type><Code>AWS.SimpleQueueService.NonExistentQueue</Code><Message>The specified queue MY_QUEUE does not exist for this wsdl version.</Message><Detail/></Error><RequestId>CMDZGU593IM71PPRCPU94ZY1UEY2TU1JIX4NIGH9AZSS8PUE8BBP</RequestId></ErrorResponse>"
2021-09-30 15:26:41.116 DEBUG 10008 --- [           main] h.i.c.DefaultManagedHttpClientConnection : http-outgoing-0: Close connection
2021-09-30 15:26:41.118 DEBUG 10008 --- [           main] o.a.http.impl.execchain.MainClientExec   : Connection discarded
2021-09-30 15:26:41.118 DEBUG 10008 --- [           main] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 0][route: {}->http://localhost:4566][total available: 0; route allocated: 0 of 50; total allocated: 0 of 50]
2021-09-30 15:26:41.154 DEBUG 10008 --- [           main] com.amazonaws.util.XpathUtils            : Ingore failure in speeding up DTMManager
renato04 commented 2 years ago

I've changed the bean configuration to this

@Configuration
public class AWSConfig {
    @Bean
    public QueueMessagingTemplate queueMessagingTemplate(AmazonSQSAsync sqs) {
        return new QueueMessagingTemplate(sqs);
    }

    @Bean
    @Primary
    public AmazonSQSAsync amazonSQSAsync() {
        return AmazonSQSAsyncClientBuilder.standard()
            .withEndpointConfiguration(new AwsClientBuilder.EndpointConfiguration("http://localhost:4566", "sa-east-1"))
            .withCredentials(new AWSStaticCredentialsProvider(new BasicAWSCredentials("accessKey", "secretKey")))
            .build();
    }
}

And now It worked.

Thanks!

nickcaballero commented 2 years ago

Looking at the logs, it did send your request to localhost:4566. Were you able to determine what was wrong?

renato04 commented 2 years ago

@nickcaballero I'm running localstack with 'sa-east-1' default region. Using the logs I realized the region in the headers was 

Authorization: AWS4-HMAC-SHA256 Credential=key/20210930/us-east-1/sqs/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;host;user-agent;x-amz-date, Signature=d3924026fe75841a0e57fb74c94d21e79360d95ab9c704aabc2a2aa14361a584[\r][\n]

As you can see the region in the was us-east-1.

After I changed the AmazonSQSAsync to my bean as primary (just like this) I realized the bean created by the framework has not the region overridden.

I think this can be a bug, So I opened another issue