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

[GSS](7.4.z) WFLY-13933 - access-log entries might become lost during the shutdown even if graceful timeout is specified

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: New (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: Undertow
    • Labels:
      None
    • Target Release:
    • Steps to Reproduce:
      Hide

      To reproduce this issue, you can use either of the following methods to emulate slow down before completing to write all access log entries. Then, trigger shutdown during the slowdown.

      • Use debugger to set thread-level breakpoint in Undertow's DefaultAccessLogReceiver#writeMessage() (or inside run())
      • Use byteman script to invoke Thread.sleep() in Undertow's DefaultAccessLogReceiver#writeMessage() (or inside run())
      RULE DefaultAccessLogReceiver_writeMessage
      CLASS io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver
      METHOD writeMessage
      AT ENTRY
      IF TRUE
      DO
        traceStack("-------------- io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver#writeMessage() is invoked \n");
        Thread.sleep(10000L); // emulate slow down
      ENDRULE
      

      Then, follow the steps:

      1. Send several requests to JBoss

      ab -n 10 -c 5 http://127.0.0.1:8080/
      

      2. Shutdown JBoss (the same result happens regardless of using graceful shutdown or not)

      ./bin/shutdown.sh -c ":shutdown()"
      

      or

      ./bin/shutdown.sh -c ":shutdown(timeout=30)"
      

      EAP 7.2 waits shutdown for the task thread to complete writing all access-log entries.
      However, EAP 7.3 does not wait. It only waits for 100 milliseconds because of the behavior change by WFCORE-1632. So, some log entries will be lost.

      Show
      To reproduce this issue, you can use either of the following methods to emulate slow down before completing to write all access log entries. Then, trigger shutdown during the slowdown. Use debugger to set thread-level breakpoint in Undertow's DefaultAccessLogReceiver#writeMessage() (or inside run()) Use byteman script to invoke Thread.sleep() in Undertow's DefaultAccessLogReceiver#writeMessage() (or inside run()) RULE DefaultAccessLogReceiver_writeMessage CLASS io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver METHOD writeMessage AT ENTRY IF TRUE DO   traceStack( "-------------- io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver#writeMessage() is invoked \n" );   Thread .sleep(10000L); // emulate slow down ENDRULE Then, follow the steps: 1. Send several requests to JBoss ab -n 10 -c 5 http: //127.0.0.1:8080/ 2. Shutdown JBoss (the same result happens regardless of using graceful shutdown or not) ./bin/shutdown.sh -c ":shutdown()" or ./bin/shutdown.sh -c ":shutdown(timeout=30)" EAP 7.2 waits shutdown for the task thread to complete writing all access-log entries. However, EAP 7.3 does not wait. It only waits for 100 milliseconds because of the behavior change by WFCORE-1632 . So, some log entries will be lost.

      Description

      access-log has a possibility to be lost during EAP 7.3 shutdown even if a graceful timeout is specified.

      If I understand correctly, access-log processing runs on a different thread from the application processing and the graceful shutdown does not care about it.

      Since EAP 7.3, WFCORE-1632 changed the shutdown behavior to wait only for 100ms (hard-coded). So, EAP 7.3 does not wait for completing a task worker thread processing access-log.

      I understand the purpose of WFCORE-1632. However, it might be good if we have an option to tune the wait time. (Of course, it would be difficult to know how long wait time is sufficient for completion. And specifying a large wait time can be a cause of long shutdown time. So, it's still questionable how it's useful.)
      Or, if it's possible to implement that the graceful shutdown can wait for access-log processing, it would be better. (This might be RFE?).

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              baranowb Bartosz Baranowski
              Reporter:
              ivassile Ilia Vassilev
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Dates

                Created:
                Updated: