Sqs2EndpointBuilder is not respecting delay - polling continuously

classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|

Sqs2EndpointBuilder is not respecting delay - polling continuously

Brice Burgess
Hi!

I'm a happy new user of Camel and have an `aws2Sqs` route that is
polling a Amazon SQS queue inside a Spring Boot application.

Versions: Spring Boot 2.2.6, Camel 3.2.0

I'm  seeing the connections come through the logs and it appears to be
polling  every 500ms _regardless_ of the delay parameter passed.

I have tried both the EndpointDSL as well as normal Route builder,
with useFixedDelay explicitly passed and without (it defaults to
true).

Is there something I am missing? Or is this a bug?

Many thanks for the guidance. Below is an excerpt from my source

```
// build.gradle
dependencies {
    implementation 'org.apache.camel:camel-endpointdsl:3.2.0'
    implementation 'org.apache.camel.springboot:camel-aws2-sqs-starter:3.2.0'
    ...
}


// EncodeQueueRoute.java
...
@Component
public class EncodeQueueRoute extends EndpointRouteBuilder {
    @Override
    public void configure() {
        from(aws2Sqs("queueName")
                .useFixedDelay(true)
                .delay(5000)
        ).to(file("data/output"));
    }
}
```

You can see the @ 500ms delay in the logs -- the period between
connection release and starting a new one:

```
2020-04-28 23:39:18.229 DEBUG 22578 --- [e-worker-encode]
h.i.c.PoolingHttpClientConnectionManager : Connection released: [id:
0][route: {}->http://localhost:4576][total available: 1; route
allocated: 1 of 50; total allocated: 1 of 50]
2020-04-28 23:39:18.731 DEBUG 22578 --- [e-worker-encode]
s.a.a.c.i.ExecutionInterceptorChain      : Creating an interceptor
chain that will apply interceptors in the following order:
[software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@7e63374b,
software.amazon.awssdk.services.sqs.internal.MessageMD5ChecksumInterceptor@aa794a3,
software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b]
2020-04-28 23:39:18.732 DEBUG 22578 --- [e-worker-encode]
s.a.a.c.i.ExecutionInterceptorChain      : Interceptor
'software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b'
modified the message with its modifyHttpRequest method.
2020-04-28 23:39:18.733 DEBUG 22578 --- [e-worker-encode]
software.amazon.awssdk.request           : Sending Request:
DefaultSdkHttpFullRequest(httpMethod=POST, protocol=http,
host=localhost, port=4576, encodedPath=,
headers=[amz-sdk-invocation-id, Content-Length, Content-Type,
User-Agent], queryParameters=[])
2020-04-28 23:39:18.733 DEBUG 22578 --- [e-worker-encode]
s.amazon.awssdk.auth.signer.Aws4Signer   : AWS4 String to sign:
AWS4-HMAC-SHA256
20200429T033918Z
20200429/us-east-1/sqs/aws4_request
dd1ab3d6875d36005937a3d8aa40ccfcf04a293217c796dc92cef0930d98db85
2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
o.a.h.client.protocol.RequestAddCookies  : CookieSpec selected:
default
2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
o.a.h.client.protocol.RequestAuthCache   : Auth cache not set in the
context
2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
h.i.c.PoolingHttpClientConnectionManager : Connection request: [route:
{}->http://localhost:4576][total available: 1; route allocated: 1 of
50; total allocated: 1 of 50]
2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
h.i.c.PoolingHttpClientConnectionManager : Connection leased: [id:
0][route: {}->http://localhost:4576][total available: 0; route
allocated: 1 of 50; total allocated: 1 of 50]

....

2020-04-28 23:39:18.740 DEBUG 22578 --- [e-worker-encode]
h.i.c.PoolingHttpClientConnectionManager : Connection released: [id:
0][route: {}->http://localhost:4576][total available: 1; route
allocated: 1 of 50; total allocated: 1 of 50]
2020-04-28 23:39:19.243 DEBUG 22578 --- [e-worker-encode]
s.a.a.c.i.ExecutionInterceptorChain      : Creating an interceptor
chain that will apply interceptors in the following order:
[software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@7e63374b,
software.amazon.awssdk.services.sqs.internal.MessageMD5ChecksumInterceptor@aa794a3,
software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b]
```

~ Brice
Reply | Threaded
Open this post in threaded view
|

Re: Sqs2EndpointBuilder is not respecting delay - polling continuously

Claus Ibsen-2
Hi

Thanks for reporting. Can you create a JIRA ticket so we wont forget about this.

And can you try a regular string uri with the regular RouteBuilder to
see if its camel-endpointdsl that is causing this or a general problem
in the component.

On Wed, Apr 29, 2020 at 5:43 AM Brice Burgess <[hidden email]> wrote:

>
> Hi!
>
> I'm a happy new user of Camel and have an `aws2Sqs` route that is
> polling a Amazon SQS queue inside a Spring Boot application.
>
> Versions: Spring Boot 2.2.6, Camel 3.2.0
>
> I'm  seeing the connections come through the logs and it appears to be
> polling  every 500ms _regardless_ of the delay parameter passed.
>
> I have tried both the EndpointDSL as well as normal Route builder,
> with useFixedDelay explicitly passed and without (it defaults to
> true).
>
> Is there something I am missing? Or is this a bug?
>
> Many thanks for the guidance. Below is an excerpt from my source
>
> ```
> // build.gradle
> dependencies {
>     implementation 'org.apache.camel:camel-endpointdsl:3.2.0'
>     implementation 'org.apache.camel.springboot:camel-aws2-sqs-starter:3.2.0'
>     ...
> }
>
>
> // EncodeQueueRoute.java
> ...
> @Component
> public class EncodeQueueRoute extends EndpointRouteBuilder {
>     @Override
>     public void configure() {
>         from(aws2Sqs("queueName")
>                 .useFixedDelay(true)
>                 .delay(5000)
>         ).to(file("data/output"));
>     }
> }
> ```
>
> You can see the @ 500ms delay in the logs -- the period between
> connection release and starting a new one:
>
> ```
> 2020-04-28 23:39:18.229 DEBUG 22578 --- [e-worker-encode]
> h.i.c.PoolingHttpClientConnectionManager : Connection released: [id:
> 0][route: {}->http://localhost:4576][total available: 1; route
> allocated: 1 of 50; total allocated: 1 of 50]
> 2020-04-28 23:39:18.731 DEBUG 22578 --- [e-worker-encode]
> s.a.a.c.i.ExecutionInterceptorChain      : Creating an interceptor
> chain that will apply interceptors in the following order:
> [software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@7e63374b,
> software.amazon.awssdk.services.sqs.internal.MessageMD5ChecksumInterceptor@aa794a3,
> software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b]
> 2020-04-28 23:39:18.732 DEBUG 22578 --- [e-worker-encode]
> s.a.a.c.i.ExecutionInterceptorChain      : Interceptor
> 'software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b'
> modified the message with its modifyHttpRequest method.
> 2020-04-28 23:39:18.733 DEBUG 22578 --- [e-worker-encode]
> software.amazon.awssdk.request           : Sending Request:
> DefaultSdkHttpFullRequest(httpMethod=POST, protocol=http,
> host=localhost, port=4576, encodedPath=,
> headers=[amz-sdk-invocation-id, Content-Length, Content-Type,
> User-Agent], queryParameters=[])
> 2020-04-28 23:39:18.733 DEBUG 22578 --- [e-worker-encode]
> s.amazon.awssdk.auth.signer.Aws4Signer   : AWS4 String to sign:
> AWS4-HMAC-SHA256
> 20200429T033918Z
> 20200429/us-east-1/sqs/aws4_request
> dd1ab3d6875d36005937a3d8aa40ccfcf04a293217c796dc92cef0930d98db85
> 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> o.a.h.client.protocol.RequestAddCookies  : CookieSpec selected:
> default
> 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> o.a.h.client.protocol.RequestAuthCache   : Auth cache not set in the
> context
> 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> h.i.c.PoolingHttpClientConnectionManager : Connection request: [route:
> {}->http://localhost:4576][total available: 1; route allocated: 1 of
> 50; total allocated: 1 of 50]
> 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> h.i.c.PoolingHttpClientConnectionManager : Connection leased: [id:
> 0][route: {}->http://localhost:4576][total available: 0; route
> allocated: 1 of 50; total allocated: 1 of 50]
>
> ....
>
> 2020-04-28 23:39:18.740 DEBUG 22578 --- [e-worker-encode]
> h.i.c.PoolingHttpClientConnectionManager : Connection released: [id:
> 0][route: {}->http://localhost:4576][total available: 1; route
> allocated: 1 of 50; total allocated: 1 of 50]
> 2020-04-28 23:39:19.243 DEBUG 22578 --- [e-worker-encode]
> s.a.a.c.i.ExecutionInterceptorChain      : Creating an interceptor
> chain that will apply interceptors in the following order:
> [software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@7e63374b,
> software.amazon.awssdk.services.sqs.internal.MessageMD5ChecksumInterceptor@aa794a3,
> software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b]
> ```
>
> ~ Brice



--
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2
Reply | Threaded
Open this post in threaded view
|

Re: Sqs2EndpointBuilder is not respecting delay - polling continuously

Brice Burgess
Thank you Claus.

This did turn out to be an issue with the aws2sqs component,
  and is being tracked here:

https://issues.apache.org/jira/browse/CAMEL-14984

On Wed, Apr 29, 2020 at 9:02 AM Claus Ibsen <[hidden email]> wrote:

