juju-db spams syslog, fills disk

[Barry Price]

Left to its own devices for a while, Juju 1.25.9 on the controller node ends up in this state:

top - 03:03:15 up 55 days, 46 min, 3 users, load average: 17.48, 21.47, 23.62

18215 root 20 0 1056272 189140 11116 S 51.7 10.9 5502:23 jujud
18140 root 20 0 4758508 97068 0 R 43.1 5.6 4362:40 mongod

ubuntu@ip-10-174-85-194:~$ sudo tail /var/log/syslog
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.673 [conn43] command admin.$cmd command: { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" } ntoreturn:1 keyUpdates:0 locks(micros) r:135 reslen:75 185ms
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.268 [conn204] authenticate db: admin { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" }
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.676 [conn204] command admin.$cmd command: { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" } ntoreturn:1 keyUpdates:0 locks(micros) r:149 reslen:75 408ms
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.506 [conn575] authenticate db: admin { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" }
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.722 [conn575] command admin.$cmd command: { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" } ntoreturn:1 keyUpdates:0 locks(micros) r:154 reslen:75 215ms
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.508 [conn453] authenticate db: admin { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" }
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.723 [conn453] command admin.$cmd command: { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" } ntoreturn:1 keyUpdates:0 locks(micros) r:144 reslen:75 215ms
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.334 [conn49] authenticate db: admin { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" }
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.659 [conn118] authenticate db: admin { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" }
Aug 9 03:03:43 ip-10-174-85-194 mongod.37017[18140]: Wed Aug 9 03:03:43.660 [conn196] authenticate db: admin { authenticate: 1, nonce: "<snip>", user: "machine-0", key: "<snip>" }
ubuntu@ip-10-174-85-194:~$ sudo grep 'Wed Aug 9 03:03:43' /var/log/syslog | wc -l
433
ubuntu@ip-10-174-85-194:~$ sudo grep mongod /var/log/syslog | wc -l
7150318
ubuntu@ip-10-174-85-194:~$ ls -lh /var/log/syslog
-rw------- 1 syslog adm 1.7G Aug 9 03:10 /var/log/syslog
ubuntu@ip-10-174-85-194:~$

That's 400+ lines per second being dumped into syslog by mongo, which quickly fills the disk.

Things return to normal if I stop the jujud-machine-0 service and then restart the juju-db service, before starting jujud-machine-0 once again.

[Thomas Cuthbert (tcuthbert)]

Hit this bug today on a version 1.25.12 controller
ubuntu@ip-10-174-85-194:/var/log$ sudo zgrep mongod syslog.1.gz| wc -l
7266023

[Barry Price (barryprice)]

Also seen in a 1.25.6 env, which is the current supported version in Trusty:

ubuntu@[hostname]:~$ grep mongod /var/log/syslog | wc -l
5338755
ubuntu@[hostname]:~$

[Haw Loeung (hloeung)]

Seems related to LP bug #1349949.

[John A Meinel (jameinel)]

https://bugs.launchpad.net/juju/+bug/1349949/comments/12

:msg, contains, "warning: No such role, \"clusterAdmin\"" ~
:msg, contains, "warning: No such role, \"readWriteAnyDatabase\"" ~
:msg, contains, "authenticate db:" ~

And also as a MAAS preseed from:
https://bugs.launchpad.net/juju/+bug/1349949/comments/22

There are workarounds for this, and it doesn't impact juju-2.x with Mongo 3.2 so I believe this is on our Won't Fix list.

[Barry Price (barryprice)]

Surely the package should set those syslog options, rather than users having to search the web for a fix.

What's the workaround for the high load and RAM/CPU usage?

[John A Meinel (jameinel)]

Upgrading to 2.x fixes most of these issues.

John
=:->

On Wed, Aug 30, 2017 at 6:05 AM, Barry Price <email address hidden>
wrote:

> Surely the package should set those syslog options, rather than users
> having to search the web for a fix.
>
> What's the workaround for the high load and RAM/CPU usage?
>
> --
> You received this bug notification because you are subscribed to juju-
> core.
> https://bugs.launchpad.net/bugs/1709520
>
> Title:
> juju-db spams syslog, fills disk
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/juju-core/+bug/1709520/+subscriptions
>