Uploaded image for project: 'OFBiz'
  1. OFBiz
  2. OFBIZ-9725

Transaction Timeout in JavaEventHandler

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: Release Branch 14.12, Release Branch 16.11
    • Fix Version/s: 16.11.04
    • Component/s: framework/webtools
    • Labels:
      None
    • Environment:

      Red Hat Enterprise Linux, release branch 14.12
      Ubuntu 17.04, release branch 16.11.03

      Description

      I have a service that is scheduled using the webtools scheduler.

      I am attempting to use the following service definition

      <service name="myCustomService" engine="java" transaction-timeout="36000" require-new-transaction="true"
                   location="my.package" invoke="myCustomService" auth="true">
              <description>Run this very long function</description>
          </service>
      

      The function in question is getting data from an oracle database and sanitizing the records and then inserting them into a postgresql database. There are millions of records in the oracle database and I am grabbing the records in batches of 200, sanitizing them then committing them using a GenericValue.create() method. This continues for 100 iterations.

      Using verbose logging we have the following log messages to indicate that the transaction timeout is being used...

      2017-09-15 06:30:48,372 |http-bio-8443-exec-8 |ServiceDispatcher             |D| [ServiceDispatcher.runSync] : invoking service myCustomService [my.package/myCustomService] (java)
      2017-09-15 06:30:48,372 |http-bio-8443-exec-8 |TransactionUtil               |D| Current status : No Transaction (6)
      2017-09-15 06:30:48,372 |http-bio-8443-exec-8 |TransactionUtil               |D| Set transaction timeout to : 36000 seconds
      2017-09-15 06:30:48,372 |http-bio-8443-exec-8 |TransactionUtil               |D| Transaction begun
      
      2017-09-15 06:49:36,444 |http-bio-8443-exec-4 |MigrationServices             |I| Ending myCustomService ::: 2017-09-15T06:49:36.444
      2017-09-15 06:49:36,444 |http-bio-8443-exec-4 |ModelService                  |D| [ModelService.validate] : {myCustomService} : Validating context - {responseMessage=success}
      2017-09-15 06:49:36,444 |http-bio-8443-exec-4 |ModelService                  |D| [ModelService.validate] : required fields -
      2017-09-15 06:49:36,444 |http-bio-8443-exec-4 |ModelService                  |D| [ModelService.validate] : {myCustomService} : (OUT) Required - 0 / 0
      2017-09-15 06:49:36,444 |http-bio-8443-exec-4 |ModelService                  |D| [ModelService.validate] : {myCustomService} : (OUT) Optional - 1 / 8
      2017-09-15 06:49:36,444 |http-bio-8443-exec-4 |TransactionUtil               |D| Current status : Transaction Active (0)
      2017-09-15 06:49:36,482 |http-bio-8443-exec-4 |TransactionUtil               |D| Transaction committed
      2017-09-15 06:49:36,482 |http-bio-8443-exec-4 |Converters                    |D| Getting converter: java.lang.String->java.lang.Long
      2017-09-15 06:49:36,482 |http-bio-8443-exec-4 |Converters                    |D| Getting converter: java.lang.String->java.lang.Long
      2017-09-15 06:49:36,482 |http-bio-8443-exec-4 |ServiceDispatcher             |T| Sync service [webtools/myCustomService] finished in [552515] milliseconds
      2017-09-15 06:49:36,482 |http-bio-8443-exec-4 |ServiceDispatcher             |D| Sync service [webtools/myCustomService] finished with response [{responseMessage=success}]
      2017-09-15 06:49:36,482 |http-bio-8443-exec-4 |JavaEventHandler              |D| [Event Return]: sync_success
      2017-09-15 06:49:36,482 |http-bio-8443-exec-4 |TransactionUtil               |D| Current status : Transaction Active (0)
      2017-09-15 06:49:36,491 |http-bio-8443-exec-4 |TransactionUtil               |W| In getSetRollbackOnlyCause no stack placeholder was in place, here is the current location:
      java.lang.Exception: Current Stack Trace
          at org.ofbiz.entity.transaction.TransactionUtil.getSetRollbackOnlyCause(TransactionUtil.java:840) [ofbiz-base.jar!/:?]
          at org.ofbiz.entity.transaction.TransactionUtil.commit(TransactionUtil.java:261) [ofbiz-base.jar!/:?]
          at org.ofbiz.entity.transaction.TransactionUtil.commit(TransactionUtil.java:234) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:115) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:80) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.RequestHandler.runEvent(RequestHandler.java:763) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.RequestHandler.doRequest(RequestHandler.java:476) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.ControlServlet.doGet(ControlServlet.java:210) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.ControlServlet.doPost(ControlServlet.java:89) [ofbiz-base.jar!/:?]
          at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [servlet-api-3.0.jar:?]
          at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) [servlet-api-3.0.jar:?]
          at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.ofbiz.webapp.control.ContextFilter.doFilter(ContextFilter.java:349) [ofbiz-base.jar!/:?]
          at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardContextValve.__invoke(StandardContextValve.java:122) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121]
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121]
          at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121]
      2017-09-15 06:49:36,511 |http-bio-8443-exec-4 |JavaEventHandler              |E| null
      org.ofbiz.entity.transaction.GenericTransactionException: Roll back error (with no rollbackOnly cause found), could not commit transaction, was rolled back instead: java.lang.Exception: Transaction has timed out (Transaction has timed out)
          at org.ofbiz.entity.transaction.TransactionUtil.commit(TransactionUtil.java:273) ~[ofbiz-base.jar!/:?]
          at org.ofbiz.entity.transaction.TransactionUtil.commit(TransactionUtil.java:234) ~[ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:115) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:80) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.RequestHandler.runEvent(RequestHandler.java:763) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.RequestHandler.doRequest(RequestHandler.java:476) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.ControlServlet.doGet(ControlServlet.java:210) [ofbiz-base.jar!/:?]
          at org.ofbiz.webapp.control.ControlServlet.doPost(ControlServlet.java:89) [ofbiz-base.jar!/:?]
          at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [servlet-api-3.0.jar:?]
          at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) [servlet-api-3.0.jar:?]
          at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.ofbiz.webapp.control.ContextFilter.doFilter(ContextFilter.java:349) [ofbiz-base.jar!/:?]
          at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardContextValve.__invoke(StandardContextValve.java:122) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423) [tomcat-7.0.65-catalina.jar:7.0.65]
          at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121]
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121]
          at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-7.0.65-tomcat-coyote.jar:7.0.65]
          at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121]
      Caused by: java.lang.Exception: Transaction has timed out
          at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:266) ~[geronimo-transaction-3.1.1.jar:3.1.1]
          at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252) ~[geronimo-transaction-3.1.1.jar:3.1.1]
          at org.ofbiz.entity.transaction.TransactionUtil.commit(TransactionUtil.java:248) ~[ofbiz-base.jar!/:?]
          ... 30 more
      

      So, I have the transaction timeout set to 36,000 seconds and the job finishes in 552,515 milliseconds (about 9.2 minutes), but then the JavaEventHandler's finally clause hits a commit and that causes a timeout

      private String invoke(String eventPath, String eventMethod, Class<?> eventClass, Class<?>[] paramTypes, Object[] params) throws EventHandlerException {
              boolean beganTransaction = false;
              if (eventClass == null) {
                  throw new EventHandlerException("Error invoking event, the class " + eventPath + " was not found");
              }
              if (eventPath == null || eventMethod == null) {
                  throw new EventHandlerException("Invalid event method or path; call initialize()");
              }
      
              Debug.logVerbose("[Processing]: JAVA Event", module);
              try {
                  beganTransaction = TransactionUtil.begin();
                  Method m = eventClass.getMethod(eventMethod, paramTypes);
                  String eventReturn = (String) m.invoke(null, params);
      
                  if (Debug.verboseOn()) Debug.logVerbose("[Event Return]: " + eventReturn, module);
                  return eventReturn;
              } catch (java.lang.reflect.InvocationTargetException e) {
                  Throwable t = e.getTargetException();
      
                  if (t != null) {
                      Debug.logError(t, "Problems Processing Event", module);
                      throw new EventHandlerException("Problems processing event: " + t.toString(), t);
                  } else {
                      Debug.logError(e, "Problems Processing Event", module);
                      throw new EventHandlerException("Problems processing event: " + e.toString(), e);
                  }
              } catch (Exception e) {
                  Debug.logError(e, "Problems Processing Event", module);
                  throw new EventHandlerException("Problems processing event: " + e.toString(), e);
              } finally {
                  try {
                      TransactionUtil.commit(beganTransaction);
                  } catch (GenericTransactionException e) {
                      Debug.logError(e, module);
                  }
              }
          }
      

      It appears that the invoking of my service creates a default timeout transaction (using GeronimoTransactionFactory's default timeout of 60 seconds) Which is then suspended by my request-new-transaction and uses my custom timeout parameter. When the service is finished the commit occurs and the default transaction resumes, and is then committed, which causes the stack-trace.

      This is an error in our production environment so I would like a patch to be created if at all possible.

      1. TestingServices.java
        2 kB
        Jeffrey Breault
      2. shortLog.log
        419 kB
        Jeffrey Breault
      3. ofbiz.log
        470 kB
        Jacques Le Roux
      4. management-trunk.zip
        15 kB
        Jacques Le Roux
      5. management.zip
        17 kB
        Jeffrey Breault

        Issue Links

          Activity

          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Thanks for your detailled report Jeffrey,

          I have fixed the issue (more a quiproquo) in trunk at revision: 1809741 by adding an indication of the limited duration for services run this way. For longer services, as you did, sheduling a job is the way. Sorry, I have no intent of prodiving a way to shedule them using a Temporal Expression. But I'll provide the enhanced way in OFBIZ-9726

          Tough it could be done in older releases, I only backported in R16.11 at r1809742

          Show
          jacques.le.roux Jacques Le Roux added a comment - Thanks for your detailled report Jeffrey, I have fixed the issue (more a quiproquo) in trunk at revision: 1809741 by adding an indication of the limited duration for services run this way. For longer services, as you did, sheduling a job is the way. Sorry, I have no intent of prodiving a way to shedule them using a Temporal Expression. But I'll provide the enhanced way in OFBIZ-9726 Tough it could be done in older releases, I only backported in R16.11 at r1809742
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          I created OFBIZ-9726 for the new feature.

          Show
          jacques.le.roux Jacques Le Roux added a comment - I created OFBIZ-9726 for the new feature.
          Hide
          jacques.le.roux Jacques Le Roux added a comment - - edited

          Is there a plan to implement creating scheduled services using Temporal Events using the UI?

          Yes, I'll check that and also contribute the feature I spoke about.

          Show
          jacques.le.roux Jacques Le Roux added a comment - - edited Is there a plan to implement creating scheduled services using Temporal Events using the UI? Yes, I'll check that and also contribute the feature I spoke about.
          Hide
          jbreault Jeffrey Breault added a comment - - edited

          Sorry for the confusion The error:

          IO Error: Connection reset

          Is from another issue I am experiencing in production which I do not believe is an issue with the Ofbiz code.

          I mistakenly pasted the content into the comment.

          My question was.

          Is there a plan to implement creating scheduled services using Temporal Events using the UI?

          Show
          jbreault Jeffrey Breault added a comment - - edited Sorry for the confusion The error: IO Error: Connection reset Is from another issue I am experiencing in production which I do not believe is an issue with the Ofbiz code. I mistakenly pasted the content into the comment. My question was. Is there a plan to implement creating scheduled services using Temporal Events using the UI?
          Hide
          jacques.le.roux Jacques Le Roux added a comment - - edited

          . I'm guessing this is an async vs sync issue?

          Yes, I guess so (did not check yet). But I think we can improve that, or then warn the user about this possible issue.

          This also leads me to anther questions. is there a plan at the moment to allow for scheduling long running services using Temporal Events?Caused by: java.sql.SQLRecoverableException: IO Error: Connection reset

          Wait you said above that it was OK when using

          schedule service (without time parameters)

          And I think it's OK to do so. So I see no reasons for your question, please explain if I'm misunderstanding.
          Anyway, for a custom project I have developed a feature which allows to follow the progress of a long running job by increasing a progress bar. It allows also to set some related parameters and report detailled errors or success. We want to contribute this feature to OFBiz and I'll hopefull work in it before Christmas. It works already in the custom project since February... I'll create a Jira for that!

          Show
          jacques.le.roux Jacques Le Roux added a comment - - edited . I'm guessing this is an async vs sync issue? Yes, I guess so (did not check yet). But I think we can improve that, or then warn the user about this possible issue. This also leads me to anther questions. is there a plan at the moment to allow for scheduling long running services using Temporal Events?Caused by: java.sql.SQLRecoverableException: IO Error: Connection reset Wait you said above that it was OK when using schedule service (without time parameters) And I think it's OK to do so. So I see no reasons for your question, please explain if I'm misunderstanding. Anyway, for a custom project I have developed a feature which allows to follow the progress of a long running job by increasing a progress bar. It allows also to set some related parameters and report detailled errors or success. We want to contribute this feature to OFBiz and I'll hopefull work in it before Christmas. It works already in the custom project since February... I'll create a Jira for that!
          Hide
          jbreault Jeffrey Breault added a comment -

          I just verified it with my real service. Running it using the run service UI option causes the timeout exception. Running it using schedule service (without time parameters) causes it to run without an issue. I'm guessing this is an async vs sync issue?

          I have not attempted to use CoreEvents.scheduleService().

          This also leads me to anther questions. is there a plan at the moment to allow for scheduling long running services using Temporal Events?Caused by: java.sql.SQLRecoverableException: IO Error: Connection reset

          Show
          jbreault Jeffrey Breault added a comment - I just verified it with my real service. Running it using the run service UI option causes the timeout exception. Running it using schedule service (without time parameters) causes it to run without an issue. I'm guessing this is an async vs sync issue? I have not attempted to use CoreEvents.scheduleService(). This also leads me to anther questions. is there a plan at the moment to allow for scheduling long running services using Temporal Events?Caused by: java.sql.SQLRecoverableException: IO Error: Connection reset
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Ha wait, I did not completly read your last comment, so the "Schedule service" UI option works also or did you use something else when you say scheduleService, like CoreEvents.scheduleService() programmatically ?

          Show
          jacques.le.roux Jacques Le Roux added a comment - Ha wait, I did not completly read your last comment, so the "Schedule service" UI option works also or did you use something else when you say scheduleService, like CoreEvents.scheduleService() programmatically ?
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Jeffrey,

          That's what I thought from start. The reason is the options to schedule service manually are only there to quickly test a service. At least the "Run Service" option contributed by Andrew Sykes in 2007. I can remember it clearly, I was then working with him. Since "Run Service" is underneath running "Schedule service" the same constraint exists for it. I think it's because we then run the service from the UI and that implies a timeout default that we should enhance in those cases. I'll have a look, thanks for reporting!

          Show
          jacques.le.roux Jacques Le Roux added a comment - Jeffrey, That's what I thought from start. The reason is the options to schedule service manually are only there to quickly test a service. At least the "Run Service" option contributed by Andrew Sykes in 2007 . I can remember it clearly, I was then working with him. Since "Run Service" is underneath running "Schedule service" the same constraint exists for it. I think it's because we then run the service from the UI and that implies a timeout default that we should enhance in those cases. I'll have a look, thanks for reporting!
          Hide
          jbreault Jeffrey Breault added a comment -

          Jacques

          It appears that using temporal expressions does not cause the same exception...

          2017-09-17 19:17:59,922 |OFBiz-JobQueue-1     |TestingServices               |I| Count : 100000
          2017-09-17 19:17:59,939 |OFBiz-JobQueue-1     |ServiceDispatcher             |T| Sync service [default/testService] finished in [162300] milliseconds
          

          As you can see, it ran for ~2.7 minutes without an exception.

          I also tried the service using the scheduleService and it seems to also run without an error...

          2017-09-17 19:35:05,874 |OFBiz-JobQueue-0     |TestingServices               |I| Count : 100000
          2017-09-17 19:35:05,893 |OFBiz-JobQueue-0     |ServiceDispatcher             |T| Sync service [default/testService] finished in [160736] milliseconds
          

          This begs the question, why does runService cause this error when schedule service and TemporalExpressions do not?

          Show
          jbreault Jeffrey Breault added a comment - Jacques It appears that using temporal expressions does not cause the same exception... 2017-09-17 19:17:59,922 |OFBiz-JobQueue-1 |TestingServices |I| Count : 100000 2017-09-17 19:17:59,939 |OFBiz-JobQueue-1 |ServiceDispatcher |T| Sync service [default/testService] finished in [162300] milliseconds As you can see, it ran for ~2.7 minutes without an exception. I also tried the service using the scheduleService and it seems to also run without an error... 2017-09-17 19:35:05,874 |OFBiz-JobQueue-0 |TestingServices |I| Count : 100000 2017-09-17 19:35:05,893 |OFBiz-JobQueue-0 |ServiceDispatcher |T| Sync service [default/testService] finished in [160736] milliseconds This begs the question, why does runService cause this error when schedule service and TemporalExpressions do not?
          Hide
          jbreault Jeffrey Breault added a comment -

          Jacques,

          I have not attempted creating the job using TemporalExpressions as of yet. Your example does work, but only because it does not exceed the one minute timeout from the default GeronimoTransactionFactory.

          If you would please try to increase the amount of items being inserted so that the job takes longer than one minute (but less than the 36,000 seconds as indicated by my service definition), I believe that you will get the same exception I had received.

          I will look into creating a TemporalExpression right now and see if it also creates the same exception.

          Show
          jbreault Jeffrey Breault added a comment - Jacques, I have not attempted creating the job using TemporalExpressions as of yet. Your example does work, but only because it does not exceed the one minute timeout from the default GeronimoTransactionFactory. If you would please try to increase the amount of items being inserted so that the job takes longer than one minute (but less than the 36,000 seconds as indicated by my service definition), I believe that you will get the same exception I had received. I will look into creating a TemporalExpression right now and see if it also creates the same exception.
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Thanks Jeffrey,

          Yes this is the same than in my patch, except the tabs, we are using 4 spaces instead. BTW did you try to create a JobSandbox instead of running from the UI?
          You can get examples OOTB. Using TemporalExpression is the newer form (rather than RecurrenceRule and associated entities).

          Show
          jacques.le.roux Jacques Le Roux added a comment - Thanks Jeffrey, Yes this is the same than in my patch, except the tabs, we are using 4 spaces instead. BTW did you try to create a JobSandbox instead of running from the UI? You can get examples OOTB. Using TemporalExpression is the newer form (rather than RecurrenceRule and associated entities).
          Hide
          jbreault Jeffrey Breault added a comment -

          This file should be the corrected version. TestingServices.java

          Show
          jbreault Jeffrey Breault added a comment - This file should be the corrected version. TestingServices.java
          Hide
          jbreault Jeffrey Breault added a comment -

          I think I know what happened there. I believe I ran a ./gradlew cleanAll and that caused some sort of issue with eclipse. Maybe when I saved the file it did an organize imports and caused that issue.

          Show
          jbreault Jeffrey Breault added a comment - I think I know what happened there. I believe I ran a ./gradlew cleanAll and that caused some sort of issue with eclipse. Maybe when I saved the file it did an organize imports and caused that issue.
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          BTW the same compilation issues exist with R16:

          C:\projectsASF\release16.11>svn up && gradlew ofbiz
          Updating '.':
          U    applications\party\widget\partymgr\LookupScreens.xml
          U    applications\marketing\widget\sfa\forms\OpportunityForms.xml
           U   .
          Updated to revision 1808538.
          :compileJava
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:9: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist
          import framework.base.src.main.java.org.apache.ofbiz.base.util.Debug;
                                                                        ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:10: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist
          
          Show
          jacques.le.roux Jacques Le Roux added a comment - BTW the same compilation issues exist with R16: C:\projectsASF\release16.11>svn up && gradlew ofbiz Updating '.': U applications\party\widget\partymgr\LookupScreens.xml U applications\marketing\widget\sfa\forms\OpportunityForms.xml U . Updated to revision 1808538. :compileJava C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:9: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist import framework.base.src.main.java.org.apache.ofbiz.base.util.Debug; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:10: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist
          Hide
          jbreault Jeffrey Breault added a comment -

          Jacques,

          When I ran it yesterday I got the attached result (shortLog.log).

          The service on my little laptop had the following timing: Sync service [webtools/testService] finished in [127424] milliseconds

          I think you may need to increase the number of records that are being inserted from my example to tax your computer more. As I said in my description I am dealing with a table with millions of records being converted. We can have it running if we have it set to a small subsection (get 200 records, convert and save, then get 200 more) for 100 iterations. But if we were to increase that number then it gets the error in the above log.

          Show
          jbreault Jeffrey Breault added a comment - Jacques, When I ran it yesterday I got the attached result ( shortLog.log ). The service on my little laptop had the following timing: Sync service [webtools/testService] finished in [127424] milliseconds I think you may need to increase the number of records that are being inserted from my example to tax your computer more. As I said in my description I am dealing with a table with millions of records being converted. We can have it running if we have it set to a small subsection (get 200 records, convert and save, then get 200 more) for 100 iterations. But if we were to increase that number then it gets the error in the above log.
          Hide
          jacques.le.roux Jacques Le Roux added a comment - - edited

          Hi Jeffrey,

          OK it was because I tried with trunk. I was able to run testService on trunk using the attached management-trunk.zip where I only changed the org.apache.ofbiz path and
          <field name="dummyRecSeqNum" type="id-ne" ></field>
          to
          <field name="dummyRecSeqNum" type="id" ></field>.

          It seems to work well, please see ofbiz.log to confirm.

          Show
          jacques.le.roux Jacques Le Roux added a comment - - edited Hi Jeffrey, OK it was because I tried with trunk. I was able to run testService on trunk using the attached management-trunk.zip where I only changed the org.apache.ofbiz path and <field name="dummyRecSeqNum" type="id-ne" ></field> to <field name="dummyRecSeqNum" type="id" ></field> . It seems to work well, please see ofbiz.log to confirm.
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Sorry Jeffrey, this is what I got, no time yet to get deeper (should be simple, only path issue I guess)

          C:\projectsASF\release16.11>svn up && gradlew ofbiz
          Updating '.':
          U    applications\party\widget\partymgr\LookupScreens.xml
          U    applications\marketing\widget\sfa\forms\OpportunityForms.xml
           U   .
          Updated to revision 1808538.
          :compileJava
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:9: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist
          import framework.base.src.main.java.org.apache.ofbiz.base.util.Debug;
                                                                        ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:10: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist
          import framework.base.src.main.java.org.apache.ofbiz.base.util.UtilMisc;
                                                                        ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:11: error: package framework.entity.src.main.java.org.apache.ofbiz.entity does not exist
          import framework.entity.src.main.java.org.apache.ofbiz.entity.Delegator;
                                                                       ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:12: error: package framework.entity.src.main.java.org.apache.ofbiz.entity does not exist
          import framework.entity.src.main.java.org.apache.ofbiz.entity.GenericEntityException;
                                                                       ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:13: error: package framework.entity.src.main.java.org.apache.ofbiz.entity does not exist
          import framework.entity.src.main.java.org.apache.ofbiz.entity.GenericValue;
                                                                       ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:14: error: package framework.service.src.main.java.org.apache.ofbiz.service does not exist
          import framework.service.src.main.java.org.apache.ofbiz.service.DispatchContext;
                                                                         ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:15: error: package framework.service.src.main.java.org.apache.ofbiz.service does not exist
          import framework.service.src.main.java.org.apache.ofbiz.service.LocalDispatcher;
                                                                         ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:16: error: package framework.service.src.main.java.org.apache.ofbiz.service does not exist
          import framework.service.src.main.java.org.apache.ofbiz.service.ServiceUtil;
                                                                         ^
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:22: error: cannot find symbol
                  public static Map<String, ? extends Object> testService(DispatchContext dctx, Map<String, Object> context) {
                                                                          ^
            symbol:   class DispatchContext
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:23: error: cannot find symbol
                          Debug.logImportant("Starting Service ::: " + LocalDateTime.now(), module);
                          ^
            symbol:   variable Debug
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:24: error: cannot find symbol
                          LocalDispatcher dispatcher = dctx.getDispatcher();
                          ^
            symbol:   class LocalDispatcher
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:25: error: cannot find symbol
                          Delegator delegator = dctx.getDelegator();
                          ^
            symbol:   class Delegator
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:31: error: cannot find symbol
                                          GenericValue dummyRec = delegator.makeValidValue("DummyRec", UtilMisc.toMap("dummyRecSeqNum", dummyRecSeq, "dummyRec", "This is a testing value")).create();
                                          ^
            symbol:   class GenericValue
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:31: error: cannot find symbol
                                          GenericValue dummyRec = delegator.makeValidValue("DummyRec", UtilMisc.toMap("dummyRecSeqNum", dummyRecSeq, "dummyRec", "This is a testing value")).create();
                                                                                                       ^
            symbol:   variable UtilMisc
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:35: error: cannot find symbol
                                  } catch (GenericEntityException e) {
                                           ^
            symbol:   class GenericEntityException
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:36: error: cannot find symbol
                                          Debug.logWarning("Failed to save DummyRec Record " + e.getLocalizedMessage(), module);
                                          ^
            symbol:   variable Debug
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:40: error: cannot find symbol
                          Debug.logImportant("Ending Service ::: " + LocalDateTime.now(), module);
                          ^
            symbol:   variable Debug
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:41: error: cannot find symbol
                          Debug.logImportant("PKS : " + pks.toString(), module);
                          ^
            symbol:   variable Debug
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:42: error: cannot find symbol
                          Debug.logImportant("Count : " + count, module);
                          ^
            symbol:   variable Debug
            location: class TestingServices
          C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:43: error: cannot find symbol
                          Map<String, Object> result = ServiceUtil.returnSuccess("Test Service was Good");
                                                       ^
            symbol:   variable ServiceUtil
            location: class TestingServices
          Note: Some input files use unchecked or unsafe operations.
          Note: Recompile with -Xlint:unchecked for details.
          20 errors
          :compileJava FAILED
          
          FAILURE: Build failed with an exception.
          
          * What went wrong:
          Execution failed for task ':compileJava'.
          > Compilation failed; see the compiler error output for details.
          
          * Try:
          Run with --stacktrace option to get the stack trace. Run with --info or --debug option to get more log output.
          
          BUILD FAILED
          
          Total time: 36.262 secs
          
          C:\projectsASF\release16.11>
          
          Show
          jacques.le.roux Jacques Le Roux added a comment - Sorry Jeffrey, this is what I got, no time yet to get deeper (should be simple, only path issue I guess) C:\projectsASF\release16.11>svn up && gradlew ofbiz Updating '.': U applications\party\widget\partymgr\LookupScreens.xml U applications\marketing\widget\sfa\forms\OpportunityForms.xml U . Updated to revision 1808538. :compileJava C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:9: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist import framework.base.src.main.java.org.apache.ofbiz.base.util.Debug; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:10: error: package framework.base.src.main.java.org.apache.ofbiz.base.util does not exist import framework.base.src.main.java.org.apache.ofbiz.base.util.UtilMisc; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:11: error: package framework.entity.src.main.java.org.apache.ofbiz.entity does not exist import framework.entity.src.main.java.org.apache.ofbiz.entity.Delegator; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:12: error: package framework.entity.src.main.java.org.apache.ofbiz.entity does not exist import framework.entity.src.main.java.org.apache.ofbiz.entity.GenericEntityException; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:13: error: package framework.entity.src.main.java.org.apache.ofbiz.entity does not exist import framework.entity.src.main.java.org.apache.ofbiz.entity.GenericValue; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:14: error: package framework.service.src.main.java.org.apache.ofbiz.service does not exist import framework.service.src.main.java.org.apache.ofbiz.service.DispatchContext; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:15: error: package framework.service.src.main.java.org.apache.ofbiz.service does not exist import framework.service.src.main.java.org.apache.ofbiz.service.LocalDispatcher; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:16: error: package framework.service.src.main.java.org.apache.ofbiz.service does not exist import framework.service.src.main.java.org.apache.ofbiz.service.ServiceUtil; ^ C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:22: error: cannot find symbol public static Map< String , ? extends Object > testService(DispatchContext dctx, Map< String , Object > context) { ^ symbol: class DispatchContext location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:23: error: cannot find symbol Debug.logImportant( "Starting Service ::: " + LocalDateTime.now(), module); ^ symbol: variable Debug location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:24: error: cannot find symbol LocalDispatcher dispatcher = dctx.getDispatcher(); ^ symbol: class LocalDispatcher location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:25: error: cannot find symbol Delegator delegator = dctx.getDelegator(); ^ symbol: class Delegator location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:31: error: cannot find symbol GenericValue dummyRec = delegator.makeValidValue( "DummyRec" , UtilMisc.toMap( "dummyRecSeqNum" , dummyRecSeq, "dummyRec" , "This is a testing value" )).create(); ^ symbol: class GenericValue location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:31: error: cannot find symbol GenericValue dummyRec = delegator.makeValidValue( "DummyRec" , UtilMisc.toMap( "dummyRecSeqNum" , dummyRecSeq, "dummyRec" , "This is a testing value" )).create(); ^ symbol: variable UtilMisc location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:35: error: cannot find symbol } catch (GenericEntityException e) { ^ symbol: class GenericEntityException location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:36: error: cannot find symbol Debug.logWarning( "Failed to save DummyRec Record " + e.getLocalizedMessage(), module); ^ symbol: variable Debug location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:40: error: cannot find symbol Debug.logImportant( "Ending Service ::: " + LocalDateTime.now(), module); ^ symbol: variable Debug location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:41: error: cannot find symbol Debug.logImportant( "PKS : " + pks.toString(), module); ^ symbol: variable Debug location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:42: error: cannot find symbol Debug.logImportant( "Count : " + count, module); ^ symbol: variable Debug location: class TestingServices C:\projectsASF\release16.11\hot-deploy\management\src\main\java\org\breault\service\TestingServices.java:43: error: cannot find symbol Map< String , Object > result = ServiceUtil.returnSuccess( "Test Service was Good" ); ^ symbol: variable ServiceUtil location: class TestingServices Note: Some input files use unchecked or unsafe operations. Note: Recompile with -Xlint:unchecked for details. 20 errors :compileJava FAILED FAILURE: Build failed with an exception. * What went wrong: Execution failed for task ':compileJava'. > Compilation failed; see the compiler error output for details. * Try: Run with --stacktrace option to get the stack trace. Run with --info or --debug option to get more log output. BUILD FAILED Total time: 36.262 secs C:\projectsASF\release16.11>
          Hide
          jbreault Jeffrey Breault added a comment - - edited

          Jacques: I apologize for the mixup. this file should be better.
          management.zip

          Show
          jbreault Jeffrey Breault added a comment - - edited Jacques: I apologize for the mixup. this file should be better. management.zip
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Sorry Jeffrey, there is nothing in management.zip. You should better attach a file.

          Show
          jacques.le.roux Jacques Le Roux added a comment - Sorry Jeffrey, there is nothing in management.zip. You should better attach a file.
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Thanks Jeffrey,

          I'll have a look ASAP

          Show
          jacques.le.roux Jacques Le Roux added a comment - Thanks Jeffrey, I'll have a look ASAP
          Hide
          jbreault Jeffrey Breault added a comment - - edited

          Jacques: I can now confirm that this issue exists in R16.11.03 with revision.txt having the following revision.
          1799419

          Place the following project into the hot-deploy directory. management.zip
          and execute the testService using the run service method.

          Edit: Tested using a local postgres DB running Ubuntu 17.04

          Show
          jbreault Jeffrey Breault added a comment - - edited Jacques: I can now confirm that this issue exists in R16.11.03 with revision.txt having the following revision. 1799419 Place the following project into the hot-deploy directory. management.zip and execute the testService using the run service method. Edit: Tested using a local postgres DB running Ubuntu 17.04
          Hide
          jbreault Jeffrey Breault added a comment -

          Run testService from org.breault.service.TestServices using the run jobs page in web tools

          Show
          jbreault Jeffrey Breault added a comment - Run testService from org.breault.service.TestServices using the run jobs page in web tools
          Hide
          jbreault Jeffrey Breault added a comment -

          Deepak Dixit I am getting this error when running the service from the "Run Service" option.
          I also have the service scheduled to run every 12 hours. I will report on Monday morning what errors are evident.

          Jacques Le Roux I will attempt to run this service from my R16.11 migration branch on Monday morning.

          Thank you both for your responses.

          Show
          jbreault Jeffrey Breault added a comment - Deepak Dixit I am getting this error when running the service from the "Run Service" option. I also have the service scheduled to run every 12 hours. I will report on Monday morning what errors are evident. Jacques Le Roux I will attempt to run this service from my R16.11 migration branch on Monday morning. Thank you both for your responses.
          Hide
          deepak.dixit Deepak Dixit added a comment -

          Hi Jeffrey,

          Could you please confirm from where are run this service?
          Run Service: https://demo-trunk.ofbiz.apache.org/webtools/control/runService
          Schedule Service: https://demo-trunk.ofbiz.apache.org/webtools/control/scheduleJob

          Show
          deepak.dixit Deepak Dixit added a comment - Hi Jeffrey, Could you please confirm from where are run this service? Run Service: https://demo-trunk.ofbiz.apache.org/webtools/control/runService Schedule Service: https://demo-trunk.ofbiz.apache.org/webtools/control/scheduleJob
          Hide
          jacques.le.roux Jacques Le Roux added a comment -

          Hi Jeffrey,

          Could you please confirm the same exists using the trunk or the last supported release branch: R16.11? Unfortunately the R14.12 branch has never and will never been released so has never and will never been supported. This does not mean that we don't care, but it would be much more easier for us to know if you cross the same kind of issue using trunk or R16.

          Thanks

          Show
          jacques.le.roux Jacques Le Roux added a comment - Hi Jeffrey, Could you please confirm the same exists using the trunk or the last supported release branch: R16.11? Unfortunately the R14.12 branch has never and will never been released so has never and will never been supported. This does not mean that we don't care, but it would be much more easier for us to know if you cross the same kind of issue using trunk or R16. Thanks

            People

            • Assignee:
              jacques.le.roux Jacques Le Roux
              Reporter:
              jbreault Jeffrey Breault
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development