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

Replacing async log-handler with console log-handler during boot can cause logging to stop

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • 7.1.0.DR16
    • 7.0.4.GA
    • Logging
    • None
    • Hide

      The Docker way

      The easiest way to reproduce is with the EAP 6 or 7 images in Red Hat Container Catalog:

      docker run -it --rm registry.access.redhat.com/jboss-eap-7/eap70-openshift:1.4-28 /opt/eap/bin/standalone.sh -c standalone.xml
      or
      docker run -it --rm registry.access.redhat.com/jboss-eap-6/eap64-openshift:1.4-28 /opt/eap/bin/standalone.sh -c standalone.xml

      Very often (at least 50% of the time), console logging stops just after this line (EAP 7.0.4.GA):

      01:07:49,913 INFO  [org.xnio.nio] (MSC service thread 1-2) XNIO NIO Implementation Version 3.4.1.Final-redhat-1

      or the next line (EAP 6.4.13.GA):

      01:09:24,548 INFO  [org.jboss.remoting] (MSC service thread 1-3) JBoss Remoting version 3.3.8.Final-redhat-1

      The non-Docker way

      Alternatively, if you want to reproduce without Docker:

      1. copy standalone.xml to standalone-async.xml, adding this log handler:

                  <async-handler name="ASYNC">
                <queue-length value="512"/>
                <overflow-action value="block"/>
                <subhandlers>
                    <handler name="CONSOLE"/>
                </subhandlers>
            </async-handler>

      2. replace the root logger's CONSOLE handler with ASYNC:

                  <root-logger>
                <level name="INFO"/>
                <handlers>
                    <handler name="ASYNC"/>
                </handlers>
            </root-logger>

      3. Let JBoss boot for a few seconds (to update logging.properties with the ASYNC configuration):
      bin/standalone.sh -c standalone.async.xml

      3b. If you save a copy of standalone/configuration/logging.properties at this point, you can try again much more quickly.)

      4. Hit control-C, then run against the default standalone.xml
      bin/standalone.sh -c standalone.xml

      If logging stops just after the org.xnio.nio line, you have reproduced it. If not, hit Control-C, and go back to step 3 (or restore logging.properties from step 3b and go to step 4.). When using this method, I can reproduce it about 20% of the time.

      Workaround

      The workaround (such as it is) is to ensure that the log handlers in logging.properties match the logging configuration in standalone.xml, eg both use ASYNC, or neither uses ASYNC. In the case of Docker, this can be done by running JBoss to generate logging.properties from the appropriate standalone*.xml, then ADDing the generated file to the image.

      Show
      The Docker way The easiest way to reproduce is with the EAP 6 or 7 images in Red Hat Container Catalog: docker run -it --rm registry.access.redhat.com/jboss-eap-7/eap70-openshift:1.4-28 /opt/eap/bin/standalone.sh -c standalone.xml or docker run -it --rm registry.access.redhat.com/jboss-eap-6/eap64-openshift:1.4-28 /opt/eap/bin/standalone.sh -c standalone.xml Very often (at least 50% of the time), console logging stops just after this line (EAP 7.0.4.GA): 01:07:49,913 INFO [org.xnio.nio] (MSC service thread 1-2) XNIO NIO Implementation Version 3.4.1.Final-redhat-1 or the next line (EAP 6.4.13.GA): 01:09:24,548 INFO [org.jboss.remoting] (MSC service thread 1-3) JBoss Remoting version 3.3.8.Final-redhat-1 The non-Docker way Alternatively, if you want to reproduce without Docker: 1. copy standalone.xml to standalone-async.xml, adding this log handler: <async-handler name= "ASYNC" > <queue-length value= "512" /> <overflow-action value= "block" /> <subhandlers> <handler name= "CONSOLE" /> </subhandlers> </async-handler> 2. replace the root logger's CONSOLE handler with ASYNC: <root-logger> <level name= "INFO" /> <handlers> <handler name= "ASYNC" /> </handlers> </root-logger> 3. Let JBoss boot for a few seconds (to update logging.properties with the ASYNC configuration): bin/standalone.sh -c standalone.async.xml 3b. If you save a copy of standalone/configuration/logging.properties at this point, you can try again much more quickly.) 4. Hit control-C, then run against the default standalone.xml bin/standalone.sh -c standalone.xml If logging stops just after the org.xnio.nio line, you have reproduced it. If not, hit Control-C, and go back to step 3 (or restore logging.properties from step 3b and go to step 4.). When using this method, I can reproduce it about 20% of the time. Workaround The workaround (such as it is) is to ensure that the log handlers in logging.properties match the logging configuration in standalone.xml, eg both use ASYNC, or neither uses ASYNC. In the case of Docker, this can be done by running JBoss to generate logging.properties from the appropriate standalone*.xml, then ADDing the generated file to the image.

      There seems to be a race condition when the logging subsystem activates during boot up, if switching from an ASYNC(CONSOLE) log handler to a CONSOLE handler. When triggered, console logging stops completely, although other loggers do activate.

      Note that this bug affects EAP 6 and 7.

              jperkins-rhn James Perkins
              sflanigan Sean Flanigan (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

                Created:
                Updated:
                Resolved: