Hi

Do NOT use such a long receive timeout, that is not its purpose.
The timeout should be a reasonable value that allows camel-jms (eg
spring jms) to react on shutdown or stopping, or reducing concurrent
consumers if there are no more pending messages.

On Thu, Oct 7, 2021 at 3:05 PM Mattern, Alex
<[email protected]> wrote:
>
> I would like Apache Camel to perform a graceful shutdown within the default 
> 45 seconds. After 45 seconds I would like the the shutdown to be forced.
>
> I normally expect the default 45 second timeout to work, but unfortunately it 
> does not seem to work when using a JMS component with a long receiveTimeout 
> on Oracle AQ.
>
> Context file snippet:
>
> <bean id="aqjms" class="org.apache.camel.component.jms.JmsComponent">
>     <property name="connectionFactory" ref="aqJmsConnectionFactory" />
>     <property name="transacted" value="true" />
>     <property name="transactionManager" ref="dbTransactionManager" />
> </bean>
>
> Stop Java Code:
>
> private org.apache.camel.spring.Main main;
>
> @Override
> public String call() throws Exception {
>     try {
>         LOG.info("Received stop command so stopping the server.");
>         stopApplication();
>     } catch (Exception e) {
>         throw new AnException("Error occurred while executing the STOP 
> command", e);
>     }
>     return "DONE";
> }
>
> public void stopApplication() {
>     try {
>         main.stop();
>     } catch (Exception e) {
>         System.out.println("Error stopping camel");
>     } finally {
>         System.exit(0);
>     }
> }
>
> @Override
> public String execute(CommandInput commandInput) {
>     // All tasks before graceful shut down goes here..
>     ExecutorService executor = Executors.newSingleThreadExecutor();
>     FutureTask<String> ft= new FutureTask<String>(this);
>     executor.execute(ft);
>     LOG.info(" Executed stop command asynchronously for JVM {}", 
> commandInput.getProcessName());
>     return "STOP";
> }
>
> Now if I set my Oracle AQ routes with a short receiveTimeout like this:
>
> aqjms://AQSCHEMA.SOME_AQ?concurrentConsumers=30
> jms://SOME_IBM_MQ?concurrentConsumers=20&receiveTimeout=3600000
> ...
>
> I get a quick camel shutdown.
>
> Tue May 11 10:15:37 EDT 2021    INFO    Executed stop command asynchronoulsy 
> for JVM SOMETHING  ClassWrapper{className='some.class'}    Camel 
> (camelContext) thread #6 - JmsConsumer[AN_IBM_MQ_TOPIC]
> Tue May 11 10:15:37 EDT 2021    INFO    Received stop command so stopping the 
> server.   ClassWrapper{className='some.class'}    pool-10638-thread-1
> Tue May 11 10:15:37 EDT 2021    INFO    CamelContext: camelContext has been 
> shutdown, triggering shutdown of the JVM.   
> ClassWrapper{className='org.apache.camel.main.MainLifecycleStrategy'}   
> pool-10638-thread-1
> Tue May 11 10:15:37 EDT 2021    INFO    Apache Camel 3.7.2 (camelContext) is 
> shutting down  
> ClassWrapper{className='org.apache.camel.impl.engine.AbstractCamelContext'} 
> pool-10638-thread-1
> Tue May 11 10:15:37 EDT 2021    INFO    Starting to graceful shutdown 120 
> routes (timeout 45 seconds)   
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   pool-10638-thread-1
> Tue May 11 10:15:37 EDT 2021    INFO    Route: first_route shutdown complete, 
> was consuming from: somewhere 
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   Camel (camelContext) thread #3 - ShutdownTask
> ...
> 119 more routes shutdown
> ...
> Tue May 11 10:15:38 EDT 2021    INFO    Graceful shutdown of 120 routes 
> completed in 1s337ms    
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   pool-10638-thread-1
> Tue May 11 10:15:38 EDT 2021    INFO    Apache Camel 3.7.2 (camelContext) 
> uptime 1d7h9m4s   
> ClassWrapper{className='org.apache.camel.impl.engine.AbstractCamelContext'} 
> pool-10638-thread-1
> Tue May 11 10:15:38 EDT 2021    INFO    Apache Camel 3.7.2 (camelContext) is 
> shutdown in 1s539ms    
> ClassWrapper{className='org.apache.camel.impl.engine.AbstractCamelContext'} 
> pool-10638-thread-1
> Tue May 11 10:15:38 EDT 2021    INFO    CamelContext: camelContext has been 
> shutdown, triggering shutdown of the JVM.   
> ClassWrapper{className='org.apache.camel.main.MainLifecycleStrategy'}   
> pool-10638-thread-1
> Tue May 11 10:15:38 EDT 2021    INFO    Received hangup signal, stopping the 
> main instance. 
> ClassWrapper{className='org.apache.camel.main.DefaultMainShutdownStrategy'} 
> Camel Thread #131 - CamelHangupInterceptor
>
> Now if I set my Oracle AQ route to have a long receiveTimeout like this:
>
> aqjms://AQSCHEMA.SOME_AQ?concurrentConsumers=30&receiveTimeout=3600000
> jms://SOME_IBM_MQ?concurrentConsumers=20&receiveTimeout=3600000
> ...
>
> I get a slow camel shutdown.
>
> Mon May 10 11:38:38 EDT 2021    INFO    Received stop command so stopping the 
> server.   ClassWrapper{className='some.class'}    pool-183-thread-1
> Mon May 10 11:38:38 EDT 2021    INFO    CamelContext: camelContext has been 
> shutdown, triggering shutdown of the JVM.   
> ClassWrapper{className='org.apache.camel.main.MainLifecycleStrategy'}   
> pool-183-thread-1
> Mon May 10 11:38:38 EDT 2021    INFO    Apache Camel 3.7.2 (camelContext) is 
> shutting down  
> ClassWrapper{className='org.apache.camel.impl.engine.AbstractCamelContext'} 
> pool-183-thread-1
> Mon May 10 11:38:38 EDT 2021    INFO    Starting to graceful shutdown 119 
> routes (timeout 45 seconds)   
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   pool-183-thread-1
> Mon May 10 11:38:38 EDT 2021    INFO    Route: first_route shutdown complete, 
> was consuming from: somewhere 
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   Camel (camelContext) thread #3 - ShutdownTask
> ...
> a couple more routes shutdown
> ...
> Mon May 10 11:39:23 EDT 2021    WARN    Timeout occurred during graceful 
> shutdown. Forcing the routes to be shutdown now. Notice: some resources may 
> still be running as graceful shutdown did not complete successfully.   
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   pool-183-thread-1
> Mon May 10 11:39:23 EDT 2021    WARN    Timeout occurred during graceful 
> shutdown. Forcing the routes to be shutdown now. Notice: some resources may 
> still be running as graceful shutdown did not complete successfully.   
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   pool-183-thread-1
> Mon May 10 11:39:23 EDT 2021    WARN    Setup of JMS message listener invoker 
> failed for destination 'AN_ORACLE_AQ_CONSUMER_ROUTE' - trying to recover. 
> Cause: JMS-257: receive(long timeout) of javax.jms.MessageConsumer took more 
> time than the network timeout configured at the java.sql.Connection.; nested 
> exception is java.sql.SQLRecoverableException: IO Error: Socket read 
> interrupted  
> ClassWrapper{className='org.apache.camel.component.jms.DefaultJmsMessageListenerContainer'}
>  Camel (camelContext) thread #120 - JmsConsumer[AN_ORACLE_AQ_CONSUMER_ROUTE]
> Mon May 10 11:39:23 EDT 2021    WARN    Setup of JMS message listener invoker 
> failed for destination 'AN_ORACLE_AQ_CONSUMER_ROUTE' - trying to recover. 
> Cause: JMS-257: receive(long timeout) of javax.jms.MessageConsumer took more 
> time than the network timeout configured at the java.sql.Connection.; nested 
> exception is java.sql.SQLRecoverableException: IO Error: Socket read 
> interrupted  
> ClassWrapper{className='org.apache.camel.component.jms.DefaultJmsMessageListenerContainer'}
>  Camel (camelContext) thread #120 - JmsConsumer[AN_ORACLE_AQ_CONSUMER_ROUTE]
> Mon May 10 11:39:23 EDT 2021    INFO    Route: another_route shutdown 
> complete, was consuming from: another_route   
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   Camel (camelContext) thread #3 - ShutdownTask
> ...
> about 63 more routes shutdown
> ...
> Mon May 10 12:06:25 EDT 2021    INFO    Route: AN_ORACLE_AQ_CONSUMER shutdown 
> complete, was consuming from: AN_ORACLE_AQ 
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>  Camel (camelContext) thread #3 - ShutdownTask
> ...
> more routes shutdown
> ...
> Mon May 10 12:06:25 EDT 2021    INFO    Shut down complete. 
> ClassWrapper{className='org.springframework.data.jdbc.jms.listener.oracle.AdtMessageListenerContainer'}
>  pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Shut down complete. 
> ClassWrapper{className='org.springframework.data.jdbc.jms.listener.oracle.AdtMessageListenerContainer'}
>  pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Shut down complete. 
> ClassWrapper{className='org.springframework.data.jdbc.jms.listener.oracle.AdtMessageListenerContainer'}
>  pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Shut down complete. 
> ClassWrapper{className='org.springframework.data.jdbc.jms.listener.oracle.AdtMessageListenerContainer'}
>  pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Shut down complete. 
> ClassWrapper{className='org.springframework.data.jdbc.jms.listener.oracle.AdtMessageListenerContainer'}
>  pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Shut down complete. 
> ClassWrapper{className='org.springframework.data.jdbc.jms.listener.oracle.AdtMessageListenerContainer'}
>  pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Shut down complete. 
> ClassWrapper{className='org.springframework.data.jdbc.jms.listener.oracle.AdtMessageListenerContainer'}
>  pool-183-thread-1
> ...
> the remainder of the routes shutdown
> ...
> Mon May 10 12:06:25 EDT 2021    INFO    Graceful shutdown of 119 routes 
> completed in 27m47s 
> ClassWrapper{className='org.apache.camel.impl.engine.DefaultShutdownStrategy'}
>   pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Apache Camel 3.7.2 (camelContext) 
> uptime 9h0m7s 
> ClassWrapper{className='org.apache.camel.impl.engine.AbstractCamelContext'} 
> pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Apache Camel 3.7.2 (camelContext) is 
> shutdown in 27m47s 
> ClassWrapper{className='org.apache.camel.impl.engine.AbstractCamelContext'} 
> pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    CamelContext: camelContext has been 
> shutdown, triggering shutdown of the JVM.   
> ClassWrapper{className='org.apache.camel.main.MainLifecycleStrategy'}   
> pool-183-thread-1
> Mon May 10 12:06:25 EDT 2021    INFO    Received hangup signal, stopping the 
> main instance. 
> ClassWrapper{className='org.apache.camel.main.DefaultMainShutdownStrategy'} 
> Camel Thread #135 - CamelHangupInterceptor
>
> From testing I have observed that the shutdown can take up to as long as the 
> length of the receiveTimeout of the Oracle AQ consumer route. A long 
> receiveTimeout with IBM MQ does not cause a delayed shutdown. I would like to 
> use the receiveTimeout to prevent overuse of the Oracle server cpu. I would 
> also like to shutdown my application in a short period of time.
>
> --
> Alex Mattern
>
> *************************** IMPORTANT NOTE*****************************
> The opinions expressed in this message and/or any attachments are those of 
> the author and not necessarily those of Brown Brothers Harriman & Co., its 
> subsidiaries and affiliates ("BBH"). There is no guarantee that this message 
> is either private or confidential, and it may have been altered by 
> unauthorized sources without your or our knowledge. Nothing in the message is 
> capable or intended to create any legally binding obligations on either party 
> and it is not intended to provide legal advice. BBH accepts no responsibility 
> for loss or damage from its use, including damage from virus.
> ******************************************************************************



-- 
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2

Reply via email to