6 Replies Latest reply on Feb 24, 2012 6:18 AM by pickup_uh

    loadbalance-failover misbehavior and RoutePolicy

    pickup_uh

      Hi Bedus (a.k.a. CamelRiders)

       

      I am currently using Camel 7.3.2 and tailored some test application where a route is started from a customized RoutePolicy. The route reads a file and splits it into lines which are fed into a pair of loadbalanced queues.

      As long as the loadbalancing ist not "failover" the system processes perfectly, as soon as I activate "failover roundrobin" the system complaints about "Index out of bounds". My StartPolicy Implementation is only performing a start(route) and not doing anything disgusting.

       

      Reversely, if I set the route to be activated from start of application and not by RoutePolicy->start(route), loadbalancing works with failover option as expected.

       

      I've already set "inheritErrorHandler" on false on the <loadbalace> tag. But did not help.

       

      Did I simply misunderstand the interference of the concepts of "failover" and "StartPolicy" or is there any configuration option parameter that I missed ?

       

      I ve provided the complete project in the attached zip File.

       

      Thank you very much for a hint indeed

       

      cheers

       

      Uli

       

      Here is the Context xml snippet. Find the log below

       

      <camelContext xmlns="http://camel.apache.org/schema/spring">

      <threadPool id="poolOne" threadName= "Splitter" maxPoolSize="10" poolSize="2" keepAliveTime="2" />

      <onException>

      <exception>*.</exception>

        <handled><constant>true</constant></handled>

        <process ref="anyExceptionFailure"/>

      </onException>

        <route id="RetrieveFile" routePolicyRef="triggeredStartPolicy" autoStartup="false">

          <from uri="file:data/?fileName=Instruments$.txt"/>

          <transacted ref="required"/>

           <log message="Processing file: ${header.CamelFileName}"/>

            <threads executorServiceRef="poolOne" >

             <split stopOnException="false" streaming="true" parallelProcessing="true" >

              <tokenize token="\n"/>

               <choice>

                <when>

                 <simple>$ < 6</simple>

                 <log message="skip header record #: $"/>

                 <log message="skip body: $"/>           </when>           <otherwise>            <loadBalance inheritErrorHandler="false">            <failover roundRobin="true" maximumFailoverAttempts="2"/>            <!-- <random/> -->             <log message="write body: $"/>

                   <to uri="jms:refInstrumentDataA"/>

                   <to uri="jms:refInstrumentDataB"/>

                  </loadBalance>

                 </otherwise>

               </choice>

             </split>

            </threads>

      </route>

       

      The Log:

      INFO  10:31:51,128                           main MainSupport                    Apache Camel 2.7.3 starting

      INFO  10:31:51,897                           main CamelNamespaceHandler          OSGi environment not detected.

      INFO  10:31:52,791                           main BrokerService                  Using Persistence Adapter: MemoryPersistenceAdapter

      INFO  10:31:52,791                           main BrokerService                  ActiveMQ 5.3.2 JMS Message Broker (localhost) is starting

      INFO  10:31:52,791                           main BrokerService                  For help or more information please see: http://activemq.apache.org/

      INFO  10:31:53,027                           main Tr<camelContext xmlns="http://camel.apache.org/schema/spring">

      INFO  10:31:53,027                           main TransportConnector             Connector tcp://localhost:61616 Started

      INFO  10:31:53,027                           main BrokerService                  ActiveMQ JMS Message Broker (localhost, ID:MGIN8K-2235-1329989512823-0:0) started

      WARN  10:31:53,168                           main atomikos                       Local heuristic termination of coordinator 10.106.2.115.tm0000600137 with state COMMITTING

      WARN  10:31:53,168                           main atomikos                       Local heuristic termination of coordinator 10.106.2.115.tm0001100137 with state COMMITTING

      • * * *

      INFO  10:31:53,670                           main SpringCamelContext             Apache Camel 2.7.3 (CamelContext: camel-1) is starting

      INFO  10:31:53,670                           main SpringCamelContext             JMX enabled. Using ManagedManagementStrategy.

      INFO  10:31:54,345                           main AnnotationTypeConverterLoader  Found 4 packages with 15 @Converter classes to load

      INFO  10:31:54,361                           main DefaultTypeConverter           Loaded 151 type converters in 0.518 seconds

      INFO  10:31:54,675                           main RoutePolicySupport             trigger: Route "RetrieveFile" starting up - send start Signal

      INFO  10:31:54,675                           main RoutePolicySupport             trigger: Route "RetrieveFile" is up&running

      INFO  10:31:54,675                       Thread-2 RoutePolicySupport             TriggeredStartPolicy received Trigger Event

      INFO  10:31:54,675                       Thread-2 RoutePolicySupport             trigger: Route "RetrieveFile" is going down - send stop Signal

      INFO  10:31:54,832                           main SpringCamelContext             Cannot start route RetrieveFile as its configured with autoStartup=false

      INFO  10:31:54,879                           main TransportConnector             Connector vm://localhost Started

      INFO  10:31:54,989                       Thread-2 DefaultShutdownStrategy        Starting to graceful shutdown 1 routes (timeout 300 seconds)

      INFO  10:31:54,989 el-1) thread #2 - ShutdownTask DefaultShutdownStrategy        Route: RetrieveFile suspended and shutdown deferred, was consuming from: Endpoint

      INFO  10:31:54,989 el-1) thread #2 - ShutdownTask DefaultShutdownStrategy        Route: RetrieveFile preparing to shutdown complete.

      INFO  10:31:54,989 el-1) thread #2 - ShutdownTask DefaultShutdownStrategy        Route: RetrieveFile shutdown complete.

      INFO  10:31:54,989                       Thread-2 DefaultShutdownStrategy        Graceful shutdown of 1 routes completed in 0 seconds

      INFO  10:31:54,989                       Thread-2 SpringCamelContext             Route: RetrieveFile stopped, was consuming from: Endpoint

      INFO  10:31:54,989                       Thread-2 RoutePolicySupport             trigger: Route "RetrieveFile" is down

      INFO  10:31:54,989                           main SpringCamelContext             Total 2 routes, of which 2 is started.

      INFO  10:31:54,989                           main SpringCamelContext             Apache Camel 2.7.3 (CamelContext: camel-1) started in 1.334 seconds

      INFO  10:32:25,121                       Thread-2 RoutePolicySupport             TriggeredStartPolicy received Trigger Event

      INFO  10:32:25,121                       Thread-2 RoutePolicySupport             trigger: Route "RetrieveFile" starting up - send start Signal

      INFO  10:32:25,168                       Thread-2 SpringCamelContext             Route: RetrieveFile started and consuming from: Endpoint

      INFO  10:32:25,168                       Thread-2 RoutePolicySupport             trigger: Route "RetrieveFile" is up&running

      INFO  10:32:26,172  atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000100138

      INFO  10:32:26,188  RetrieveFile                   Processing file: Instruments20120223.txt

      INFO  10:32:26,204 el (camel-1) thread #5 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000200138

      INFO  10:32:26,204 el (camel-1) thread #8 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000400138

      INFO  10:32:26,204 el (camel-1) thread #7 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000300138

      INFO  10:32:26,204 el (camel-1) thread #9 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000500138

      INFO  10:32:26,204 l (camel-1) thread #10 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000600138

      INFO  10:32:26,204 el (camel-1) thread #7 - Split RetrieveFile                   skip header record #: 1

      INFO  10:32:26,204 l (camel-1) thread #10 - Split RetrieveFile                   skip header record #: 4

      INFO  10:32:26,204 el (camel-1) thread #7 - Split RetrieveFile                   skip body: XETR, XBUL, XEUB, XEEE (Frankfurt 1): 04.02.2012

      INFO  10:32:26,204 el (camel-1) thread #5 - Split RetrieveFile                   skip header record #: 0

      INFO  10:32:26,204 el (camel-1) thread #5 - Split RetrieveFile                   skip body: Date Last Update:

      INFO  10:32:26,204 el (camel-1) thread #9 - Split RetrieveFile                   skip header record #: 3

      INFO  10:32:26,204 el (camel-1) thread #9 - Split RetrieveFile                   skip body: XDUB (Dublin): 04.02.2012

      INFO  10:32:26,204 l (camel-1) thread #10 - Split RetrieveFile                   skip body: XETI (Xetra International Market): 04.02.2012

      INFO  10:32:26,204 el (camel-1) thread #8 - Split RetrieveFile                   skip header record #: 2

      INFO  10:32:26,204 el (camel-1) thread #8 - Split RetrieveFile                   skip body: XFRA (Frankfurt 2): 04.02.2012

      INFO  10:32:26,204 l (camel-1) thread #11 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000700138

      INFO  10:32:26,204 l (camel-1) thread #11 - Split RetrieveFile                   skip header record #: 5

      INFO  10:32:26,204 l (camel-1) thread #11 - Split RetrieveFile                   skip body: Date Last Update;Instrument;ISIN;ISIX;WKN;Mnemonic;MIC Code;CCP * * * * *

      INFO  10:32:26,204 l (camel-1) thread #12 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000800138

      INFO  10:32:26,204 el (camel-1) thread #9 - Split atomikos                       commit() done (by application) of transaction 10.106.2.115.tm0000500138

      INFO  10:32:26,204 el (camel-1) thread #7 - Split atomikos                       commit() done (by application) of transaction 10.106.2.115.tm0000300138

      INFO  10:32:26,204 el (camel-1) thread #8 - Split atomikos                       commit() done (by application) of transaction 10.106.2.115.tm0000400138

      INFO  10:32:26,204 l (camel-1) thread #11 - Split atomikos                       commit() done (by application) of transaction 10.106.2.115.tm0000700138

      INFO  10:32:26,204 l (camel-1) thread #10 - Split atomikos                       commit() done (by application) of transaction 10.106.2.115.tm0000600138

      INFO  10:32:26,204 el (camel-1) thread #5 - Split atomikos                       commit() done (by application) of transaction 10.106.2.115.tm0000200138

      INFO  10:32:26,219 l (camel-1) thread #13 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0000900138

      INFO  10:32:26,219 l (camel-1) thread #15 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0001000138

      INFO  10:32:26,219 l (camel-1) thread #14 - Split atomikos                       createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.106.2.115.tm0001100138

      ERROR 10:32:26,219 l (camel-1) thread #14 - Split DefaultErrorHandler            Failed delivery for exchangeId: ID-MGIN8K-2236-1329989513419-0-12. Exhausted after delivery attempt: 1 caught: java.lang.ArrayIndexOutOfBoundsException: 0

      java.lang.ArrayIndexOutOfBoundsException: 0

       

       

      • at java.util.concurrent.CopyOnWriteArrayList.get(Unknown Source):1.6.0_29*

       

      Edited by: pickup on Feb 23, 2012 10:32 AM

       

      Edited by: pickup on Feb 23, 2012 10:57 AM

        • 1. Re: loadbalance-failover misbehavior and RoutePolicy
          davsclaus

          Can you past the full strack trace?

           

          And also its hard to read your configuration due the xml tags. Maybe attach them as files.

           

          If you are a FuseSource subscriber, then I suggest to use that channel to get help.

          • 2. Re: loadbalance-failover misbehavior and RoutePolicy
            pickup_uh

            Thank you for response. The log & Stack Trace is attached to this post as a text file. And I ve just edited my origibal post to include the project.

             

            Uli

            • 3. Re: loadbalance-failover misbehavior and RoutePolicy
              davsclaus

              Okay so you say that having a  with autoStartup=false, and the route has a failover loadbalancer. And when you later start the route, then the failover loadbalancer does not work, as it throws that IndexOutOfBoundsException.

               

              And it works fine, if you set autoStartup=true.

               

              Is this correct?

              • 4. Re: loadbalance-failover misbehavior and RoutePolicy
                pickup_uh

                Thank you for coming back.

                 

                "autostart=true" and simultaneously deleting the attribute routePolicyRef="triggeredStartPolicy"

                from the route entry:

                 

                1.) route id="RetrieveFile" routePolicyRef="triggeredStartPolicy" autoStartup="false"

                2.) route id="RetrieveFile" autoStartup="true"    (default anyway)

                 

                In 1.) the route is started from RoutePolicy "triggeredStartPolicy"" by calling the start(route) method explicitely a couple of seconds (30) after the application is up & runing. This config causes the Exception after activation of the route

                In 2.) everything works perfectly as designed.

                • 5. Re: loadbalance-failover misbehavior and RoutePolicy
                  davsclaus

                  You may have to upgrade to a newer release of Camel to have this issue fixed.

                   

                  I added an unit test on Camel trunk and it works fine.

                   

                  Apache Camel 2.7.x is no longer supported at Apache. But you can try the latest 2.7.x release. Or upgrade to a 2.8 or 2.9 branch.

                   

                  Alternative the Fuse Camel 2.7.x releases is supported for a longer period of time by us from FuseSource.

                  • 6. Re: loadbalance-failover misbehavior and RoutePolicy
                    pickup_uh

                    After using suspend and resume instead of stop(route) and start(route) in a Observer-class which "extends RoutePolicySupport()" it was possible to achieve the application to behave as originally intended.

                     

                    Thus it is possible to activate and shutdown a route triggered from outside Camel.

                     

                    CamelContext con = route.getRouteContext().getCamelContext();

                    con.suspendRoute(route.getId());

                    con.resumeRoute(route.getId());