mysql service holds deleted log files

[Anna Savchenko]

I've observed that two very large files were held by mysql process causing the disk to be 95% utilized.

ubuntu@ubuntu-infra-13-01:~$ juju ssh mysql-innodb-cluster/0
Last login: Thu Feb 1 17:30:08 2024 from 10.131.8.4

ubuntu@juju-c3cb23-0-lxd-8:~$ sudo lsof +L1
lsof: WARNING: can't stat() tracefs file system /sys/kernel/debug/tracing
      Output information may be incomplete.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NLINK NODE NAME
unattende 332 root 3w REG 8,34 113 0 301747 /var/log/unattended-upgrades/unattended-upgrades-shutdown.log.1 (deleted)
mysqld 348 mysql 1w REG 8,34 104091260620 0 1750078 /var/log/mysql/error.log.1 (deleted)
mysqld 348 mysql 2w REG 8,34 104091260620 0 1750078 /var/log/mysql/error.log.1 (deleted)
mysqld 348 mysql 6u REG 8,34 0 0 134193 /tmp/#134193 (deleted)
mysqld 348 mysql 7u REG 8,34 142 0 134226 /tmp/#134226 (deleted)
mysqld 348 mysql 8u REG 8,34 64710 0 136080 /tmp/#136080 (deleted)
mysqld 348 mysql 13u REG 8,34 2174 0 136916 /tmp/#136916 (deleted)
landscape 1118 root 6w REG 8,34 361 0 304942 /var/log/landscape/watchdog.log.1 (deleted)
landscape 1120 landscape 6w REG 8,34 2207957 0 305187 /var/log/landscape/broker.log.1 (deleted)
landscape 1121 landscape 6w REG 8,34 1690223 0 305186 /var/log/landscape/monitor.log.1 (deleted)
landscape 1122 root 6w REG 8,34 536214 0 305185 /var/log/landscape/manager.log.1 (deleted)

Two /var/log/mysql/error.log.1 files 104091260620 bytes each.

After restarting mysql service, the files got released and disk utilization went down.

ubuntu@juju-c3cb23-0-lxd-8:~$ sudo systemctl restart mysql.service

ubuntu@juju-c3cb23-0-lxd-8:~$ sudo lsof +L1
lsof: WARNING: can't stat() tracefs file system /sys/kernel/debug/tracing
      Output information may be incomplete.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NLINK NODE NAME
unattende 332 root 3w REG 8,34 113 0 301747 /var/log/unattended-upgrades/unattended-upgrades-shutdown.log.1 (deleted)
landscape 1118 root 6w REG 8,34 361 0 304942 /var/log/landscape/watchdog.log.1 (deleted)
landscape 1120 landscape 6w REG 8,34 2207957 0 305187 /var/log/landscape/broker.log.1 (deleted)
landscape 1121 landscape 6w REG 8,34 1690223 0 305186 /var/log/landscape/monitor.log.1 (deleted)
landscape 1122 root 6w REG 8,34 536214 0 305185 /var/log/landscape/manager.log.1 (deleted)
mysqld 1773156 mysql 6u REG 8,34 0 0 134193 /tmp/#134193 (deleted)
mysqld 1773156 mysql 7u REG 8,34 0 0 134226 /tmp/#134226 (deleted)
mysqld 1773156 mysql 8u REG 8,34 0 0 136080 /tmp/#136080 (deleted)
mysqld 1773156 mysql 13u REG 8,34 0 0 136916 /tmp/#136916 (deleted)

ubuntu@juju-c3cb23-0-lxd-8:~$ df -h
Filesystem Size Used Avail Use% Mounted on
/dev/sdc2 229G 108G 109G 50% /
none 492K 4.0K 488K 1% /dev
tmpfs 100K 0 100K 0% /dev/lxd
tmpfs 100K 0 100K 0% /dev/.lxd-mounts
tmpfs 189G 0 189G 0% /dev/shm
tmpfs 76G 328K 76G 1% /run
tmpfs 5.0M 0 5.0M 0% /run/lock
snapfuse 56M 56M 0 100% /snap/core18/2812
snapfuse 75M 75M 0 100% /snap/core22/1033
snapfuse 64M 64M 0 100% /snap/core20/1891
snapfuse 112M 112M 0 100% /snap/lxd/24322
snapfuse 94M 94M 0 100% /snap/mysql-shell/29
snapfuse 6.2M 6.2M 0 100% /snap/prometheus-grok-exporter/1
snapfuse 41M 41M 0 100% /snap/snapd/20290
snapfuse 64M 64M 0 100% /snap/core20/2105
snapfuse 41M 41M 0 100% /snap/snapd/20671
snapfuse 115M 115M 0 100% /snap/lxd/26741
snapfuse 270M 270M 0 100% /snap/grafana-agent/16
tmpfs 38G 4.0K 38G 1% /run/user/1000

Ubuntu 22.04.3 LTS
Openstack Yoga
Juju 3.1.6
LXD 5.0.2
MAAS 3.2.10

How to reproduce: monitor disk utilization and the output of "sudo lsof +L1"

Noticed this error in the journalctl output: "Feb 01 20:17:01 juju-c3cb23-0-lxd-2 sudo[356539]: root : command not allowed ; PWD=/ ; USER=root ; COMMAND=/usr/bin/juju-run logrotated/13 '/var/lib/juju/agents/unit-logrotated-13/.venv/bin/python3 /var/lib/juju/agents/unit-logrotated-13/charm/lib/lib_cron.py'"

