Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-12074

EJB client 4.x freezes intermittently after some time

XMLWordPrintable

    • Regression, Blocks Testing

      Seen in our clustering failover tests for remote stateful EJBs.
      Setup: 4 node cluster, one node at the time is shut down gracefully/killed, while 500 standalone clients keep calling the application (number of clients was lowered from 2000 to reduce the log size).

      Description: the test continues normally for some time (3-4 minutes), then suddenly all the client threads get stuck on invoking remoteBean.getSerialAndIncrement() and never get a response.

      Note: we do not specify invocation timeout so it's set to its default value. We can set it to any value if needed.
      Edit: We cannot. See JBEAP-12075.

      NOTE: There is extra debugging enabled - each EJB client logs these two messages (in the beginning of the invocation and after it received a response):

      Invoking SFSB: getSerialAndIncrement()
      Response acquired, serial: X delay: Y
      

      You can see the ID number of the EJB client in the log message: [Runner - XXX]

      Client log:
      http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/mvinkler_perflab_eap-7x-failover-ejb-ejbremote-jvmkill-dist-async/14/console-perf29/

      Snippet from client log - clients log "getSerialAndIncrement()" but no response comes after that.

      2017/07/12 03:32:37:039 EDT [DEBUG][Runner - 404] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Response acquired, serial: 49 delay: 2
      2017/07/12 03:32:37:039 EDT [DEBUG][Runner - 279] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:039 EDT [DEBUG][Runner - 17] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Response acquired, serial: 50 delay: 2
      2017/07/12 03:32:37:041 EDT [DEBUG][Runner - 89] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:041 EDT [DEBUG][Runner - 279] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Response acquired, serial: 49 delay: 2
      2017/07/12 03:32:37:043 EDT [DEBUG][Runner - 89] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Response acquired, serial: 50 delay: 2
      2017/07/12 03:32:37:093 EDT [DEBUG][Runner - 244] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:093 EDT [DEBUG][Runner - 256] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:111 EDT [DEBUG][Runner - 249] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:113 EDT [DEBUG][Runner - 249] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Response acquired, serial: 50 delay: 2
      2017/07/12 03:32:37:127 EDT [DEBUG][Runner - 408] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:129 EDT [DEBUG][Runner - 408] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Response acquired, serial: 49 delay: 2
      2017/07/12 03:32:37:156 EDT [DEBUG][Runner - 250] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:161 EDT [DEBUG][Runner - 251] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:161 EDT [DEBUG][Runner - 409] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:184 EDT [DEBUG][Runner - 252] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:306 EDT [DEBUG][Runner - 415] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:332 EDT [DEBUG][Runner - 414] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:338 EDT [DEBUG][Runner - 258] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:364 EDT [DEBUG][Runner - 259] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:367 EDT [DEBUG][Runner - 417] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:437 EDT [DEBUG][Runner - 420] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:464 EDT [DEBUG][Runner - 421] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:563 EDT [DEBUG][Runner - 423] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:599 EDT [DEBUG][Runner - 425] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:602 EDT [DEBUG][Runner - 426] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:629 EDT [DEBUG][Runner - 428] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:673 EDT [DEBUG][Runner - 269] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:692 EDT [DEBUG][Runner - 270] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:694 EDT [DEBUG][Runner - 429] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:721 EDT [DEBUG][Runner - 272] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:767 EDT [DEBUG][Runner - 274] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:791 EDT [DEBUG][Runner - 276] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:850 EDT [DEBUG][Runner - 278] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:893 EDT [DEBUG][Runner - 438] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:923 EDT [DEBUG][Runner - 439] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      2017/07/12 03:32:37:923 EDT [DEBUG][Runner - 281] HOST perf29.mw.lab.eng.bos.redhat.com:rootProcess:c - Invoking SFSB: getSerialAndIncrement().
      

      This is very similar to JBEAP-10307 although there is no obvious connection between cluster topology change and the clients being stuck.

        1. jstack_threaddump_24_run2.out
          1.10 MB
          Daniel Cihak
        2. jstack_threaddump_26_CR1.out
          2.15 MB
          Daniel Cihak
        3. jstack_threaddump_30_run1.out
          1.13 MB
          Daniel Cihak
        4. stackTraceAfterLockup.txt
          548 kB
          Richard Achmatowicz
        5. threaddump_055e133.txt
          6.07 MB
          Jan Martiska

              Unassigned Unassigned
              mvinkler1@redhat.com Michal Vinkler
              Daniel Cihak Daniel Cihak
              Daniel Cihak Daniel Cihak
              Votes:
              0 Vote for this issue
              Watchers:
              15 Start watching this issue

                Created:
                Updated:
                Resolved: