Mongodb log rotation creates an extra empty log file each time it runs

Question

I configured a new mongodb arbiter recently, and used this to test some new mongo config, using the mongo 3 config syntax, at the same time I tested log rotation on the server. This worked nicely:

$ cat /etc/mongo.conf

storage:
  dbPath: "/srv/mongodb"
  directoryPerDB: true

#where to log
systemLog:
  destination: file
  path: "/var/log/mongodb/mongodb.log"
  logAppend: true
  logRotate: reopen

# in replica set configuration, specify the name of the replica set
replication:
  replSetName: "dev"

net:
  http:
    enabled: true
    RESTInterfaceEnabled: true

Log rotation config:

cat /etc/logrotate.d/mongodb

/var/log/mongodb/*.log {
    daily
    rotate 7
    compress
    dateext
    missingok
    notifempty
    sharedscripts
    copytruncate
    postrotate
        /bin/kill -SIGUSR1 `cat /var/run/mongodb.pid 2> /dev/null` 2> /dev/null || true
    endscript
}

The log files:

-rw-r--r--  1 mongodb mongodb 230277 Jan 18 09:28 mongodb.log
-rw-r--r--  1 mongodb mongodb 353041 Jan 13 06:38 mongodb.log-20160113.gz
-rw-r--r--  1 mongodb mongodb 249142 Jan 14 06:34 mongodb.log-20160114.gz
-rw-r--r--  1 mongodb mongodb 238532 Jan 15 06:50 mongodb.log-20160115.gz
-rw-r--r--  1 mongodb mongodb 201815 Jan 16 06:47 mongodb.log-20160116.gz
-rw-r--r--  1 mongodb mongodb 205026 Jan 17 06:26 mongodb.log-20160117.gz
-rw-r--r--  1 mongodb mongodb 211581 Jan 18 06:51 mongodb.log-20160118.gz

Since this worked nicely I tried the same config on one of the existing db-nodes, using the following config:

cat /etc/mongod.conf

storage:
  dbPath: "/srv/mongodb"
  directoryPerDB: true

#where to log
systemLog:
  destination: file
  path: "/var/log/mongodb/mongodb.log"
  logAppend: true
  logRotate: reopen

# in replica set configuration, specify the name of the replica set
replication:
  replSetName: "dev"

net:
  http:
    enabled: true
    RESTInterfaceEnabled: true

Log rotation:

cat /etc/logrotate.d/mongodb

/var/log/mongodb/*.log {
    daily
    rotate 7
    compress
    dateext
    missingok
    notifempty
    sharedscripts
    copytruncate
    postrotate
        /bin/kill -SIGUSR1 `cat /var/run/mongodb.pid 2> /dev/null` 2> /dev/null || true
    endscript
}

Gives me these log files:

-rw-r--r--  1 mongodb mongodb   224461 Jan 18 09:19 mongodb.log
-rw-r--r--  1 mongodb mongodb 18081598 Jan 16 06:43 mongodb.log-20160116.gz
-rw-r--r--  1 mongodb mongodb        0 Jan 16 06:43 mongodb.log.2016-01-16T06-43-30
-rw-r--r--  1 mongodb mongodb   212828 Jan 17 06:37 mongodb.log-20160117.gz
-rw-r--r--  1 mongodb mongodb        0 Jan 17 06:37 mongodb.log.2016-01-17T06-37-37
-rw-r--r--  1 mongodb mongodb   212639 Jan 18 06:49 mongodb.log-20160118.gz
-rw-r--r--  1 mongodb mongodb        0 Jan 18 06:49 mongodb.log.2016-01-18T06-49-22

Can anyone explain why I am getting 2 log files every day, one with the time stamp as part of the filename? I thought maybe I had some config difference, but I can't see it.

I know I can work around it by putting a find /var/log/mongodb/* -empty -delete in my post rotate config, but I'd rather not have them created at all rather than remove them after they are created.

Both machines are using the same version of mongodb (3.0.8) installed from the ubuntu repo from mongodb.org

score 0 · Answer 1 · answered Jan 20 '16 at 11:15

0

In your configuration your log is being rotated twice. First time when you send SIGUSR1 to mongo instance and second time via logrotate. So logrotate rotates empty log just created by mongo. One doesn't need logrotate to rotate mongo log because mongodb can do it by its own. I set up rotation this way

[mongod@lab7-mongo-4 ~]$ crontab -l
00 00 * * * /opt/gicapods/scripts/rotate_mongo.sh

[mongod@lab7-mongo-4 ~]$ less /opt/scripts/rotate_mongo.sh
#!/bin/bash
cat `find /opt/mongo/db/ -type f -name mongod.lock |egrep -v '(config|backup)'` |xargs kill -SIGUSR1
COUNT=1
for i in `/bin/ls -t /opt/mongo/log | egrep 'mongod_lab7-mongo-[0-9]+.log.*'`; do
    if [[ $COUNT -gt 5 ]]; then
            rm -f /opt/mongo/log/$i
    fi
    let "COUNT++"
done

answered Jan 20 '16 at 11:15

user1700494

1,642
2
12
21

Thanks for the response, but that doesn't explain why this works fine on my arbiter, and I only get the issue on nodes that I reconfigured. Also, the documentation states this is the way to do it: https://docs.mongodb.org/v3.0/tutorial/rotate-log-files/#log-rotation-with-logrotate-reopen – Rumbles Jan 20 '16 at 12:20
Your question was not "why this works fine on my arbiter". You asked about origin of empty files, and i gave you responce. Btw there is nothing about `logrotate` in link you provided – user1700494 Jan 21 '16 at 10:59

score 0 · Accepted Answer · answered Jan 21 '16 at 11:22

0

Simply the config that stops this from happening hasn't been applied:

  logRotate: reopen

As the mongo service hadn't been restarted since the config had been updated. After a restart of the service the next rotation only created a single log file.

answered Jan 21 '16 at 11:22

Rumbles

994
1
12
28

Mongodb log rotation creates an extra empty log file each time it runs

2 Answers2