>
> Hi
>
> Thanks for reporting. Can you create a JIRA ticket so we wont forget about this.
>
> And can you try a regular string uri with the regular RouteBuilder to
> see if its camel-endpointdsl that is causing this or a general problem
> in the component.
>
> On Wed, Apr 29, 2020 at 5:43 AM Brice Burgess <[hidden email]> wrote:
> >
> > Hi!
> >
> > I'm a happy new user of Camel and have an `aws2Sqs` route that is
> > polling a Amazon SQS queue inside a Spring Boot application.
> >
> > Versions: Spring Boot 2.2.6, Camel 3.2.0
> >
> > I'm  seeing the connections come through the logs and it appears to be
> > polling  every 500ms _regardless_ of the delay parameter passed.
> >
> > I have tried both the EndpointDSL as well as normal Route builder,
> > with useFixedDelay explicitly passed and without (it defaults to
> > true).
> >
> > Is there something I am missing? Or is this a bug?
> >
> > Many thanks for the guidance. Below is an excerpt from my source
> >
> > ```
> > // build.gradle
> > dependencies {
> >     implementation 'org.apache.camel:camel-endpointdsl:3.2.0'
> >     implementation 'org.apache.camel.springboot:camel-aws2-sqs-starter:3.2.0'
> >     ...
> > }
> >
> >
> > // EncodeQueueRoute.java
> > ...
> > @Component
> > public class EncodeQueueRoute extends EndpointRouteBuilder {
> >     @Override
> >     public void configure() {
> >         from(aws2Sqs("queueName")
> >                 .useFixedDelay(true)
> >                 .delay(5000)
> >         ).to(file("data/output"));
> >     }
> > }
> > ```
> >
> > You can see the @ 500ms delay in the logs -- the period between
> > connection release and starting a new one:
> >
> > ```
> > 2020-04-28 23:39:18.229 DEBUG 22578 --- [e-worker-encode]
> > h.i.c.PoolingHttpClientConnectionManager : Connection released: [id:
> > 0][route: {}->http://localhost:4576][total available: 1; route
> > allocated: 1 of 50; total allocated: 1 of 50]
> > 2020-04-28 23:39:18.731 DEBUG 22578 --- [e-worker-encode]
> > s.a.a.c.i.ExecutionInterceptorChain      : Creating an interceptor
> > chain that will apply interceptors in the following order:
> > [software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@7e63374b,
> > software.amazon.awssdk.services.sqs.internal.MessageMD5ChecksumInterceptor@aa794a3,
> > software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b]
> > 2020-04-28 23:39:18.732 DEBUG 22578 --- [e-worker-encode]
> > s.a.a.c.i.ExecutionInterceptorChain      : Interceptor
> > 'software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b'
> > modified the message with its modifyHttpRequest method.
> > 2020-04-28 23:39:18.733 DEBUG 22578 --- [e-worker-encode]
> > software.amazon.awssdk.request           : Sending Request:
> > DefaultSdkHttpFullRequest(httpMethod=POST, protocol=http,
> > host=localhost, port=4576, encodedPath=,
> > headers=[amz-sdk-invocation-id, Content-Length, Content-Type,
> > User-Agent], queryParameters=[])
> > 2020-04-28 23:39:18.733 DEBUG 22578 --- [e-worker-encode]
> > s.amazon.awssdk.auth.signer.Aws4Signer   : AWS4 String to sign:
> > AWS4-HMAC-SHA256
> > 20200429T033918Z
> > 20200429/us-east-1/sqs/aws4_request
> > dd1ab3d6875d36005937a3d8aa40ccfcf04a293217c796dc92cef0930d98db85
> > 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> > o.a.h.client.protocol.RequestAddCookies  : CookieSpec selected:
> > default
> > 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> > o.a.h.client.protocol.RequestAuthCache   : Auth cache not set in the
> > context
> > 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> > h.i.c.PoolingHttpClientConnectionManager : Connection request: [route:
> > {}->http://localhost:4576][total available: 1; route allocated: 1 of
> > 50; total allocated: 1 of 50]
> > 2020-04-28 23:39:18.734 DEBUG 22578 --- [e-worker-encode]
> > h.i.c.PoolingHttpClientConnectionManager : Connection leased: [id:
> > 0][route: {}->http://localhost:4576][total available: 0; route
> > allocated: 1 of 50; total allocated: 1 of 50]
> >
> > ....
> >
> > 2020-04-28 23:39:18.740 DEBUG 22578 --- [e-worker-encode]
> > h.i.c.PoolingHttpClientConnectionManager : Connection released: [id:
> > 0][route: {}->http://localhost:4576][total available: 1; route
> > allocated: 1 of 50; total allocated: 1 of 50]
> > 2020-04-28 23:39:19.243 DEBUG 22578 --- [e-worker-encode]
> > s.a.a.c.i.ExecutionInterceptorChain      : Creating an interceptor
> > chain that will apply interceptors in the following order:
> > [software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@7e63374b,
> > software.amazon.awssdk.services.sqs.internal.MessageMD5ChecksumInterceptor@aa794a3,
> > software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@1dce481b]
> > ```
> >
> > ~ Brice
>
>
>
> --
> Claus Ibsen
> -----------------
> http://davsclaus.com @davsclaus
> Camel in Action 2: https://www.manning.com/ibsen2