Description of problem: When using the provided logrotate config, extra files are created. For example, I have a directory listing of /var/log/mongodb/ like this: -rw-r--r--. 1 mongodb mongodb 13K Jan 4 15:34 mongodb.log -rw-r--r--. 1 mongodb mongodb 2.6M Nov 20 03:40 mongodb.log-20161120.gz -rw-r--r--. 1 mongodb mongodb 0 Nov 20 03:40 mongodb.log.2016-11-20T08-40-04 -rw-r--r--. 1 mongodb mongodb 27K Nov 28 03:50 mongodb.log-20161128.gz -rw-r--r--. 1 mongodb mongodb 0 Nov 28 03:50 mongodb.log.2016-11-28T08-50-03 -rw-r--r--. 1 mongodb mongodb 8.0K Dec 4 03:43 mongodb.log-20161204.gz -rw-r--r--. 1 mongodb mongodb 0 Dec 4 03:43 mongodb.log.2016-12-04T08-43-02 -rw-r--r--. 1 mongodb mongodb 6.7K Dec 12 03:49 mongodb.log-20161212.gz -rw-r--r--. 1 mongodb mongodb 0 Dec 12 03:49 mongodb.log.2016-12-12T08-49-02 -rw-r--r--. 1 mongodb mongodb 1.1M Dec 18 03:16 mongodb.log-20161218.gz -rw-r--r--. 1 mongodb mongodb 0 Dec 18 03:16 mongodb.log.2016-12-18T08-16-02 -rw-r--r--. 1 mongodb mongodb 99K Dec 25 03:36 mongodb.log-20161225.gz -rw-r--r--. 1 mongodb mongodb 0 Dec 25 03:36 mongodb.log.2016-12-25T08-36-02 -rw-r--r--. 1 mongodb mongodb 5.9K Jan 2 03:42 mongodb.log-20170102 -rw-r--r--. 1 mongodb mongodb 0 Jan 2 03:42 mongodb.log.2017-01-02T08-42-02 Each of the 0-length files should not be present. The included logrotate config looks like this: $ cat /etc/logrotate.d/mongodb /var/log/mongodb/*.log { weekly rotate 10 copytruncate delaycompress compress notifempty missingok postrotate /bin/kill -USR1 `cat /var/run/mongodb/mongod.pid 2>/dev/null` 2> /dev/null|| true endscript } This is what I think is happening, using data above as an example: - logrotate operated as normal. It renamed mongodb.log to mongodb.log-20170102, and then created a new 0-length mongodb.log - the "postrotate" command ran, which sent SIGUSR1 to the mongodb process. Per mongo's documentation [0], that caused mongodb to invoke *its own implementation of log rotation* - mongodb thus renamed the brand-new-and-empty mongodb.log file to mongodb.log.2017-01-02T08-42-02, and created a new mongodb.log file. So in effect, log rotation is happening twice in rapid succession. Only one of them needs to actually happen. [0] https://docs.mongodb.com/v2.6/tutorial/rotate-log-files/#overview Version-Release number of selected component (if applicable): mongodb-server-2.6.12-3.el7.x86_64 How reproducible: Always Steps to Reproduce: 1. start mongodb 2. run logrotate Actual results: an extra 0-length file in /var/log/mongodb/ Expected results: just the rotated log files plus a current/active log file
Additoinal to the 0-length files also spare files that look huge can be created. After logrotate moves the file, then mongod is still writing to the file at postiion <huge> and then creates a sparse file. Quickly after that the USR1 is received by mongod and also mongod is switching. See the Size vs. Blocks in the stat and the hexdump of the first 20 0x00 characters: [crash] root@li-lc-1017:~# head -c 20 /var/log/mongodb/mongodb.log.2016-12-05T03-22-28 | xxd 0000000: 0000 0000 0000 0000 0000 0000 0000 0000 ................ 0000010: 0000 0000 .... [crash] root@li-lc-1017:~# stat /var/log/mongodb/mongodb.log.2016-12-05T03-22-28 File: ‘/var/log/mongodb/mongodb.log.2016-12-05T03-22-28’ Size: 1342099293 Blocks: 16 IO Block: 4096 regular file Device: fd07h/64775d Inode: 11156 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 184/ mongodb) Gid: ( 130/ mongodb) Context: system_u:object_r:mongod_log_t:s0 Access: 2017-01-04 16:14:49.667227212 +0000 Modify: 2016-12-05 03:22:28.217426986 +0000 Change: 2016-12-05 03:22:28.388427487 +0000 Birth: -
Upstream introduced fix for this in MongoDB 3.0 - https://docs.mongodb.com/v3.0/tutorial/rotate-log-files/#log-rotation-with-logrotate-reopen (this option improve working with logrotate utility and solves this problem). For MongoDB 2.6 EPEL7 workaround is needed. I am preparing fix which will: copy config file, do MongoDB logrotation (result empty/big file + starting using new file) and remove files from MongoDB logrotation.
mongodb-2.6.12-4.el7 has been submitted as an update to Fedora EPEL 7. https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2017-5805758e8b
mongodb-2.6.12-4.el7 has been pushed to the Fedora EPEL 7 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2017-5805758e8b
Thanks for the quick resolution!
mongodb-2.6.12-4.el7 has been pushed to the Fedora EPEL 7 stable repository. If problems still persist, please make note of it in this bug report.