Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-1192

Stuck Thread Issue due to file system got full with logs

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Major Major
    • None
    • 1.1.3
    • logback-core
    • logback 1.1.3, RollingFileAppender, Time based rolling policy with roll over of 1 hr and gz compression mode. Java 1.8, OS windows 7, intel core i 7, 256 GB SSD.

    Description

      while doing performance test of our application that uses logback for logging, when file system got full after lots of logs generated (started with available space 15 GB), application is stucking/hangling in this case. We run a background thread in our application who logs all stuck threads. We got following stack trace of stuck thread (because of file system got full ):

      [tomcat-http--585] = java.lang.Class.forName0(Native Method)
      java.lang.Class.forName(Class.java:264)
      ch.qos.logback.classic.spi.PackagingDataCalculator.bestEffortLoadClass(PackagingDataCalculator.java:239)
      ch.qos.logback.classic.spi.PackagingDataCalculator.computeBySTEP(PackagingDataCalculator.java:138)
      ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:101)
      ch.qos.logback.classic.spi.PackagingDataCalculator.__AW_calculate(PackagingDataCalculator.java:57)
      ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java)
      ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:147)
      ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:124)
      ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
      ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
      ch.qos.logback.classic.Logger.info(Logger.java:616)

      And following log in my JMH logs:
      <JMH had finished, but forked VM did not exit, are there stray running threads? Waiting 25 seconds more...>

      Non-finished threads:

      Thread[pool-2-thread-1,5,main]
      at java.io.FileInputStream.readBytes(Native Method)
      at java.io.FileInputStream.read(Unknown Source)
      at java.io.BufferedInputStream.read1(Unknown Source)
      at java.io.BufferedInputStream.read(Unknown Source)
      at java.io.FilterInputStream.read(Unknown Source)
      at ch.qos.logback.core.rolling.helper.Compressor.gzCompress(Compressor.java:204)
      at ch.qos.logback.core.rolling.helper.Compressor.compress(Compressor.java:55)
      at ch.qos.logback.core.rolling.helper.CompressionRunnable.run(CompressionRunnable.java:33)
      at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
      at java.util.concurrent.FutureTask.run(Unknown Source)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)

      Thread[DestroyJavaVM,5,main]

      <JMH had finished, but forked VM did not exit, are there stray running threads? Waiting 20 seconds more...>

      Non-finished threads:

      Thread[pool-2-thread-1,5,main]
      at java.util.zip.Deflater.deflateBytes(Native Method)
      at java.util.zip.Deflater.deflate(Unknown Source)
      at java.util.zip.Deflater.deflate(Unknown Source)
      at java.util.zip.DeflaterOutputStream.deflate(Unknown Source)
      at java.util.zip.DeflaterOutputStream.write(Unknown Source)
      at java.util.zip.GZIPOutputStream.write(Unknown Source)
      at ch.qos.logback.core.rolling.helper.Compressor.gzCompress(Compressor.java:205)
      at ch.qos.logback.core.rolling.helper.Compressor.compress(Compressor.java:55)
      at ch.qos.logback.core.rolling.helper.CompressionRunnable.run(CompressionRunnable.java:33)
      at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
      at java.util.concurrent.FutureTask.run(Unknown Source)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)

      I am not sure if it is desired behavior, when file system got full. If this is not the case, please provide some fix.

      Following is part of logback config:

      Attachments

        Activity

          People

            logback-dev Logback dev list
            hitman Pushpendra Patel
            Votes:
            1 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated: