Excessive logging in juju-db

[Peter Sabaini]

We have an env where juju-db has logged about 40G of messages to /var/log/syslog yesterday.

Version: 1.25.6.1
logging-config:
$ juju get-env logging-config
<root>=WARNING; unit=INFO

I'm seeing a lot of repetition of this in the logs:

Dec 1 15:30:02 state-host mongod.37017[6670]: Thu Dec 1 15:30:02.888 [conn2843] command juju.$cmd command: { getLastError: 1, j: true } ntoreturn:1 keyUpdates:0 reslen:83 511ms
Dec 1 15:30:02 state-host mongod.37017[6670]: Thu Dec 1 15:30:02.888 [conn2782] command juju.$cmd command: { getLastError: 1, j: true } ntoreturn:1 keyUpdates:0 reslen:83 511ms
Dec 1 15:30:02 state-host mongod.37017[6670]: Thu Dec 1 15:30:02.888 [conn2880] command juju.$cmd command: { getLastError: 1, j: true } ntoreturn:1 keyUpdates:0 reslen:83 511ms
Dec 1 15:30:02 state-host mongod.37017[6670]: Thu Dec 1 15:30:02.888 [conn2825] command juju.$cmd command: { getLastError: 1, j: true } ntoreturn:1 keyUpdates:0 reslen:83 511ms
Dec 1 15:30:02 state-host mongod.37017[6670]: Thu Dec 1 15:30:02.888 [conn2728] command juju.$cmd command: { getLastError: 1, j: true } ntoreturn:1 keyUpdates:0 reslen:83 510ms
Dec 1 15:30:02 state-host mongod.37017[6670]: Thu Dec 1 15:30:02.888 [conn2775] command juju.$cmd command: { getLastError: 1, j: true } ntoreturn:1 keyUpdates:0 reslen:83 510ms
Dec 1 15:30:02 state-host mongod.37017[6670]: Thu Dec 1 15:30:02.888 [conn2741] command juju.$cmd command: { getLastError: 1, j: true } ntoreturn:1 keyUpdates:0 reslen:83 510ms

And

Dec 1 06:25:02 state-host mongod.37017[22248]: Thu Dec 1 06:25:02.727 [conn8496] authenticate db: admin { authenticate: 1, nonce: "xxx", user: "machine-0", key: ...
Dec 1 06:25:02 state-host mongod.37017[22248]: Thu Dec 1 06:25:02.727 [conn7837] authenticate db: admin { authenticate: 1, nonce: "xxx", user: "machine-0", key: ...
Dec 1 06:25:02 state-host mongod.37017[22248]: Thu Dec 1 06:25:02.728 [conn7547] authenticate db: admin { authenticate: 1, nonce: "xxx", user: "machine-0", key: ...
Dec 1 06:25:02 state-host mongod.37017[22248]: Thu Dec 1 06:25:02.728 [conn7140] authenticate db: admin { authenticate: 1, nonce: "xxx", user: "machine-0", key: ...

This has the potential to fill up a disk real fast.

[Anastasia (anastasia-macmood)]

Juju uses lumberjack library to produce logs. We will be adding compression to the library and modifying both Juju 1.x and Juju 2.x to compress logs.

I am marking this one as a duplicate of bug # 1494661 as we are using it to track this issue.

[Peter Sabaini (peter-sabaini)]

Anastasia, I don't think this is related to bug #1494661. The log I'm referring to is /var/log/syslog and is fed by juju-db primarily afaict. The log is rotated and compressed just fine, but as it's producing 40Gb of data per day it still fills up a disk very quickly.

[Anastasia (anastasia-macmood)]

@Peter,

This is the correct information ;D
Juju 1.25 uses mongo 2.4. Mongo fixed log spam in version 3.

[Peter Sabaini (peter-sabaini)]

Anastasia, is running mongo v3 supported for running with Juju 1.25? Can we just upgrade it?

[John A Meinel (jameinel)]

1.25 doesn't support Mongo 3. It is possible to add rsyslog filters to omit these from syslog, I don't remember the exact strings. My email searches aren't turning it up immediately, I'll try to track down what people were using.

Something along the lines of:
http://www.rsyslog.com/discarding-unwanted-messages/

[John A Meinel (jameinel)]

Something like:

:msg, contains, "getLastError: 1" ~
:msg, contains, "authenticate db: admin" ~

Added to /etc/rsyslog.conf