Rotate catalina.out with logrotate in docker-entrypoint.sh #21

mamelara · 2020-10-07T23:35:33Z

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.

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

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 · 2020-10-08T15:56:17Z

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

mamelara · 2020-10-08T16:03:54Z

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 · 2020-10-08T19:49:44Z

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 · 2020-10-08T20:02:01Z

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 · 2020-10-08T21:11:25Z

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 · 2020-10-08T21:14:01Z

@vchendrix turning this into a draft for now

mamelara · 2020-10-09T18:23:29Z

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 · 2020-10-12T15:27:18Z

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

mamelara · 2020-10-14T21:29:53Z

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 · 2020-10-15T17:57:32Z

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.

vchendrix · 2020-10-16T17:26:33Z

metacat.conf

+    copytruncate
+    daily
+    rotate 7
+    compress
+    missingok
+    size 1G


I think we need to discuss these defaults. If we are rotating daily, then we are only keeping logs for the last seven days (rotate 7). Let's rotate monthly and keep the last twelve months. I think 1G is too big for a limit. We only have ~650 MB for the last year. Lets have 100M as the limit.

Let me know what you think of my suggestion below

Suggested change

copytruncate

daily

rotate 7

compress

missingok

size 1G

copytruncate

rotate 12

compress

missingok

monthly

size 100M

I agree with these suggestions

Changes should be addressed in latest commit

vchendrix

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).

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

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.

-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?

mamelara · 2020-10-16T17:59:54Z

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 · 2020-10-19T16:53:49Z

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 · 2020-10-21T17:37:36Z

TODO:

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

mamelara · 2020-10-21T18:37:47Z

@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?

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`.

mamelara · 2020-10-22T06:43:44Z

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

vchendrix

Looks great. After it is merged can you build a new image and deploy to data-dev?

mamelara requested a review from vchendrix October 7, 2020 23:35

mamelara marked this pull request as draft October 8, 2020 21:13

mamelara force-pushed the issue_155_log4j_configuration branch from 9c5bb03 to caf2724 Compare October 15, 2020 16:47

mamelara marked this pull request as ready for review October 15, 2020 16:50

vchendrix reviewed Oct 16, 2020

View reviewed changes

vchendrix requested changes Oct 16, 2020

View reviewed changes

mamelara force-pushed the issue_155_log4j_configuration branch 2 times, most recently from 5624326 to 47769b1 Compare October 19, 2020 16:52

mamelara force-pushed the issue_155_log4j_configuration branch 2 times, most recently from 308d2e9 to 76a06d6 Compare October 22, 2020 06:29

mamelara force-pushed the issue_155_log4j_configuration branch from 76a06d6 to 5fd9f6a Compare October 22, 2020 06:39

mamelara changed the title ~~Patch log4j configuration files in metacat~~ Rotate catalina.out with logrotate in docker-entrypoint.sh Oct 22, 2020

vchendrix approved these changes Oct 27, 2020

View reviewed changes

vchendrix merged commit eae4c7e into master Oct 27, 2020

vchendrix deleted the issue_155_log4j_configuration branch October 27, 2020 18:46

Rotate catalina.out with logrotate in docker-entrypoint.sh #21

Rotate catalina.out with logrotate in docker-entrypoint.sh #21

Uh oh!

Conversation

mamelara commented Oct 7, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Rotate catalina.out with logrotate

Description

Type of change

How Has This Been Tested?

Test Configuration

Uh oh!

vchendrix commented Oct 8, 2020

Uh oh!

mamelara commented Oct 8, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vchendrix commented Oct 8, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mamelara commented Oct 8, 2020

Uh oh!

mamelara commented Oct 8, 2020

Uh oh!

mamelara commented Oct 8, 2020

Uh oh!

mamelara commented Oct 9, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vchendrix commented Oct 12, 2020

Uh oh!

mamelara commented Oct 14, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mamelara commented Oct 15, 2020

Uh oh!

vchendrix Oct 16, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mamelara Oct 16, 2020

Choose a reason for hiding this comment

Uh oh!

mamelara Oct 19, 2020

Choose a reason for hiding this comment

Uh oh!

vchendrix left a comment

Choose a reason for hiding this comment

Uh oh!

mamelara commented Oct 16, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mamelara commented Oct 19, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mamelara commented Oct 21, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mamelara commented Oct 21, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mamelara commented Oct 22, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vchendrix left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

mamelara commented Oct 7, 2020 •

edited

Loading

mamelara commented Oct 8, 2020 •

edited

Loading

vchendrix commented Oct 8, 2020 •

edited

Loading

mamelara commented Oct 9, 2020 •

edited

Loading

mamelara commented Oct 14, 2020 •

edited

Loading

vchendrix Oct 16, 2020 •

edited

Loading

mamelara commented Oct 16, 2020 •

edited

Loading

mamelara commented Oct 19, 2020 •

edited

Loading

mamelara commented Oct 21, 2020 •

edited

Loading

mamelara commented Oct 21, 2020 •

edited

Loading

mamelara commented Oct 22, 2020 •

edited

Loading