mamelara commented 3 years ago

Rotate catalina.out with logrotate

Description

Closes ess-dive/ess-dive-project#155

Logrotates catalina.out by using the docker-entrypoint.sh file and executing logrotate upon container start-up. This mounts a configuration file into the container that logrotate will use for rotation settings.

Due to the bugs present in DailyLogRollingFile - documented here: https://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/DailyRollingFileAppender.html

It is recommended to use an appender from log4j extras. This causes additional maintenance overhead. Rather than modifying log4j.properties files for metacat and metacat-index, the defaults are kept and the logrotation is done only in catalina.out.

Type of change

Please delete options that are not relevant.

[X] New feature (non-breaking change which adds functionality)

How Has This Been Tested?

Please describe the tests that you ran to verify your changes. Provide instructions so we can reproduce. Please also list any relevant details for your test configuration

[ ] Unit tests
[ ] Integration tests
[ ] Test coverage >= 77%
[ ] Flake8 Tests
[ ] Mypy Tests
[X] Other - add any additional tests here

Tested by building the image and running the entire application stack using ess-dive-catalog repository

Test Configuration

Metacat Version: 2.12.3
Python Version: 3.7

vchendrix commented 3 years ago

@mamelara I don't see any changes to docker-entrypoint.sh that rolls the catalina.out on startup based on some metric.

mamelara commented 3 years ago

I was going to do a separate PR to address that. I could include those changes in this PR as well.

Are the configuration changes fine? I basically just removed the ConsoleAppender and just write to a file.

vchendrix commented 3 years ago

I was going to do a separate PR to address that. I could include those changes in this PR as well.

My thought was that the inclusion of the catalog rolling would "Close" this issue. If you want to split this up into two PRs then you need to change the syntax in the commit and PR from "Closes" to "Issue".

Are the configuration changes fine? I basically just removed the ConsoleAppender and just write to a file.

I haven't tested it yet, but the changes look fine on the surface.

mamelara commented 3 years ago

Ah okay, I can add the rolling file changes then. They're currently under progress in this PR.

My plan is to check the file size of catalina.out. This is adjustable via an environment variable called MAX_CATALINA_GB_SIZE with the default being 10GB. If the size of the file is larger than that then create a copy of it, date it with the current date and then truncate -s 0 catalina.out.

mamelara commented 3 years ago

cp may not be a good route since that could take long if the file is very large and metacat startup could take awhile.

mamelara commented 3 years ago

@vchendrix turning this into a draft for now

mamelara commented 3 years ago

I'd like to discuss an idea. I can actually install logrotate in the server and call it. So this is what my logic looks like:

    echo
    echo '**************************************'
    echo "Creating logrotate.conf"
    echo '**************************************'
    echo

    cat << EOF > /tmp/logrotate.conf
/usr/local/tomcat/logs/catalina.out {
    copytruncate
    daily
    rotate 7
    missingok
    compress
    size $MAX_CATALINA_OUT_GB_SIZE
}
EOF

    echo
    echo '**************************************'
    echo "Checking catalina.out size"
    echo '**************************************'
    echo
    MAX_CATALINA_OUT_GB_SIZE=${MAX_CATALINA_OUT_GB_SIZE:-10}
    LOG_DIR=$CATALINA_HOME/logs
    CATALINA_OUT=/usr/local/tomcat/logs/catalina.out

    file_size_bytes=`stat -c %s "$CATALINA_OUT"`
    file_size=$((file_size_bytes / 1024**3))

    if [ $file_size -gt $MAX_CATALINA_OUT_GB_SIZE ];
    then
        echo
        echo '**************************************'
        echo "Truncating catalina.out"
        echo '**************************************'
        echo
        current_date=`date +"%m-%d-%Y"`
        catalina_copy=$LOG_DIR/"catalina-$current_date.out.backup"
        /usr/sbin/logrotate -s /usr/local/tomcat/logs/status /tmp/logrotate.conf
        #cp $CATALINA_OUT $catalina_copy
        truncate -s 0 $CATALINA_OUT
    fi

think I can simplify this and just let logrotate determine the size. So that logic of checking the size could just be simplfied to:

    echo
    echo '**************************************'
    echo "Creating logrotate.conf"
    echo '**************************************'
    echo

    cat << EOF > /tmp/logrotate.conf
/usr/local/tomcat/logs/catalina.out {
    copytruncate
    daily
    rotate 7
    missingok
    compress
    size $MAX_CATALINA_OUT_GB_SIZE
}
EOF

    echo
    echo '**************************************'
    echo "Running logrotate"
    echo '**************************************'
    echo

  /usr/sbin/logrotate -s /usr/local/tomcat/logs/status /tmp/logrotate.conf

I can create the configuration file upon start up of docker-entrypoint, but we can also mount one. I wanted to at least allow changes via environment variables. I can add some additional logic to apply_config.py that can handle logrotate files.

Let me know if this is getting overengineered 😄

vchendrix commented 3 years ago

@mamelara put a short meeting on my calendar to discuss this idea.

mamelara commented 3 years ago

To keep this simple, it was agreed in our meeting to create a default logrotate.conf configuration file and ADD to the canonical path (/etc/logrotate.d/). Then we just call logrotate as usual. It was also decided to keep metacat and metacat-index to log to the Console to keep a unified structure. The log4j.properties will be modified to write to a file as well using the DailyRollingFileAppender.

mamelara commented 3 years ago

Marking this as ready for review:

To test:

Build the image using essdive-appstack repo and run:

$ ./build.sh metacat 2.12.3

If you have a catalina.out already present on the mounted ess-dive-volumes you can test out the logrotate functionality by running the following command:

$ truncate -s XG` catalina.out`

Then on ess-dive-catalog run the docker-compose.yml file

$ docker-compose -f provision/docker-compose.yml up

You should see in the logs information about logrotate.

I also tested a couple of iterations of logrotating and it does seem to work fine creating the tarball.

Are we okay with the default of 1G? It might not matter in the long run since we won't be restarting the services much and catalina.out will still get large enough.

mamelara commented 3 years ago

The structure of the changes looks good. I tested out the logrotate and reviewed the logrotate configuration and think there needs to be some different defaults (see my previous comment)

I agree with the suggestions.

Also, running the truncate per your instructions did not "rotate" as I didn't have a compress dated file from that; it just truncated. I wanted to see what the rotation would look like

I've experienced this behavior before when I ran truncate. You may want to make sure no processes have a hold on the file, so make sure that metacat is down.

Below are the files that created. The status file is, I assume, a log of the rotation events? If so, it needs a better name that tells me what the contents of the file are.

Yes status holds the logs for all the logrotate events. I can change the name.

-rw-r----- 1 metacat metacat 1.7K Oct 16 17:32 localhost_access_log.2020-10-16.txt
-rw-r----- 1 metacat metacat 6.6K Oct 16 17:32 metacat.log
-rw-rw---- 1 metacat metacat 101M Oct 16 17:32 catalina.out
-rw-r----- 1 metacat metacat 1.8M Oct 16 17:28 catalina.2020-10-16.log
-rw-r----- 1 metacat metacat 5.3K Oct 16 17:28 metacat-index.log
-rw-r----- 1 metacat metacat  13K Oct 16 17:28 localhost.2020-10-16.log
-rw-r----- 1 metacat metacat    0 Oct 16 17:28 host-manager.2020-10-16.log
-rw-r----- 1 metacat metacat    0 Oct 16 17:28 manager.2020-10-16.log
-rw-r--r-- 1 metacat metacat   85 Oct 16 17:28 status

Can you tell me what the compress file output from log rotate will look like. Will they be dated?

The compress filenames look like catalina.1.gz, catalina.2.gz. I'm not sure if they will be dated but I can look up configuration options to name the tarballs.

mamelara commented 3 years ago

Updated with your configuration suggestions - also renamed the status file to -> logrotate-status-log.

Here is what it looks like on my local machine:

data/ess-dive-volumes/logs
❯ ls
catalina.2020-10-10.log  catalina.2020-10-14.log   host-manager.2020-10-07.log  host-manager.2020-10-19.log  localhost.2020-10-14.log             localhost_access_log.2020-10-09.txt  manager.2020-10-07.log  manager.2020-10-19.log     metacat.log
catalina.2020-10-07.log         catalina.2020-10-11.log  catalina.2020-10-19.log   host-manager.2020-10-08.log  localhost.2020-10-07.log     localhost.2020-10-19.log             localhost_access_log.2020-10-14.txt  manager.2020-10-08.log  metacat-index.log          metacat.log.2020-41
catalina.2020-10-08.log         catalina.2020-10-12.log  catalina.out              host-manager.2020-10-09.log  localhost.2020-10-08.log     localhost_access_log.2020-10-07.txt  localhost_access_log.2020-10-19.txt  manager.2020-10-09.log  metacat-index.log.2020-41  metacat.log.2020-42
catalina.2020-10-09.log         catalina.2020-10-13.log  catalina.out-20201019.gz  host-manager.2020-10-14.log  localhost.2020-10-09.log     localhost_access_log.2020-10-08.txt  logrotate-status-log                 manager.2020-10-14.log  metacat-index.log.2020-42

To highlight: catalina.out-20201019.gz and logrotate-status-log are the changes present

mamelara commented 3 years ago

TODO:

~~[ ] Move the date to the middle of the file.~~ There is no easy way to change this
[x] Change the name of the logrotate status file to .log

mamelara commented 3 years ago

@vchendrix I found this while trying to look for ways to change the name of the file: https://bz.apache.org/bugzilla/show_bug.cgi?id=43374

Perhaps we should switch to RollingFileAppender?

https://howtodoinjava.com/log4j/log4j-rolling-file-appender/

Should we make the max size 100MB?

mamelara commented 3 years ago

Per our conversation via Slack, it has been decided that duplicating the logs between a file and the console is not the best approach. To keep things simple, we rotate catalina.out with docker-entrypoint.sh and mount the configuration settings into the container

ess-dive / docker-metacat