The error was repeated many times.

[Anna Savchenko (annsavchenko)]

Found this in journalctl output:

Feb 02 00:00:09 juju-c3cb23-7-lxd-8 logrotate[1754765]: error: error running shared postrotate script for '/var/log/mysql.log /var/log/mysql/*log '
Feb 02 00:00:09 juju-c3cb23-7-lxd-8 systemd[1]: logrotate.service: Main process exited, code=exited, status=1/FAILURE
Feb 02 00:00:09 juju-c3cb23-7-lxd-8 systemd[1]: logrotate.service: Failed with result 'exit-code'.
Feb 02 00:00:09 juju-c3cb23-7-lxd-8 systemd[1]: Failed to start Rotate log files.

When I try to execute mysql-server job (/etc/logrotate.d/mysql-server), I get this error:

root@juju-c3cb23-7-lxd-8:/etc/logrotate.d# MYADMIN="/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf"

root@juju-c3cb23-7-lxd-8:/etc/logrotate.d# $MYADMIN ping
mysqladmin: connect to server at 'localhost' failed

[Anna Savchenko (annsavchenko)]

root@juju-c3cb23-7-lxd-8:/etc/logrotate.d# $MYADMIN ping
mysqladmin: connect to server at 'localhost' failed
error: 'Access denied for user 'debian-sys-maint'@'localhost' (using password: YES)'

[Anna Savchenko (annsavchenko)]

subscribed ~field-high

[Anna Savchenko (annsavchenko)]

Subscribed Field High as this might affect the customer at any point.

[Alex Kavanagh (ajkavanagh)]

Anna, can you have a look and see if the 'debian-sys-maint' user exists in the database (mysql table). Also you could check if the debian-sys-maint user can login with the password in /etc/mysql/debian.cnf

The mysql-server-9.0 package's postinst should create the user in the DB and the file in /etc/mysql/debian.cnf. If the user is missing, then perhaps it never got created (packaging bug), or the user has been removed at some point in the installation (charm bug? -- but I can't find any evidence), or some locking down/security process that's been done to the mysql instances?

[Launchpad Janitor (janitor)]

[Expired for MySQL InnoDB Cluster Charm because there has been no activity for 60 days.]

[Anna Savchenko (annsavchenko)]

Hey Alex, apologies for the late response!

I tried to login to mysql with the creds in /etc/mysql/debian.cnf and got "access denied"

$ sudo mysql -u debian-sys-maint -p
Enter password:
ERROR 1045 (28000): Access denied for user 'debian-sys-maint'@'localhost' (using password: YES)

I tried to login with the mysql user in order to check the database but got "access denied" as well.

[Victor Vavan (victorvavan)]

Hi all,

I'm dealing with a case that is suffering from this bug.

$ sudo lsof +L1
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NLINK NODE NAME
mysqld 328 mysql 1w REG 8,3 99624508241 0 23331627 /var/log/mysql/error.log.1 (deleted)
mysqld 328 mysql 2w REG 8,3 99624508241 0 23331627 /var/log/mysql/error.log.1 (deleted)
mysqld 328 mysql 6u REG 8,3 0 0 21794716 /tmp/#21794716 (deleted)
mysqld 328 mysql 7u REG 8,3 142 0 21794718 /tmp/#21794718 (deleted)
mysqld 328 mysql 8u REG 8,3 0 0 21794720 /tmp/#21794720 (deleted)
mysqld 328 mysql 13u REG 8,3 2175 0 21794755 /tmp/#21794755 (deleted)
filebeat 572 root 18r REG 8,3 99624508701 0 23331627 /var/log/mysql/error.log.1 (deleted)
landscape 575 root 6w REG 8,3 353 0 21794792 /var/log/landscape/watchdog.log.1 (deleted)
landscape 842 landscape 6w REG 8,3 2166444 0 21784887 /var/log/landscape/broker.log.1 (deleted)
landscape 843 landscape 6w REG 8,3 2737262 0 21794803 /var/log/landscape/monitor.log.1 (deleted)
landscape 844 root 6w REG 8,3 600319 0 21794805 /var/log/landscape/manager.log.1 (deleted)

# /usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf ping
mysqladmin: connect to server at 'localhost' failed
error: 'Access denied for user 'debian-sys-maint'@'localhost' (using password: YES)'

Workaround: restart MySQL application manually.

The username/password combination in /etc/mysql/debian.cnf for user debian-sys-maint do NOT work.

We logged into MySQL:

juju exec --unit mysql/leader leader-get mysql.passwd
juju ssh mysql/leader
sudo mysql -u root -p"<password>"

The user is present in the DB:

+-----------+------------------+
| Host | User |
+-----------+------------------+
| localhost | debian-sys-maint |
+-----------+------------------+

Ubuntu Focal
Openstack Yoga
Juju 2.9.43
mysql-innodb-cluster 8.0/stable

I changed the password for user debian-sys-maint to reflect what is in /etc/mysql/debian.cnf

ALTER user 'debian-sys-maint'@'localhost' IDENTIFIED by 'LMfSBaA9l2z4EdjD1';

I could then log in as the user and the section that was failing in /etc/logrotate.d/mysql-server succeeds:

sudo /usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf ping
mysqld is alive

The changes persist through reboot of the MySQL units.

I'm not sure what triggered the password change in debian.cnf (or MySQL?) however.