Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-13933

access-log entries might become lost during the shutdown even if graceful timeout is specified

    XMLWordPrintable

Details

    • 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 WildFly 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 WildFly 16+, WFCORE-1632 changed the shutdown behavior to wait only for 100ms (hard-coded). So, WildFly 16+ 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

              rhn-cservice-bbaranow Bartosz Baranowski
              rhn-support-mmiura Masafumi Miura
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated: