Home / server / Questions / 71341
Accepted
Ben Williams
Asked: 2009-10-06 05:26:44 +0800 CST

Why do JBoss and Logrotate create log files full of NUL characters?

  • 772

I've set up Logrotate to rotate my JBoss Application Server 4.2.2.GA logs nightly. After the log files have been rotated and JBoss starts writing to them again, the new log files begin with as many NUL characters as there were characters in the previous log file, followed by the new log messages. For example, if the JBoss server.log file was 5000 bytes long then, after rotation, the new server.log file will begin with 5000 NUL characters. After several days, server.log begins with NUL characters equivalent to the characters in all the previous days log files combined. It seems as if JBoss is remembering its position in the log file and picking up where it left off in the truncated file. Here is my logrotate config for JBoss:

/apps/jboss-4.2.2.GA/server/default/log/*log {
    daily
    rotate 30
    compress
    notifempty
    copytruncate
    missingok
    nocreate
}

I can't restart JBoss nightly because that would be too much downtime. I also can't use the log4j DailyRollingFileAppender as it doesn't delete old log files. Has anyone gotten logrotate working properly with JBoss?

jboss

3 Answers

  1. Best Answer

    We had the same problem for a file being written by log4j. The solution was to set the property "Append" for the FileAppender to "true". After this change, we have not seen this problem with files having NUL when rotated by an external program like logrotate.

    • 7

  2. From my experience - and the reason that we do not use logrotate with Log4j is that the way logrotate works is that it renames the files, then instructs the program to close its logs and reopen them with the old file name (which does not exist anymore), normally using the HUP signal.

    But Log4j cannot be told to reopen its log files, so I see you use copytruncate to copy the files instead - the problem is that Log4j uses buffered writers that keep track of the current position of the file that is being written and when you truncate the log file log4j keeps writing from where it stopped writing before the truncate. Depending on your file system implementation this should create "files with holes" - i.e. the NULL characters that you see there do not really exist - the file is actually only as big as the actual data and the NULL character is the way your viewer represents the hole. Some file systems on the other hand do not support holes and will indeed fill the file with NULL characters when Log4j resumes writing.

    I suggest - don't use logrotate, find some way to rotate the files within Log4j by using a RollingFileAppender (that does support removing old files) or using the DailyRollingFileAppender and a cronjob that removes old files externally (as it was meant to be done).

    • 5

  3. This works perfectly. To summarize what @Guss suggested:

    1. Open your "log4j.xml" and add the following appender (I've used DailyRollingAppender class and configured it to rollover daily):

    *NOTE: Frequency of rollover is based on the "DatePattern". See: http://www.codejava.net/coding/configure-log4j-for-creating-daily-rolling-log-files

    <appender name="RollingAppender" class="org.apache.log4j.DailyRollingFileAppender">
       <param name="File" value="/logging_directory_path_here/server1.log" />
       <param name="DatePattern" value="'.'yyyy-MM-dd" />
       <layout class="org.apache.log4j.PatternLayout">
          <param name="ConversionPattern" value="[%p] %d %c %M - %m%n"/>          
       </layout>
    </appender>

    <root>
            <priority value="info" />
            <appender-ref ref="RollingAppender" />
    </root>
    1. Create a shell script that compresses the roll-overed log file.
    2. Install that Shell Script in the Unix Server's Crontab to have it run daily. e.g. Runs daily at 12:10 a.m. (Why 12:10 a.m.? This gives ample time for log4j to finish the rollover, just in case if the log file(s) is/are too big, or if there are too many log files to compress).
    3. Finally make sure the log4j Rollover runs at 12:00 a.m. (default) and the cron job that executes the shell script at 12:10 a.m.
    • 0