You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by Ma...@brodos.net on 2018/08/06 13:14:18 UTC

Problem with camel route with sql endpoint and jpa

I have an Order and it has two type of todo tasks. There is as table where new todo entries are inserted. Camel route read todo entries and process it and with help of jpa(hibernate) and processing result is stored in database and todo entries are also deleted.

This looks working in general except one case which just happend once since last month, that when jpa go to store processing result to database , it took more than 10 minute and I got transaction rollback exception. The problem is that the log does not tell what was wrong there with jpa and what need to fixed?

Tools used : Apache karaf, Camel, Hibernate (Jpa), Mariadb

-- Camel route in blueprint file
<route id="order-todo-type1-processing" autoStartup="{{order-dispatcher}}">
    <from uri="sql:SELECT tdt.order_id FROM order_todo_task tdt where tdt.type='TYPE-1'?dataSource=OrderData&amp;consumer.delay=30000" />
    <to uri="bean:processorOrderTodoType1?method=process" />
</route>
<route id="order-todo-type2-processing" autoStartup="{{order-dispatcher}}">
    <from uri="sql:SELECT tdt.order_id FROM order_todo_task tdt where tdt.type='TYPE-2'?dataSource=OrderData&amp;consumer.delay=30000" />
    <to uri="bean:processorOrderTodoType2?method=process" />
</route>

-- Domain entities
@Entity
@Table(name = "order")
Class Order {
    @Id
    @Column(name = "id", unique = true, nullable = false)
    private Long id;

    @OneToMany(mappedBy = "order_id", cascade = CascadeType.ALL, fetch = FetchType.EAGER, orphanRemoval = true)
    private Set<TodoTask> tasks;

    @OneToMany(mappedBy = "order_id", cascade = CascadeType.ALL, fetch = FetchType.EAGER)
    private Set<TodoProcessingLogs> todoProcessingLogs;

}
-- class for processing of todo type-1 
class ProcessorOrderTodoType1 {

    OrderService service;//inject as osgi service and use jpa entity manager


    public void process(Map<String, Object> data) {
	    String orderId = data.get("order_id").toString();
	    Order order = em.find(Order.class, orderId);
	    //do business processing step - 1
	    order.getTodoProcessingLogs.add(new TodoProcessingLogs(....));
	    service.merge(order);//save partial processing status
	    //do business processing step - 2
	    order.removeSpecifiedTodoType("TYPE-1");
	    ...
	    service.merge(order);
    }

}
-- Error logs
 | ERROR | _fk%20=%20tft.id | DefaultErrorHandler   		   | 78 - org.apache.camel.camel-core - 2.18.0 | Failed delivery for (MessageId: ID-d8f4bff62acc-41735-1531810001157-0-15905 on ExchangeId: ID-d8f4bff62acc-41735-1531810001157-0-15906). Exhausted after delivery attempt: 1 caught: javax.transaction.RollbackException

Message History
---------------------------------------------------------------------------------------------------------------------------------------
RouteId			  ProcessorId   	   Processor  																	  Elapsed (ms)
[order-todo-type1-processing   ] [order-todo-type1-processing   ] [sql://SELECT tdt.order_id FROM order_todo_task tdt where tdt.type='TYPE-1'] [    804724]
[order-todo-type1-processing   ] [to1  			 ] [bean:processorOrderTodoType1?method=process					   ] [    804722]

Stacktrace
---------------------------------------------------------------------------------------------------------------------------------------
javax.transaction.RollbackException
    at org.apache.aries.transaction.TxInterceptorImpl.postCallWithReturn(TxInterceptorImpl.java:109)
    at org.apache.aries.blueprint.proxy.Collaborator.postInvoke(Collaborator.java:98)
    at Proxy8af2e5ee_c7cb_4f0f_b75b_dacb4d121b4f.merge(Unknown Source)
    at Proxy22cba4f1_c863_4172_bb5c_72387fe65471.merge(Unknown Source)
    at com.mycompany.ProcessorOrderTodoType1.save(ProcessorOrderTodoType1.java:39)
    at Proxy7bce399e_051e_45f0_a58a_2bbec26edb59.save(Unknown Source)
    at com.mycompany.ProcessorOrderTodoType1.process(ProcessorOrderTodoType1.java:5)[11:com.mycompany.order-application:1.0.6]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_162]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_162]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_162]
    at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_162]
    at org.apache.camel.component.bean.MethodInfo.invoke(MethodInfo.java:435)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.MethodInfo$1.doProceed(MethodInfo.java:286)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.MethodInfo$1.proceed(MethodInfo.java:259)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.BeanProcessor.process(BeanProcessor.java:178)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.BeanProducer.process(BeanProducer.java:41)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:145)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:77)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:542)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:197)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.Pipeline.process(Pipeline.java:120)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.Pipeline.process(Pipeline.java:83)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:197)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:97)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.sql.SqlConsumer.processBatch(SqlConsumer.java:233)[80:org.apache.camel.camel-sql:2.18.0]
    at org.apache.camel.component.sql.SqlConsumer$1.doInPreparedStatement(SqlConsumer.java:153)[80:org.apache.camel.camel-sql:2.18.0]
    at org.apache.camel.component.sql.SqlConsumer$1.doInPreparedStatement(SqlConsumer.java:112)[80:org.apache.camel.camel-sql:2.18.0]
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:633)[165:org.apache.servicemix.bundles.spring-jdbc:4.3.5.RELEASE_1]
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:662)[165:org.apache.servicemix.bundles.spring-jdbc:4.3.5.RELEASE_1]
    at org.apache.camel.component.sql.SqlConsumer.poll(SqlConsumer.java:168)[80:org.apache.camel.camel-sql:2.18.0]
    at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:175)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:102)[78:org.apache.camel.camel-core:2.18.0]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_162]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)[:1.8.0_162]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)[:1.8.0_162]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)[:1.8.0_162]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[:1.8.0_162]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)[:1.8.0_162]
    at java.lang.Thread.run(Thread.java:748)[:1.8.0_162]

Problem with camel route with sql endpoint and jpa

Posted by Ma...@brodos.net.
I have an Order and it has two type of todo tasks. There is as table where new todo entries are inserted. Camel route read todo entries and process it and with help of jpa(hibernate) and processing result is stored in database and todo entries are also deleted.

This looks working in general except one case which just happend once since last month, that when jpa go to store processing result to database , it took more than 10 minute and I got transaction rollback exception. The problem is that the log does not tell what was wrong there with jpa and what need to fixed?

Tools used : Apache karaf, Camel, Hibernate (Jpa), Mariadb

-- Camel route in blueprint file
<route id="order-todo-type1-processing" autoStartup="{{order-dispatcher}}">
    <from uri="sql:SELECT tdt.order_id FROM order_todo_task tdt where tdt.type='TYPE-1'?dataSource=OrderData&amp;consumer.delay=30000" />
    <to uri="bean:processorOrderTodoType1?method=process" />
</route>
<route id="order-todo-type2-processing" autoStartup="{{order-dispatcher}}">
    <from uri="sql:SELECT tdt.order_id FROM order_todo_task tdt where tdt.type='TYPE-2'?dataSource=OrderData&amp;consumer.delay=30000" />
    <to uri="bean:processorOrderTodoType2?method=process" />
</route>

-- Domain entities
@Entity
@Table(name = "order")
Class Order {
    @Id
    @Column(name = "id", unique = true, nullable = false)
    private Long id;

    @OneToMany(mappedBy = "order_id", cascade = CascadeType.ALL, fetch = FetchType.EAGER, orphanRemoval = true)
    private Set<TodoTask> tasks;

    @OneToMany(mappedBy = "order_id", cascade = CascadeType.ALL, fetch = FetchType.EAGER)
    private Set<TodoProcessingLogs> todoProcessingLogs;

}
-- class for processing of todo type-1 
class ProcessorOrderTodoType1 {

    OrderService service;//inject as osgi service and use jpa entity manager


    public void process(Map<String, Object> data) {
	    String orderId = data.get("order_id").toString();
	    Order order = em.find(Order.class, orderId);
	    //do business processing step - 1
	    order.getTodoProcessingLogs.add(new TodoProcessingLogs(....));
	    service.merge(order);//save partial processing status
	    //do business processing step - 2
	    order.removeSpecifiedTodoType("TYPE-1");
	    ...
	    service.merge(order);
    }

}
-- Error logs
 | ERROR | _fk%20=%20tft.id | DefaultErrorHandler   		   | 78 - org.apache.camel.camel-core - 2.18.0 | Failed delivery for (MessageId: ID-d8f4bff62acc-41735-1531810001157-0-15905 on ExchangeId: ID-d8f4bff62acc-41735-1531810001157-0-15906). Exhausted after delivery attempt: 1 caught: javax.transaction.RollbackException

Message History
---------------------------------------------------------------------------------------------------------------------------------------
RouteId			  ProcessorId   	   Processor  																	  Elapsed (ms)
[order-todo-type1-processing   ] [order-todo-type1-processing   ] [sql://SELECT tdt.order_id FROM order_todo_task tdt where tdt.type='TYPE-1'] [    804724]
[order-todo-type1-processing   ] [to1  			 ] [bean:processorOrderTodoType1?method=process					   ] [    804722]

Stacktrace
---------------------------------------------------------------------------------------------------------------------------------------
javax.transaction.RollbackException
    at org.apache.aries.transaction.TxInterceptorImpl.postCallWithReturn(TxInterceptorImpl.java:109)
    at org.apache.aries.blueprint.proxy.Collaborator.postInvoke(Collaborator.java:98)
    at Proxy8af2e5ee_c7cb_4f0f_b75b_dacb4d121b4f.merge(Unknown Source)
    at Proxy22cba4f1_c863_4172_bb5c_72387fe65471.merge(Unknown Source)
    at com.mycompany.ProcessorOrderTodoType1.save(ProcessorOrderTodoType1.java:39)
    at Proxy7bce399e_051e_45f0_a58a_2bbec26edb59.save(Unknown Source)
    at com.mycompany.ProcessorOrderTodoType1.process(ProcessorOrderTodoType1.java:5)[11:com.mycompany.order-application:1.0.6]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_162]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_162]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_162]
    at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_162]
    at org.apache.camel.component.bean.MethodInfo.invoke(MethodInfo.java:435)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.MethodInfo$1.doProceed(MethodInfo.java:286)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.MethodInfo$1.proceed(MethodInfo.java:259)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.BeanProcessor.process(BeanProcessor.java:178)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.bean.BeanProducer.process(BeanProducer.java:41)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:145)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:77)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:542)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:197)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.Pipeline.process(Pipeline.java:120)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.Pipeline.process(Pipeline.java:83)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:197)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:97)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.component.sql.SqlConsumer.processBatch(SqlConsumer.java:233)[80:org.apache.camel.camel-sql:2.18.0]
    at org.apache.camel.component.sql.SqlConsumer$1.doInPreparedStatement(SqlConsumer.java:153)[80:org.apache.camel.camel-sql:2.18.0]
    at org.apache.camel.component.sql.SqlConsumer$1.doInPreparedStatement(SqlConsumer.java:112)[80:org.apache.camel.camel-sql:2.18.0]
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:633)[165:org.apache.servicemix.bundles.spring-jdbc:4.3.5.RELEASE_1]
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:662)[165:org.apache.servicemix.bundles.spring-jdbc:4.3.5.RELEASE_1]
    at org.apache.camel.component.sql.SqlConsumer.poll(SqlConsumer.java:168)[80:org.apache.camel.camel-sql:2.18.0]
    at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:175)[78:org.apache.camel.camel-core:2.18.0]
    at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:102)[78:org.apache.camel.camel-core:2.18.0]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_162]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)[:1.8.0_162]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)[:1.8.0_162]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)[:1.8.0_162]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[:1.8.0_162]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)[:1.8.0_162]
    at java.lang.Thread.run(Thread.java:748)[:1.8.0_162]