Uploaded image for project: 'Undertow'
  1. Undertow
  2. UNDERTOW-597

DefaultAccessLogReceiver cannot always be closed cleanly and may log a NullPointerException

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Major
    • 1.2.12.Final, 1.3.10.Final
    • None
    • None
    • Hide

      These two tests should hopefully illustrate the problem:

      @Test
          public void cleanShutdownAfterLoggingAMessage()
                  throws IOException, InterruptedException {
              Xnio xnio = Xnio.getInstance(getClass().getClassLoader());
              XnioWorker worker = xnio.createWorker(OptionMap.builder().getMap());
              File outputDirectory = new File("target/access_logs");
              outputDirectory.mkdirs();
              DefaultAccessLogReceiver receiver = new DefaultAccessLogReceiver(worker,
                      outputDirectory, "foo.");
              // This will work because logging the message causes the writer to be created.
              receiver.logMessage("message");
              // Sleep for a bit so that the writer gets created before we close the receiver
              Thread.sleep(100);
              receiver.close();
              // Sleep for a bit to give any exception a chance to occur
              Thread.sleep(100);
          }
      
          @Test
          public void cleanShutdownWithAFreshReceiver()
                  throws IOException, InterruptedException {
              Xnio xnio = Xnio.getInstance(getClass().getClassLoader());
              XnioWorker worker = xnio.createWorker(OptionMap.builder().getMap());
              File outputDirectory = new File("target/access_logs");
              outputDirectory.mkdirs();
              DefaultAccessLogReceiver receiver = new DefaultAccessLogReceiver(worker,
                      outputDirectory, "foo.");
              // This will NPE because the receiver's writer is null. This can happen if the
              // receiver isn't used before it's closed, or it's closed after it's been rotated.
              receiver.close();
              // Sleep for a bit to give any exception a chance to occur
              Thread.sleep(100);
          }
      

      The first test will not log any exception due to the logging of the message creating the writer. The second test will log an NPE because the writer is null.

      Show
      These two tests should hopefully illustrate the problem: @Test public void cleanShutdownAfterLoggingAMessage() throws IOException, InterruptedException { Xnio xnio = Xnio.getInstance(getClass().getClassLoader()); XnioWorker worker = xnio.createWorker(OptionMap.builder().getMap()); File outputDirectory = new File("target/access_logs"); outputDirectory.mkdirs(); DefaultAccessLogReceiver receiver = new DefaultAccessLogReceiver(worker, outputDirectory, "foo."); // This will work because logging the message causes the writer to be created. receiver.logMessage("message"); // Sleep for a bit so that the writer gets created before we close the receiver Thread.sleep(100); receiver.close(); // Sleep for a bit to give any exception a chance to occur Thread.sleep(100); } @Test public void cleanShutdownWithAFreshReceiver() throws IOException, InterruptedException { Xnio xnio = Xnio.getInstance(getClass().getClassLoader()); XnioWorker worker = xnio.createWorker(OptionMap.builder().getMap()); File outputDirectory = new File("target/access_logs"); outputDirectory.mkdirs(); DefaultAccessLogReceiver receiver = new DefaultAccessLogReceiver(worker, outputDirectory, "foo."); // This will NPE because the receiver's writer is null. This can happen if the // receiver isn't used before it's closed, or it's closed after it's been rotated. receiver.close(); // Sleep for a bit to give any exception a chance to occur Thread.sleep(100); } The first test will not log any exception due to the logging of the message creating the writer. The second test will log an NPE because the writer is null.

    Description

      When DefaultAccessLogReceiver is closed with a null writer an NPE is logged to System.err. The writer may be null because the receiver hasn't been used or because it's just rotated its log file. The NPE looks like this:

      Exception in thread "XNIO-1 task-1" java.lang.NullPointerException
      	at io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver.run(DefaultAccessLogReceiver.java:192)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      

      This happens on both 1.2.x (1.2.12.Final) and 1.3.x (1.3.10.Final).

      Attachments

        Issue Links

          Activity

            People

              sdouglas1@redhat.com Stuart Douglas
              ankinson Andy Wilkinson
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: