Uploaded image for project: 'Seam 2'
  1. Seam 2
  2. JBSEAM-4013

Synchronous invocation of asynchronous method from asynchronously executing method.

    Details

    • Type: Bug
    • Status: Reopened (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 2.1.1.GA
    • Fix Version/s: None
    • Component/s: Async
    • Labels:
    • Environment:

      Seam 2.1.1GA, JBoss 4.2.3GA.

      Description

      There is a problem with REENTRANT flag in AsynchronousInterceptor.java that leads to synchronous invocation of asynchronous method from asynchronously executing method. Any call to a synchronous method will reset the flag, so subsequent calls to asynchronous methods are executed synchronously.

      How to reproduce: just add these three classes to quartz example:

      Async.java:
      ________________________
      package org.jboss.seam.example.quartz;

      import org.jboss.seam.annotations.In;
      import org.jboss.seam.annotations.Name;
      import org.jboss.seam.annotations.Observer;

      @Name( "async" )
      public class Async {

      @In( create = true )
      private Async1 async1;

      @Observer( "org.jboss.seam.postInitialization" )
      public void initialize()

      { async1.test( 5000L ); }

      }

      Async1.java
      ________________________
      package org.jboss.seam.example.quartz;

      import org.jboss.seam.annotations.In;
      import org.jboss.seam.annotations.Logger;
      import org.jboss.seam.annotations.Name;
      import org.jboss.seam.annotations.async.Asynchronous;
      import org.jboss.seam.annotations.async.Duration;
      import org.jboss.seam.async.AbstractDispatcher;
      import org.jboss.seam.async.QuartzTriggerHandle;
      import org.jboss.seam.contexts.Contexts;
      import org.jboss.seam.log.Log;

      @Name( "async1" )
      public class Async1 {

      @Logger
      private Log log;
      @In( create = true )
      private Async2 async2;
      private static final String REENTRANT = "org.jboss.seam.async.AsynchronousIntercepter.REENTRANT";

      @Asynchronous
      public QuartzTriggerHandle test( @Duration Long duration ) {
      log.info( "EXECUTING_ASYNCHRONOUS_CALL = #0", Contexts.getEventContext().isSet( AbstractDispatcher.EXECUTING_ASYNCHRONOUS_CALL ) );
      log.info( "1. REENTRANT = #0", Contexts.getEventContext().isSet( REENTRANT ) );
      async2.test( 5000L, "test1" );
      log.info( "2. REENTRANT = #0", Contexts.getEventContext().isSet( REENTRANT ) );
      async2.log( "sync" );
      log.info( "3. REENTRANT = #0", Contexts.getEventContext().isSet( REENTRANT ) );
      async2.test( 10000L, "test2" );
      try

      { Thread.sleep( 15000L ); }

      catch( InterruptedException e ) {
      }
      log.info( "4. REENTRANT = #0", Contexts.getEventContext().isSet( REENTRANT ) );
      return null;
      }

      }

      Async2.java
      ________________________
      package org.jboss.seam.example.quartz;

      import org.jboss.seam.annotations.Logger;
      import org.jboss.seam.annotations.Name;
      import org.jboss.seam.annotations.async.Asynchronous;
      import org.jboss.seam.annotations.async.Duration;
      import org.jboss.seam.async.AbstractDispatcher;
      import org.jboss.seam.async.QuartzTriggerHandle;
      import org.jboss.seam.contexts.Contexts;
      import org.jboss.seam.log.Log;

      @Name( "async2" )
      public class Async2 {

      @Logger
      private Log log;

      @Asynchronous
      public QuartzTriggerHandle test( @Duration Long duration, String message )

      { log( message ); return null; }

      // non-asynchronous method
      public void log( String message )

      { log.info( "#0: EXECUTING_ASYNCHRONOUS_CALL = #1", message, Contexts.getEventContext().isSet( AbstractDispatcher.EXECUTING_ASYNCHRONOUS_CALL ) ); log.info( "#0: REENTRANT = #1", message, Contexts.getEventContext().isSet( "org.jboss.seam.async.AsynchronousIntercepter.REENTRANT" ) ); }

      }

      Async schedules invocation of Async1. Then Async1 schedules two invocations of Async2. It also calls non-asynchronous method of Async2 before scheduling the second invocation. This causes the REENTRANT flag to be off and the second invocation to be executed synchronously by the same thread. Here is a relevant log:

      18:24:34,349 INFO (main) [ServletContextListener] Welcome to Seam 2.1.1.GA
      18:24:37,077 INFO (main) [QuartzScheduler] Quartz Scheduler v.1.6.0 created.
      18:24:37,079 INFO (main) [RAMJobStore] RAMJobStore initialized.
      18:24:37,365 INFO (main) [Server] JBoss (MX MicroKernel) [4.2.3.GA (build: SVNTag=JBoss_4_2_3_GA date=200807181417)] Started in 22s:600ms
      18:24:42,172 INFO (Sched1_Worker-1) [Async1] EXECUTING_ASYNCHRONOUS_CALL = true
      18:24:42,173 INFO (Sched1_Worker-1) [Async1] 1. REENTRANT = true
      18:24:42,175 INFO (Sched1_Worker-1) [Async1] 2. REENTRANT = true
      18:24:42,176 INFO (Sched1_Worker-1) [Async2] sync: EXECUTING_ASYNCHRONOUS_CALL = true
      18:24:42,177 INFO (Sched1_Worker-1) [Async2] sync: REENTRANT = true
      18:24:42,177 INFO (Sched1_Worker-1) [Async1] 3. REENTRANT = false
      18:24:42,185 INFO (Sched1_Worker-1) [Async2] test2: EXECUTING_ASYNCHRONOUS_CALL = true
      18:24:42,185 INFO (Sched1_Worker-1) [Async2] test2: REENTRANT = true
      18:24:47,190 INFO (Sched1_Worker-2) [Async2] test1: EXECUTING_ASYNCHRONOUS_CALL = true
      18:24:47,190 INFO (Sched1_Worker-2) [Async2] test1: REENTRANT = true
      18:24:57,186 INFO (Sched1_Worker-1) [Async1] 4. REENTRANT = false

      Expected behavior: test2 should be invoked asynchronously (by different thread) after the test1.

      Changes might be as simple as the following (AsynchronousInterceptor.java):
      boolean flag_is_set = false;
      if (isExecutingAsynchronousCall() && !Contexts.getEventContext().isSet(REENTRANT))

      { Contexts.getEventContext().set(REENTRANT, true); flag_is_set = true; }

      try

      { return invocation.proceed(); }

      finally
      {
      if (flag_is_set)

      { Contexts.getEventContext().remove(REENTRANT); }

      }
      to make sure we do not reset the REENTRANT flag if it was not set by us.

      Another way to fix is to make sure non-asynchronous methods go short route:
      @AroundInvoke
      public Object aroundInvoke(InvocationContext invocation) throws Exception
      {
      if (!invocation.getMethod().isAnnotationPresent(Asynchronous.class))
      return invocation.proceed();
      boolean scheduleAsync = !isExecutingAsynchronousCall() || Contexts.getEventContext().isSet(REENTRANT);
      ...

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  Unassigned
                  Reporter:
                  AntonL Anton Lyakishev
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  1 Start watching this issue

                  Dates

                  • Created:
                    Updated: