You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by Veijo Länsikunnas <ve...@trimble.com.INVALID> on 2025/09/26 10:00:52 UTC

Http redelivery sending extra times (4.14.0)

Hello,

I just noticed an issue in our app, that http redelivery was sending
extra messages to the target url. I first thought it to be related to
jms transactions, but with a closer look this happens with just a
simple retry.

Here is a simple test case to view the result. The message should be
sent twice (original and retry), but it gets sent four times.

import org.apache.camel.Exchange;
import org.apache.camel.LoggingLevel;
import org.apache.camel.builder.RouteBuilder;
import org.springframework.stereotype.Component;

@Component
public class TestRoute extends RouteBuilder {
    private static final String DIRECT_EXHAUSTED = "direct:exhausted";
    private static final long DEFAULT_RESPONSE_CODE = 503;
    public static final String SINK = "http://localhost:29999/sink";

    @Override
    public void configure() {

 errorHandler(deadLetterChannel(DIRECT_EXHAUSTED).maximumRedeliveries(1).redeliveryDelay(10000).logExhausted(false));
        from("timer:camel-timer?repeatCount=1")
                .setBody(constant("Hello world!"))
                .log(LoggingLevel.INFO, "This is request ")
                .to(SINK);

        from(DIRECT_EXHAUSTED)
                .routeId("exhausted")
                .log(LoggingLevel.INFO, "Retries exhausted ${exception}");

        from("jetty:"+SINK)
                .log("Request headers: ${headers}")
                .setHeader(Exchange.HTTP_RESPONSE_CODE,
constant(DEFAULT_RESPONSE_CODE))
                .log("Finished");
    }
}


When I set http activity logging to be used, it sent the message only
twice and failed with a null pointer exception in the logger. I
created a simpler logger to just log the invocations without anything
that could fail when values are null

import org.apache.camel.Exchange;
import org.apache.camel.component.http.HttpActivityListener;
import org.apache.hc.core5.http.HttpEntity;
import org.apache.hc.core5.http.HttpHost;
import org.apache.hc.core5.http.HttpResponse;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.apache.hc.core5.http.HttpRequest;

@Component
public class HttpActivityLogger implements HttpActivityListener {

    private static final Logger LOGGER =
LoggerFactory.getLogger(HttpActivityLogger.class);

    @Override
    public void onRequestSubmitted(Object source, Exchange exchange,
HttpHost host, HttpRequest request, HttpEntity entity) {
        LOGGER.info("{} onRequestSubmitted: {}", exchange, source);
        LOGGER.trace("{} Stack trace: {}", exchange,
Thread.currentThread().getStackTrace());
    }

    @Override
    public void onResponseReceived(Object source, Exchange exchange,
HttpHost host, HttpResponse response, HttpEntity entity, long elapsed)
{
        LOGGER.info("{} Spent {} milliseconds", exchange, elapsed);
    }
}


Here is the log from the execution where the extra call with null
exchange occurs a few milliseconds later that the original

2025-09-25T10:32:22.403+03:00 Apache Camel 4.10.6 (camel-1) started in
362ms (build:0ms init:0ms start:362ms boot:985ms)
2025-09-25T10:32:22.405+03:00 Started CamelTestApplication in 2.671
seconds (process running for 3.157)
2025-09-25T10:32:23.416+03:00 This is request
2025-09-25T10:32:23.455+03:00
Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
org.apache.camel.component.http.HttpEndpoint$1@427b9a63
2025-09-25T10:32:23.548+03:00 Request headers: {Accept-Encoding=gzip,
x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
CamelHttpQuery=null, CamelHttpUri=/sink,
CamelHttpUrl=http://localhost:29999/sink,
CamelServletContextPath=/sink, Connection=keep-alive,
Content-Length=12, Host=localhost:29999,
User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
2025-09-25T10:32:23.548+03:00 Finished
2025-09-25T10:32:23.562+03:00
Exchange[DDE7F0CB4616F92-0000000000000000] Spent 106 milliseconds
2025-09-25T10:32:24.574+03:00 null onRequestSubmitted:
org.apache.camel.component.http.HttpEndpoint$1@427b9a63
2025-09-25T10:32:24.576+03:00 Request headers: {Accept-Encoding=gzip,
x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
CamelHttpQuery=null, CamelHttpUri=/sink,
CamelHttpUrl=http://localhost:29999/sink,
CamelServletContextPath=/sink, Connection=keep-alive,
Content-Length=12, Host=localhost:29999,
User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
2025-09-25T10:32:24.576+03:00 Finished
2025-09-25T10:32:24.577+03:00 null Spent 3 milliseconds
2025-09-25T10:32:34.591+03:00
Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
org.apache.camel.component.http.HttpEndpoint$1@427b9a63
2025-09-25T10:32:34.592+03:00 Request headers: {Accept-Encoding=gzip,
x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
CamelHttpQuery=null, CamelHttpUri=/sink,
CamelHttpUrl=http://localhost:29999/sink,
CamelServletContextPath=/sink, Connection=keep-alive,
Content-Length=12, Host=localhost:29999,
User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
2025-09-25T10:32:34.593+03:00 Finished
2025-09-25T10:32:34.594+03:00
Exchange[DDE7F0CB4616F92-0000000000000000] Spent 2 milliseconds
2025-09-25T10:32:35.599+03:00 null onRequestSubmitted:
org.apache.camel.component.http.HttpEndpoint$1@427b9a63
2025-09-25T10:32:35.601+03:00 Request headers: {Accept-Encoding=gzip,
x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
CamelHttpQuery=null, CamelHttpUri=/sink,
CamelHttpUrl=http://localhost:29999/sink,
CamelServletContextPath=/sink, Connection=keep-alive,
Content-Length=12, Host=localhost:29999,
User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
2025-09-25T10:32:35.601+03:00 Finished
2025-09-25T10:32:35.602+03:00 null Spent 2 milliseconds
2025-09-25T10:32:35.606+03:00 Retries exhausted
org.apache.camel.http.base.HttpOperationFailedException: HTTP
operation failed invoking http://localhost:29999/sink with statusCode:
503


To me this looks like a bug in the retry logic, based on the exchange
being null in that unwanted call.

I tested this with camel 4.14.0 and 4.10.6 and both behave the same way.

-- 
Veijo Länsikunnas

Re: Http redelivery sending extra times (4.14.0)

Posted by Claus Ibsen <cl...@gmail.com>.
Hi

Okay so the null exchange is being fixed
https://issues.apache.org/jira/browse/CAMEL-22474

You have both Camel error handler to redlievery after 10 seconds, and then
http client is also doing its own redelivery.
So that is why you see a 2nd call asap, and then 10 sec later Camel
redeliver also.

You can disable automatic retries on the http component in application yaml

automaticRetriesDisabled: true


On Tue, Sep 30, 2025 at 10:03 AM Veijo Länsikunnas
<ve...@trimble.com.invalid> wrote:

> Hello,
>
> Here is a sample project for reproducing the issue:
> https://github.com/VeijoFromTrimble/camel-http-resend-issue
>
>
> --
> Veijo Länsikunnas
>
>
> --
> Veijo Länsikunnas | He/Him
> Senior Integration Architect, Forestry
> ________________________________
>
> Hatsinanpuisto 8, 02600 Espoo
> Finland
> +358 40 545 7525 Mobile
>
> veijo.lansikunnas@trimble.com
> forestry.trimble.com
>
>
> This email may contain confidential information that is intended only
> for the listed recipient(s) of this email. Any unauthorized review,
> use, disclosure or distribution is prohibited. If you believe you have
> received this email in error, please immediately delete this email and
> any attachments, and inform me via reply email.
>
>
>
> ma 29.9.2025 klo 13.58 Claus Ibsen (claus.ibsen@gmail.com) kirjoitti:
> >
> > Hi
> >
> > Can you put together a reproducer sample project that you can either
> attach
> > as a .zip to a JIRA ticket or put on github for others to take a look at.
> >
> >
> > On Fri, Sep 26, 2025 at 12:03 PM Veijo Länsikunnas
> > <ve...@trimble.com.invalid> wrote:
> >
> > > Hello,
> > >
> > > I just noticed an issue in our app, that http redelivery was sending
> > > extra messages to the target url. I first thought it to be related to
> > > jms transactions, but with a closer look this happens with just a
> > > simple retry.
> > >
> > > Here is a simple test case to view the result. The message should be
> > > sent twice (original and retry), but it gets sent four times.
> > >
> > > import org.apache.camel.Exchange;
> > > import org.apache.camel.LoggingLevel;
> > > import org.apache.camel.builder.RouteBuilder;
> > > import org.springframework.stereotype.Component;
> > >
> > > @Component
> > > public class TestRoute extends RouteBuilder {
> > >     private static final String DIRECT_EXHAUSTED = "direct:exhausted";
> > >     private static final long DEFAULT_RESPONSE_CODE = 503;
> > >     public static final String SINK = "http://localhost:29999/sink";
> > >
> > >     @Override
> > >     public void configure() {
> > >
> > >
> > >
> errorHandler(deadLetterChannel(DIRECT_EXHAUSTED).maximumRedeliveries(1).redeliveryDelay(10000).logExhausted(false));
> > >         from("timer:camel-timer?repeatCount=1")
> > >                 .setBody(constant("Hello world!"))
> > >                 .log(LoggingLevel.INFO, "This is request ")
> > >                 .to(SINK);
> > >
> > >         from(DIRECT_EXHAUSTED)
> > >                 .routeId("exhausted")
> > >                 .log(LoggingLevel.INFO, "Retries exhausted
> ${exception}");
> > >
> > >         from("jetty:"+SINK)
> > >                 .log("Request headers: ${headers}")
> > >                 .setHeader(Exchange.HTTP_RESPONSE_CODE,
> > > constant(DEFAULT_RESPONSE_CODE))
> > >                 .log("Finished");
> > >     }
> > > }
> > >
> > >
> > > When I set http activity logging to be used, it sent the message only
> > > twice and failed with a null pointer exception in the logger. I
> > > created a simpler logger to just log the invocations without anything
> > > that could fail when values are null
> > >
> > > import org.apache.camel.Exchange;
> > > import org.apache.camel.component.http.HttpActivityListener;
> > > import org.apache.hc.core5.http.HttpEntity;
> > > import org.apache.hc.core5.http.HttpHost;
> > > import org.apache.hc.core5.http.HttpResponse;
> > > import org.slf4j.Logger;
> > > import org.slf4j.LoggerFactory;
> > > import org.springframework.stereotype.Component;
> > > import org.apache.hc.core5.http.HttpRequest;
> > >
> > > @Component
> > > public class HttpActivityLogger implements HttpActivityListener {
> > >
> > >     private static final Logger LOGGER =
> > > LoggerFactory.getLogger(HttpActivityLogger.class);
> > >
> > >     @Override
> > >     public void onRequestSubmitted(Object source, Exchange exchange,
> > > HttpHost host, HttpRequest request, HttpEntity entity) {
> > >         LOGGER.info("{} onRequestSubmitted: {}", exchange, source);
> > >         LOGGER.trace("{} Stack trace: {}", exchange,
> > > Thread.currentThread().getStackTrace());
> > >     }
> > >
> > >     @Override
> > >     public void onResponseReceived(Object source, Exchange exchange,
> > > HttpHost host, HttpResponse response, HttpEntity entity, long elapsed)
> > > {
> > >         LOGGER.info("{} Spent {} milliseconds", exchange, elapsed);
> > >     }
> > > }
> > >
> > >
> > > Here is the log from the execution where the extra call with null
> > > exchange occurs a few milliseconds later that the original
> > >
> > > 2025-09-25T10:32:22.403+03:00 Apache Camel 4.10.6 (camel-1) started in
> > > 362ms (build:0ms init:0ms start:362ms boot:985ms)
> > > 2025-09-25T10:32:22.405+03:00 Started CamelTestApplication in 2.671
> > > seconds (process running for 3.157)
> > > 2025-09-25T10:32:23.416+03:00 This is request
> > > 2025-09-25T10:32:23.455+03:00
> > > Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
> > > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > > 2025-09-25T10:32:23.548+03:00 Request headers: {Accept-Encoding=gzip,
> > > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > > CamelHttpQuery=null, CamelHttpUri=/sink,
> > > CamelHttpUrl=http://localhost:29999/sink,
> > > CamelServletContextPath=/sink, Connection=keep-alive,
> > > Content-Length=12, Host=localhost:29999,
> > > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > > 2025-09-25T10:32:23.548+03:00 Finished
> > > 2025-09-25T10:32:23.562+03:00
> > > Exchange[DDE7F0CB4616F92-0000000000000000] Spent 106 milliseconds
> > > 2025-09-25T10:32:24.574+03:00 null onRequestSubmitted:
> > > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > > 2025-09-25T10:32:24.576+03:00 Request headers: {Accept-Encoding=gzip,
> > > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > > CamelHttpQuery=null, CamelHttpUri=/sink,
> > > CamelHttpUrl=http://localhost:29999/sink,
> > > CamelServletContextPath=/sink, Connection=keep-alive,
> > > Content-Length=12, Host=localhost:29999,
> > > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > > 2025-09-25T10:32:24.576+03:00 Finished
> > > 2025-09-25T10:32:24.577+03:00 null Spent 3 milliseconds
> > > 2025-09-25T10:32:34.591+03:00
> > > Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
> > > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > > 2025-09-25T10:32:34.592+03:00 Request headers: {Accept-Encoding=gzip,
> > > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > > CamelHttpQuery=null, CamelHttpUri=/sink,
> > > CamelHttpUrl=http://localhost:29999/sink,
> > > CamelServletContextPath=/sink, Connection=keep-alive,
> > > Content-Length=12, Host=localhost:29999,
> > > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > > 2025-09-25T10:32:34.593+03:00 Finished
> > > 2025-09-25T10:32:34.594+03:00
> > > Exchange[DDE7F0CB4616F92-0000000000000000] Spent 2 milliseconds
> > > 2025-09-25T10:32:35.599+03:00 null onRequestSubmitted:
> > > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > > 2025-09-25T10:32:35.601+03:00 Request headers: {Accept-Encoding=gzip,
> > > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > > CamelHttpQuery=null, CamelHttpUri=/sink,
> > > CamelHttpUrl=http://localhost:29999/sink,
> > > CamelServletContextPath=/sink, Connection=keep-alive,
> > > Content-Length=12, Host=localhost:29999,
> > > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > > 2025-09-25T10:32:35.601+03:00 Finished
> > > 2025-09-25T10:32:35.602+03:00 null Spent 2 milliseconds
> > > 2025-09-25T10:32:35.606+03:00 Retries exhausted
> > > org.apache.camel.http.base.HttpOperationFailedException: HTTP
> > > operation failed invoking http://localhost:29999/sink with statusCode:
> > > 503
> > >
> > >
> > > To me this looks like a bug in the retry logic, based on the exchange
> > > being null in that unwanted call.
> > >
> > > I tested this with camel 4.14.0 and 4.10.6 and both behave the same
> way.
> > >
> > > --
> > > Veijo Länsikunnas
> > >
> >
> >
> > --
> > Claus Ibsen
>


-- 
Claus Ibsen

Re: Http redelivery sending extra times (4.14.0)

Posted by Veijo Länsikunnas <ve...@trimble.com.INVALID>.
Hello,

Here is a sample project for reproducing the issue:
https://github.com/VeijoFromTrimble/camel-http-resend-issue


-- 
Veijo Länsikunnas


-- 
Veijo Länsikunnas | He/Him
Senior Integration Architect, Forestry
________________________________

Hatsinanpuisto 8, 02600 Espoo
Finland
+358 40 545 7525 Mobile

veijo.lansikunnas@trimble.com
forestry.trimble.com


This email may contain confidential information that is intended only
for the listed recipient(s) of this email. Any unauthorized review,
use, disclosure or distribution is prohibited. If you believe you have
received this email in error, please immediately delete this email and
any attachments, and inform me via reply email.



ma 29.9.2025 klo 13.58 Claus Ibsen (claus.ibsen@gmail.com) kirjoitti:
>
> Hi
>
> Can you put together a reproducer sample project that you can either attach
> as a .zip to a JIRA ticket or put on github for others to take a look at.
>
>
> On Fri, Sep 26, 2025 at 12:03 PM Veijo Länsikunnas
> <ve...@trimble.com.invalid> wrote:
>
> > Hello,
> >
> > I just noticed an issue in our app, that http redelivery was sending
> > extra messages to the target url. I first thought it to be related to
> > jms transactions, but with a closer look this happens with just a
> > simple retry.
> >
> > Here is a simple test case to view the result. The message should be
> > sent twice (original and retry), but it gets sent four times.
> >
> > import org.apache.camel.Exchange;
> > import org.apache.camel.LoggingLevel;
> > import org.apache.camel.builder.RouteBuilder;
> > import org.springframework.stereotype.Component;
> >
> > @Component
> > public class TestRoute extends RouteBuilder {
> >     private static final String DIRECT_EXHAUSTED = "direct:exhausted";
> >     private static final long DEFAULT_RESPONSE_CODE = 503;
> >     public static final String SINK = "http://localhost:29999/sink";
> >
> >     @Override
> >     public void configure() {
> >
> >
> >  errorHandler(deadLetterChannel(DIRECT_EXHAUSTED).maximumRedeliveries(1).redeliveryDelay(10000).logExhausted(false));
> >         from("timer:camel-timer?repeatCount=1")
> >                 .setBody(constant("Hello world!"))
> >                 .log(LoggingLevel.INFO, "This is request ")
> >                 .to(SINK);
> >
> >         from(DIRECT_EXHAUSTED)
> >                 .routeId("exhausted")
> >                 .log(LoggingLevel.INFO, "Retries exhausted ${exception}");
> >
> >         from("jetty:"+SINK)
> >                 .log("Request headers: ${headers}")
> >                 .setHeader(Exchange.HTTP_RESPONSE_CODE,
> > constant(DEFAULT_RESPONSE_CODE))
> >                 .log("Finished");
> >     }
> > }
> >
> >
> > When I set http activity logging to be used, it sent the message only
> > twice and failed with a null pointer exception in the logger. I
> > created a simpler logger to just log the invocations without anything
> > that could fail when values are null
> >
> > import org.apache.camel.Exchange;
> > import org.apache.camel.component.http.HttpActivityListener;
> > import org.apache.hc.core5.http.HttpEntity;
> > import org.apache.hc.core5.http.HttpHost;
> > import org.apache.hc.core5.http.HttpResponse;
> > import org.slf4j.Logger;
> > import org.slf4j.LoggerFactory;
> > import org.springframework.stereotype.Component;
> > import org.apache.hc.core5.http.HttpRequest;
> >
> > @Component
> > public class HttpActivityLogger implements HttpActivityListener {
> >
> >     private static final Logger LOGGER =
> > LoggerFactory.getLogger(HttpActivityLogger.class);
> >
> >     @Override
> >     public void onRequestSubmitted(Object source, Exchange exchange,
> > HttpHost host, HttpRequest request, HttpEntity entity) {
> >         LOGGER.info("{} onRequestSubmitted: {}", exchange, source);
> >         LOGGER.trace("{} Stack trace: {}", exchange,
> > Thread.currentThread().getStackTrace());
> >     }
> >
> >     @Override
> >     public void onResponseReceived(Object source, Exchange exchange,
> > HttpHost host, HttpResponse response, HttpEntity entity, long elapsed)
> > {
> >         LOGGER.info("{} Spent {} milliseconds", exchange, elapsed);
> >     }
> > }
> >
> >
> > Here is the log from the execution where the extra call with null
> > exchange occurs a few milliseconds later that the original
> >
> > 2025-09-25T10:32:22.403+03:00 Apache Camel 4.10.6 (camel-1) started in
> > 362ms (build:0ms init:0ms start:362ms boot:985ms)
> > 2025-09-25T10:32:22.405+03:00 Started CamelTestApplication in 2.671
> > seconds (process running for 3.157)
> > 2025-09-25T10:32:23.416+03:00 This is request
> > 2025-09-25T10:32:23.455+03:00
> > Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
> > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > 2025-09-25T10:32:23.548+03:00 Request headers: {Accept-Encoding=gzip,
> > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > CamelHttpQuery=null, CamelHttpUri=/sink,
> > CamelHttpUrl=http://localhost:29999/sink,
> > CamelServletContextPath=/sink, Connection=keep-alive,
> > Content-Length=12, Host=localhost:29999,
> > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > 2025-09-25T10:32:23.548+03:00 Finished
> > 2025-09-25T10:32:23.562+03:00
> > Exchange[DDE7F0CB4616F92-0000000000000000] Spent 106 milliseconds
> > 2025-09-25T10:32:24.574+03:00 null onRequestSubmitted:
> > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > 2025-09-25T10:32:24.576+03:00 Request headers: {Accept-Encoding=gzip,
> > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > CamelHttpQuery=null, CamelHttpUri=/sink,
> > CamelHttpUrl=http://localhost:29999/sink,
> > CamelServletContextPath=/sink, Connection=keep-alive,
> > Content-Length=12, Host=localhost:29999,
> > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > 2025-09-25T10:32:24.576+03:00 Finished
> > 2025-09-25T10:32:24.577+03:00 null Spent 3 milliseconds
> > 2025-09-25T10:32:34.591+03:00
> > Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
> > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > 2025-09-25T10:32:34.592+03:00 Request headers: {Accept-Encoding=gzip,
> > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > CamelHttpQuery=null, CamelHttpUri=/sink,
> > CamelHttpUrl=http://localhost:29999/sink,
> > CamelServletContextPath=/sink, Connection=keep-alive,
> > Content-Length=12, Host=localhost:29999,
> > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > 2025-09-25T10:32:34.593+03:00 Finished
> > 2025-09-25T10:32:34.594+03:00
> > Exchange[DDE7F0CB4616F92-0000000000000000] Spent 2 milliseconds
> > 2025-09-25T10:32:35.599+03:00 null onRequestSubmitted:
> > org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> > 2025-09-25T10:32:35.601+03:00 Request headers: {Accept-Encoding=gzip,
> > x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> > CamelHttpQuery=null, CamelHttpUri=/sink,
> > CamelHttpUrl=http://localhost:29999/sink,
> > CamelServletContextPath=/sink, Connection=keep-alive,
> > Content-Length=12, Host=localhost:29999,
> > User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> > 2025-09-25T10:32:35.601+03:00 Finished
> > 2025-09-25T10:32:35.602+03:00 null Spent 2 milliseconds
> > 2025-09-25T10:32:35.606+03:00 Retries exhausted
> > org.apache.camel.http.base.HttpOperationFailedException: HTTP
> > operation failed invoking http://localhost:29999/sink with statusCode:
> > 503
> >
> >
> > To me this looks like a bug in the retry logic, based on the exchange
> > being null in that unwanted call.
> >
> > I tested this with camel 4.14.0 and 4.10.6 and both behave the same way.
> >
> > --
> > Veijo Länsikunnas
> >
>
>
> --
> Claus Ibsen

Re: Http redelivery sending extra times (4.14.0)

Posted by Claus Ibsen <cl...@gmail.com>.
Hi

Can you put together a reproducer sample project that you can either attach
as a .zip to a JIRA ticket or put on github for others to take a look at.


On Fri, Sep 26, 2025 at 12:03 PM Veijo Länsikunnas
<ve...@trimble.com.invalid> wrote:

> Hello,
>
> I just noticed an issue in our app, that http redelivery was sending
> extra messages to the target url. I first thought it to be related to
> jms transactions, but with a closer look this happens with just a
> simple retry.
>
> Here is a simple test case to view the result. The message should be
> sent twice (original and retry), but it gets sent four times.
>
> import org.apache.camel.Exchange;
> import org.apache.camel.LoggingLevel;
> import org.apache.camel.builder.RouteBuilder;
> import org.springframework.stereotype.Component;
>
> @Component
> public class TestRoute extends RouteBuilder {
>     private static final String DIRECT_EXHAUSTED = "direct:exhausted";
>     private static final long DEFAULT_RESPONSE_CODE = 503;
>     public static final String SINK = "http://localhost:29999/sink";
>
>     @Override
>     public void configure() {
>
>
>  errorHandler(deadLetterChannel(DIRECT_EXHAUSTED).maximumRedeliveries(1).redeliveryDelay(10000).logExhausted(false));
>         from("timer:camel-timer?repeatCount=1")
>                 .setBody(constant("Hello world!"))
>                 .log(LoggingLevel.INFO, "This is request ")
>                 .to(SINK);
>
>         from(DIRECT_EXHAUSTED)
>                 .routeId("exhausted")
>                 .log(LoggingLevel.INFO, "Retries exhausted ${exception}");
>
>         from("jetty:"+SINK)
>                 .log("Request headers: ${headers}")
>                 .setHeader(Exchange.HTTP_RESPONSE_CODE,
> constant(DEFAULT_RESPONSE_CODE))
>                 .log("Finished");
>     }
> }
>
>
> When I set http activity logging to be used, it sent the message only
> twice and failed with a null pointer exception in the logger. I
> created a simpler logger to just log the invocations without anything
> that could fail when values are null
>
> import org.apache.camel.Exchange;
> import org.apache.camel.component.http.HttpActivityListener;
> import org.apache.hc.core5.http.HttpEntity;
> import org.apache.hc.core5.http.HttpHost;
> import org.apache.hc.core5.http.HttpResponse;
> import org.slf4j.Logger;
> import org.slf4j.LoggerFactory;
> import org.springframework.stereotype.Component;
> import org.apache.hc.core5.http.HttpRequest;
>
> @Component
> public class HttpActivityLogger implements HttpActivityListener {
>
>     private static final Logger LOGGER =
> LoggerFactory.getLogger(HttpActivityLogger.class);
>
>     @Override
>     public void onRequestSubmitted(Object source, Exchange exchange,
> HttpHost host, HttpRequest request, HttpEntity entity) {
>         LOGGER.info("{} onRequestSubmitted: {}", exchange, source);
>         LOGGER.trace("{} Stack trace: {}", exchange,
> Thread.currentThread().getStackTrace());
>     }
>
>     @Override
>     public void onResponseReceived(Object source, Exchange exchange,
> HttpHost host, HttpResponse response, HttpEntity entity, long elapsed)
> {
>         LOGGER.info("{} Spent {} milliseconds", exchange, elapsed);
>     }
> }
>
>
> Here is the log from the execution where the extra call with null
> exchange occurs a few milliseconds later that the original
>
> 2025-09-25T10:32:22.403+03:00 Apache Camel 4.10.6 (camel-1) started in
> 362ms (build:0ms init:0ms start:362ms boot:985ms)
> 2025-09-25T10:32:22.405+03:00 Started CamelTestApplication in 2.671
> seconds (process running for 3.157)
> 2025-09-25T10:32:23.416+03:00 This is request
> 2025-09-25T10:32:23.455+03:00
> Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
> org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> 2025-09-25T10:32:23.548+03:00 Request headers: {Accept-Encoding=gzip,
> x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> CamelHttpQuery=null, CamelHttpUri=/sink,
> CamelHttpUrl=http://localhost:29999/sink,
> CamelServletContextPath=/sink, Connection=keep-alive,
> Content-Length=12, Host=localhost:29999,
> User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> 2025-09-25T10:32:23.548+03:00 Finished
> 2025-09-25T10:32:23.562+03:00
> Exchange[DDE7F0CB4616F92-0000000000000000] Spent 106 milliseconds
> 2025-09-25T10:32:24.574+03:00 null onRequestSubmitted:
> org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> 2025-09-25T10:32:24.576+03:00 Request headers: {Accept-Encoding=gzip,
> x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> CamelHttpQuery=null, CamelHttpUri=/sink,
> CamelHttpUrl=http://localhost:29999/sink,
> CamelServletContextPath=/sink, Connection=keep-alive,
> Content-Length=12, Host=localhost:29999,
> User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> 2025-09-25T10:32:24.576+03:00 Finished
> 2025-09-25T10:32:24.577+03:00 null Spent 3 milliseconds
> 2025-09-25T10:32:34.591+03:00
> Exchange[DDE7F0CB4616F92-0000000000000000] onRequestSubmitted:
> org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> 2025-09-25T10:32:34.592+03:00 Request headers: {Accept-Encoding=gzip,
> x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> CamelHttpQuery=null, CamelHttpUri=/sink,
> CamelHttpUrl=http://localhost:29999/sink,
> CamelServletContextPath=/sink, Connection=keep-alive,
> Content-Length=12, Host=localhost:29999,
> User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> 2025-09-25T10:32:34.593+03:00 Finished
> 2025-09-25T10:32:34.594+03:00
> Exchange[DDE7F0CB4616F92-0000000000000000] Spent 2 milliseconds
> 2025-09-25T10:32:35.599+03:00 null onRequestSubmitted:
> org.apache.camel.component.http.HttpEndpoint$1@427b9a63
> 2025-09-25T10:32:35.601+03:00 Request headers: {Accept-Encoding=gzip,
> x-gzip, deflate, CamelHttpMethod=POST, CamelHttpPath=,
> CamelHttpQuery=null, CamelHttpUri=/sink,
> CamelHttpUrl=http://localhost:29999/sink,
> CamelServletContextPath=/sink, Connection=keep-alive,
> Content-Length=12, Host=localhost:29999,
> User-Agent=Apache-HttpClient/5.5 (Java/17.0.15)}
> 2025-09-25T10:32:35.601+03:00 Finished
> 2025-09-25T10:32:35.602+03:00 null Spent 2 milliseconds
> 2025-09-25T10:32:35.606+03:00 Retries exhausted
> org.apache.camel.http.base.HttpOperationFailedException: HTTP
> operation failed invoking http://localhost:29999/sink with statusCode:
> 503
>
>
> To me this looks like a bug in the retry logic, based on the exchange
> being null in that unwanted call.
>
> I tested this with camel 4.14.0 and 4.10.6 and both behave the same way.
>
> --
> Veijo Länsikunnas
>


-- 
Claus Ibsen