Bug 777984 (SOA-513)

Link: Added: This issue depends JBESB-1648

Increasing severity level to spur investigation - the issue can be not in quickstart but in TX processing

No, the issue could well be with the quickstart.

That is what I meant, just to clarify
Increasing severity level to spur investigation - the issue can be not only in quickstart but also in TX processing

Link: Added: This issue related SOA-514

Attaching sever logs  from GA and CP01.

The test runs successfully in GA - not in CP01.

Attachment: Added: CP01_server.log
Attachment: Added: GA_server.log

The issue is in the TX processing and there are two parts to it.

- add the correct TX code to message aware listener (after the rewrite)
- fix the SQL resource handling

The first is my fault and I am about to commit the changes into our CP branch and trunk.  The second was raised by Tom Fennelly shortly before the CP release and he has been working on fixing this.

The fact that this QS worked in the GA release appears to have been a fluke.

I'll follow this up.

Link: Added: This issue related JBQA-1570

Closing - fix verified in April 15 2008 CP01 build.

This message - in the server.log -  may be alarming at first glance:

12:24:28,140 INFO  [STDOUT] BAD READ ON DATA!

But - it is correct:

                  // Set message properties and message body so that SystemPrintln will display message 
                  message.getProperties().setProperty("jbesbfilename", "helloworldTxSQlAction.log");
                  message.getBody().add(results.toString());

                  if (problem)
                          System.out.println("Will rollback transaction. Expect to see record again!");
                  else
                          System.out.println("Will commit transaction. Will not see record again!");

                  if (!problem)
                          return message;
                  else
                  {
                          System.out.println("BAD READ ON DATA!");

                          throw new RuntimeException();
                  }


&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
12:24:28,139 INFO  [STDOUT] DATA READ: data 22
12:24:28,140 INFO  [STDOUT] column DATA_COLUMN = <data 22>column TIMESTAMP_COL = <null>column UNIQUE_ID = <2>
12:24:28,140 INFO  [STDOUT] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
12:24:28,140 INFO  [STDOUT] Will rollback transaction. Expect to see record again!
12:24:28,140 INFO  [STDOUT] BAD READ ON DATA!
12:24:28,142 WARN  [ActionProcessingPipeline] Unexpected exception caught while processing the action pipeline: header: [ To: JDBCEpr [ PortReference < <wsa:Address jdbc:hsqldb:hsql://localhost:1703/>, <wsa:ReferenceProperties jbossesb:postDelete : true/>, <wsa:ReferenceProperties jbossesb:errorDelete : true/>, <wsa:ReferenceProperties jbossesb:datasource : java:/QuickstartDB/>, <wsa:ReferenceProperties jbossesb:tablename : TX_ESB_MESSAGES/>, <wsa:ReferenceProperties jbossesb:message_id_column : MESSAGE_ID/>, <wsa:ReferenceProperties jbossesb:status_column : STATUS_COL/>, <wsa:ReferenceProperties jbossesb:message_column : DATA_COLUMN/>, <wsa:ReferenceProperties jbossesb:insert_timestamp_column : TIMESTAMP_COL/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jdbc/> > ] MessageID: 18fe7384-e01b-42e0-a10b-28337f1e252f ]
java.lang.RuntimeException
        at org.jboss.soa.esb.samples.quickstart.helloworldtxsqlaction.MyAction.displayMessage(MyAction.java:74)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.jboss.soa.esb.listeners.message.ActionProcessorMethodInfo.processMethods(ActionProcessorMethodInfo.java:102)
        at org.jboss.soa.esb.listeners.message.OverriddenActionLifecycleProcessor.process(OverriddenActionLifecycleProcessor.java:74)
        at org.jboss.soa.esb.listeners.message.ActionProcessingPipeline.process(ActionProcessingPipeline.java:316)
        at org.jboss.soa.esb.listeners.message.MessageAwareListener$TransactionalRunner.run(MessageAwareListener.java:530)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
12:24:28,181 ERROR [STDERR] Exception in thread "pool-9-thread-1" 
12:24:28,182 ERROR [STDERR] java.lang.RuntimeException
12:24:28,182 ERROR [STDERR]     at org.jboss.soa.esb.samples.quickstart.helloworldtxsqlaction.MyAction.displayMessage(MyAction.java:74)
12:24:28,182 ERROR [STDERR]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
12:24:28,182 ERROR [STDERR]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
12:24:28,182 ERROR [STDERR]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
12:24:28,182 ERROR [STDERR]     at java.lang.reflect.Method.invoke(Method.java:585)
12:24:28,182 ERROR [STDERR]     at org.jboss.soa.esb.listeners.message.ActionProcessorMethodInfo.processMethods(ActionProcessorMethodInfo.java:102)
12:24:28,182 ERROR [STDERR]     at org.jboss.soa.esb.listeners.message.OverriddenActionLifecycleProcessor.process(OverriddenActionLifecycleProcessor.java:74)
12:24:28,182 ERROR [STDERR]     at org.jboss.soa.esb.listeners.message.ActionProcessingPipeline.process(ActionProcessingPipeline.java:316)
12:24:28,183 ERROR [STDERR]     at org.jboss.soa.esb.listeners.message.MessageAwareListener$TransactionalRunner.run(MessageAwareListener.java:530)
12:24:28,183 ERROR [STDERR]     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
12:24:28,183 ERROR [STDERR]     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
12:24:28,183 ERROR [STDERR]     at java.lang.Thread.run(Thread.java:595)
12:24:28,184 INFO  [STDOUT] 
&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
12:24:28,184 INFO  [STDOUT] DATA READ: data 22
12:24:28,185 INFO  [STDOUT] column DATA_COLUMN = <data 22>column TIMESTAMP_COL = <null>column UNIQUE_ID = <2>
12:24:28,185 INFO  [STDOUT] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
12:24:28,185 INFO  [STDOUT] Will commit transaction. Will not see record again!
12:24:28,186 INFO  [STDOUT] Message structure: 
12:24:28,186 INFO  [STDOUT] [column DATA_COLUMN = <data 22>column TIMESTAMP_COL = <null>column UNIQUE_ID = <2>].
12:24:28,262 INFO  [STDOUT]