Subject: [Pkg-cacti-maint] Bug#1031116: autopkgtest for cacti/1.2.23+ds1-2 fails as dbconfig-common attempts to create database before any server is up

From: Otto Kekäläinen <[email-masked]>
Date: Sat, 11 Feb 2023 16:29:26 -0800

Package: cacti

(Filing against cacti for now for visibility, actual root cause might
be elsewhere.)

After uploading mariadb 1:10.11.1-4 the autopkgtests for cacti started
failing on all architectures. I suspect the problem is that the
mariadbd server is not running at the time when dbconfig-common
attempts to create credentials for cacti.

Note in log https://ci.debian.net/data/autopkgtest/testing/s390x/d/dbconfig-common/31204959/log.gz
section:

Setting up mariadb-server (1:10.11.1-4) ...
Created symlink
/etc/systemd/system/multi-user.target.wants/mariadb.service →
/lib/systemd/system/mariadb.service.
Could not execute systemctl:  at /usr/bin/deb-systemd-invoke line 145.
...
Determining localhost credentials from /etc/mysql/debian.cnf: succeeded.
...
dbconfig-common: writing config to /etc/dbconfig-common/db-test-multidbtype.conf
debconf (developer): <-- X_LOADTEMPLATEFILE /var/lib/dpkg/info/ucf.templates ucf
debconf (developer): --> 0

Creating config file /etc/dbconfig-common/db-test-multidbtype.conf
with new version
dbc_read_package_config() .
dbc_detect_installed_dbtype() mysql.
_dbc_detect_installed_dbtype() mysql.
dbc_get_admin_pass() .
debconf (developer): <-- FGET db-test-multidbtype/mysql/admin-pass seen
debconf (developer): --> 0 true
debconf (developer): <-- GET db-test-multidbtype/mysql/admin-pass
debconf (developer): --> 0
_dbc_detect_installed_dbtype() mysql.
ERROR 2002 (HY000): Can't connect to local server through socket
'/run/mysqld/mysqld.sock' (2).
unable to connect to mysql server.

Line 145 in /usr/bin/deb-systemd-invoke is:

            system('systemctl', '--quiet', @instance_args, $action,
@start_units) == 0 or die("Could not execute systemctl: $!");

Looking at previous log
https://ci.debian.net/data/autopkgtest/testing/amd64/c/cacti/31113621/log.gz
(with MariaDB 1:10.11.1-3) this section has:

Setting up mariadb-server (1:10.11.1-3) ...
Created symlink
/etc/systemd/system/multi-user.target.wants/mariadb.service →
/lib/systemd/system/mariadb.service.

There is nothing about deb-systemd-invoke.

When I run this manually inside failed cacti autopkgtest shell I get:

root@fb9c1752c1c7:/tmp/autopkgtest.n2vt3p/build.b5I/real-tree#
/usr/bin/deb-systemd-invoke restart mariadb
sh: 1: systemctl: not found
Can't exec "systemctl": No such file or directory at
/usr/bin/deb-systemd-invoke line 133.
mariadb is a disabled or a static unit not running, not starting it.

Reproducing this manually:
# /usr/bin/deb-systemd-invoke restart mariadb
ERROR:systemctl:the ExecStartPre control process exited with error code
Could not execute systemctl:  at /usr/bin/deb-systemd-invoke line 145.

After applying some debugging seems the script attempts to run:
systemctl --quiet --system restart mariadb

Checking what the systemd service file tries to run:
# grep ExecStartPre /lib/systemd/system/mariadb.service
ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld
ExecStartPre=/bin/sh -c "systemctl unset-environment _WSREP_START_POSITION"
ExecStartPre=/bin/sh -c "[ ! -e /usr/bin/galera_recovery ] && VAR= || \

If systemctl is used from package 'systemctl' (not real, but systemd
shim) the start is bound to fail:
# systemctl unset-environment
ERROR:systemctl:Unknown operation unset-environment.

However, nothing about this changed in MariaDB 10.11.1-4.

# diff -u mariadb.service-10.6.11-2 mariadb.service-10.11.1-4
--- mariadb.service-10.6.11-2 2023-02-12 00:22:18.522820677 +0000
+++ mariadb.service-10.11.1-4 2023-02-12 00:25:01.013942479 +0000
@@ -19,7 +19,7 @@
 # (at your option) any later version.

 [Unit]
-Description=MariaDB 10.6.11 database server
+Description=MariaDB 10.11.1 database server
 Documentation=man:mariadbd(8)
 Documentation=https://mariadb.com/kb/en/library/systemd/
 After=network.target

# systemctl restart mariadb
ERROR:systemctl:the ExecStartPre control process exited with error code
# dpkg -S /lib/systemd/system/mariadb.service
mariadb-server-10.6: /lib/systemd/system/mariadb.service

Did cacti perhaps change how it uses systemd/systemctl?

Probably not, the same version of cacti has been in Debian for a long
time. Latest upload of dbconfig-common was on Feb 2nd, and after that
MariaDB 10.11.1-3 was still working on Feb 3rd..

Suggestions on what to debug next welcome.

---

From: Otto Kekäläinen <[email-masked]>
Date: Sat, 11 Feb 2023 16:45:58 -0800

Ignore everything in the initial bug report, I was accidentally
looking at s390x log which has a completely different root cause
(Linux kernel bug on s390x that affects MariaDB and prevents it from
running).

I found out the actual root cause by putting the last passing log
(https://ci.debian.net/data/autopkgtest/testing/amd64/c/cacti/31113621/log.gz)
and equivalent failing one
(https://ci.debian.net/data/autopkgtest/testing/amd64/c/cacti/31254901/log.gz)
for amd64 in meld to compare side-by-side.

The difference is in what order apt-get sets up the packages. See
attached screenshots.

First one shows MariaDB being set up early in the process before cacti:

Setting up apache2-bin (2.4.55-1) ...
Setting up libcairo2:amd64 (1.16.0-7) ...
Setting up mariadb-server (1:10.11.1-3) ...
Created symlink
/etc/systemd/system/multi-user.target.wants/mariadb.service →
/lib/systemd/system/mariadb.service.
Setting up libjs-jquery-ui-touch-punch (0.0~git20141218.2.4bc0091+dfsg1-4.1) ...
Setting up php-ldap (2:8.2+93) ...
Setting up php8.2-xml (8.2.2-1) ...
...
Setting up rrdtool (1.7.2-4+b8) ...
Setting up cacti (1.2.23+ds1-2) ...
Determining localhost credentials from /etc/mysql/debian.cnf: succeeded.
dbconfig-common: writing config to /etc/dbconfig-common/cacti.conf
Creating config file /etc/dbconfig-common/cacti.conf with new version
Creating config file /etc/cacti/debian.php with new version
checking privileges on database cacti for cacti@localhost: user creation needed.
granting access to database cacti for cacti@localhost: success.
verifying access for cacti@localhost: success.
creating database cacti: success.
verifying database cacti exists: success.
populating database via administrative sql...  done.
populating database via sql...  done.
dbconfig-common: flushing administrative password
Creating config file /etc/apache2/conf-available/cacti.conf with new version
Creating config file /etc/lighttpd/conf-available/20-cacti.conf with new version
Loading default cacti templates (may take some time)..............  done.
apache2_invoke: Enable configuration cacti
Setting up autopkgtest-satdep (0) ...

The latter one shows cacti trying to set up itself before
mariadb-server, and thus fails:

Setting up rrdtool (1.7.2-4+b8) ...
Setting up cacti (1.2.23+ds1-2) ...
dbconfig-common: writing config to /etc/dbconfig-common/cacti.conf
Creating config file /etc/dbconfig-common/cacti.conf with new version
Creating config file /etc/cacti/debian.php with new version
ERROR 2002 (HY000): Can't connect to local server through socket
'/run/mysqld/mysqld.sock' (2).
unable to connect to mysql server.
error encountered creating user:
ERROR 2002 (HY000): Can't connect to local server through socket
'/run/mysqld/mysqld.sock' (2)
dbconfig-common: cacti configure: noninteractive fail.
dbconfig-common: cacti configure: ignoring errors from here forwards
populating database via administrative sql...  done.
populating database via sql...  done.
dbconfig-common: flushing administrative password
Creating config file /etc/apache2/conf-available/cacti.conf with new version
Creating config file /etc/lighttpd/conf-available/20-cacti.conf with new version
apache2_invoke: Enable configuration cacti
Setting up mariadb-plugin-provider-bzip2 (1:10.11.1-4) ...
Setting up mariadb-plugin-provider-lzma (1:10.11.1-4) ...
Setting up mariadb-plugin-provider-lzo (1:10.11.1-4) ...
Setting up mariadb-plugin-provider-lz4 (1:10.11.1-4) ...
Setting up mariadb-plugin-provider-snappy (1:10.11.1-4) ...
Setting up mariadb-server (1:10.11.1-4) ...
Created symlink
/etc/systemd/system/multi-user.target.wants/mariadb.service →
/lib/systemd/system/mariadb.service.
Setting up autopkgtest-satdep (0) ...
Processing triggers for libc-bin (2.36-8) ...
Processing triggers for php8.2-cli (8.2.2-1) ...
Processing triggers for libapache2-mod-php8.2 (8.2.2-1) ...
(Reading database ... 21124 files and directories currently installed.)
Removing autopkgtest-satdep (0) ...

This happened because of
https://salsa.debian.org/mariadb-team/mariadb-server/-/commit/5545bb341808cef8a4227b55b0c75e331cc48c96

However that is a valid fix, I would not rush to revert it.

Can we force cacti to wait until mariadb-server is fully setup before
it tries to connect to it?

---

From: Paul Gevers <[email-masked]>
Date: Sun, 12 Feb 2023 08:28:44 +0100

Hi Otto,

> Did cacti perhaps change how it uses systemd/systemctl?

cacti doesn't use systemd nor systemctl

> MariaDB 10.11.1-3 was still working on Feb 3rd..

Agreed. cacti nor dbconfig-common changed in years on this front. It 
does expect the MariaDB server to be running and has always done so.

Of course I can accommodate for changes in MariaDB, but I need to 
understand what changed in MariaDB. From my side it's obviously a delta 
between the two MariaDB versions.

I'm also seeing this in the (amd64) log (but it's a warning)
"""
Preparing to unpack .../000-mariadb-server_1%3a10.11.1-4_amd64.deb ...
adduser: Warning: The home dir /nonexistent you specified can't be 
accessed: No such file or directory
"""
while that's not there in a successful run I inspected. Maybe unrelated 
but I noticed that the amount of "mysql-common" occurrences in a 
successful log is different than in a failed log.

 > ERROR:systemctl:the ExecStartPre control process exited with error code

That looks pretty bad and has nothing to do with cacti.

 > mariadb-server-10.6: /lib/systemd/system/mariadb.service

But that's the version in testing, no?

Paul

---

From: Otto Kekäläinen <[email-masked]>
Date: Sat, 11 Feb 2023 23:36:53 -0800

Please see my second message
(https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1031116#10), I
later found out the exact commit that introduced this and why.

On Sat, 11 Feb 2023 at 23:28, Paul Gevers <[email-masked]> wrote:
...
> accessed: No such file or directory

Not related. This is expected for machine accounts that don't have
real home directories.

> That looks pretty bad and has nothing to do with cacti.

This was actually not the root cause. MariaDB failing to start
happened on s390x only and for other reasons.

Actual root cause that completely breaks cacti autopkgtests is the
changed ordering in apt (check my second message).

---

From: Otto Kekäläinen <[email-masked]>
Date: Sun, 12 Feb 2023 16:08:57 -0800

I am working to fix this, but as a side note, for real users this also
happens but is not super serious as they get out of trouble by simply
re-running the exact same apt command:

$ apt install -y cacti
...
Setting up cacti (1.2.23+ds1-2) ...
dbconfig-common: writing config to /etc/dbconfig-common/cacti.conf
Creating config file /etc/dbconfig-common/cacti.conf with new version
Creating config file /etc/cacti/debian.php with new version
ERROR 2002 (HY000): Can't connect to local server through socket
'/run/mysqld/mysqld.sock' (2).
unable to connect to mysql server.
error encountered creating user:
ERROR 2002 (HY000): Can't connect to local server through socket
'/run/mysqld/mysqld.sock' (2)
dbconfig-common: cacti configure: aborted.
dbconfig-common: flushing administrative password
dpkg: error processing package cacti (--configure):
 installed cacti package post-installation script subprocess returned
error exit status 1
Setting up mariadb-plugin-provider-bzip2 (1:10.11.2-0~exp1) ...
Setting up mariadb-plugin-provider-lzma (1:10.11.2-0~exp1) ...
Setting up mariadb-plugin-provider-lzo (1:10.11.2-0~exp1) ...
Setting up mariadb-plugin-provider-lz4 (1:10.11.2-0~exp1) ...
Setting up mariadb-plugin-provider-snappy (1:10.11.2-0~exp1) ...
Setting up mariadb-server (1:10.11.2-0~exp1) ...
Stopping MariaDB database server: mariadbd.
Starting MariaDB database server: mariadbd.
Setting up default-mysql-server (1.1.0) ...
Processing triggers for libc-bin (2.36-8) ...
Processing triggers for ca-certificates (20211016) ...
Updating certificates in /etc/ssl/certs...
0 added, 0 removed; done.
Running hooks in /etc/ca-certificates/update.d...
done.
Processing triggers for php8.2-cli (8.2.2-3) ...
Processing triggers for libapache2-mod-php8.2 (8.2.2-3) ...
Errors were encountered while processing:
 cacti
E: Sub-process /usr/bin/dpkg returned an error code (1)

$ apt install -y cacti
Reading package lists... Done
Building dependency tree... Done
Reading state information... Done
cacti is already the newest version (1.2.23+ds1-2).
0 upgraded, 0 newly installed, 0 to remove and 11 not upgraded.
1 not fully installed or removed.
After this operation, 0 B of additional disk space will be used.
Setting up cacti (1.2.23+ds1-2) ...
Determining localhost credentials from /etc/mysql/debian.cnf: succeeded.
dbconfig-common: writing config to /etc/dbconfig-common/cacti.conf
checking privileges on database cacti for cacti@localhost: user creation needed.
granting access to database cacti for cacti@localhost: success.
verifying access for cacti@localhost: success.
creating database cacti: success.
verifying database cacti exists: success.
populating database via administrative sql...  done.
populating database via sql...  done.
dbconfig-common: flushing administrative password
Creating config file /etc/apache2/conf-available/cacti.conf with new version
Creating config file /etc/lighttpd/conf-available/20-cacti.conf with new version
Loading default cacti templates (may take some time)..............  done.
Created directory: /var/lib/snmp/cert_indexes
apache2_invoke: Enable configuration cacti
Reloading Apache httpd web server: apache2.

$ mariadb -E -e "SHOW CREATE TABLE version;" cacti
*************************** 1. row ***************************
       Table: version
Create Table: CREATE TABLE `version` (
  `cacti` char(20) NOT NULL DEFAULT '',
  PRIMARY KEY (`cacti`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1 COLLATE=latin1_swedish_ci
ROW_FORMAT=DYNAMIC
root@e7fa16a54a88:/build#

---

From: "Debian Bug Tracking System" <[email-masked]>
Date: Mon, 13 Feb 2023 02:27:03 +0000

Processing control commands:

> tag -1 pending
Bug #1031116 [cacti] autopkgtest for cacti/1.2.23+ds1-2 fails as dbconfig-common attempts to create database before any server is up
Added tag(s) pending.

-- 
1031116: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1031116
Debian Bug Tracking System
Contact [email-masked] with problems

---

From: "Debian Bug Tracking System" <[email-masked]>
Date: Thu, 16 Feb 2023 04:45:03 +0000

Bug #1031116 [cacti] autopkgtest for cacti/1.2.23+ds1-2 fails as dbconfig-common attempts to create database before any server is up
Ignoring request to alter tags of bug #1031116 to the same tags previously set

---

From: "Debian Bug Tracking System" <[email-masked]>
Date: Thu, 16 Feb 2023 09:00:08 +0000

Your message dated Thu, 16 Feb 2023 08:55:56 +0000
with message-id <[email-masked]>
and subject line Bug#1031116: fixed in mariadb 1:10.11.1-5
has caused the Debian Bug report #1031116,
regarding autopkgtest for cacti/1.2.23+ds1-2 fails as dbconfig-common attempts to create database before any server is up
to be marked as done.

This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.

(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact [email-masked]
immediately.)

Subject: autopkgtest for cacti/1.2.23+ds1-2 fails as dbconfig-common attempts to create database before any server is up
From: Otto Kekäläinen <[email-masked]>
To: [email-masked]
Date: Sat, 11 Feb 2023 16:29:26 -0800

Package: cacti

Looking at previous log

 [Unit]

Subject: Bug#1031116: fixed in mariadb 1:10.11.1-5
From: Debian FTP Masters <[email-masked]>
To: [email-masked]
Date: Thu, 16 Feb 2023 08:55:56 +0000

Source: mariadb
Source-Version: 1:10.11.1-5
Done: Otto Kekäläinen <[email-masked]>

We believe that the bug you reported is fixed in the latest version of
mariadb, which is due to be installed in the Debian FTP archive.

A summary of the changes between this version and the previous one is
attached.

Thank you for reporting the bug, which will now be closed.  If you
have further comments please address them to [email-masked],
and the maintainer will reopen the bug report if appropriate.

Debian distribution maintenance software
pp.
Otto Kekäläinen <[email-masked]> (supplier of updated mariadb package)

(This message was generated automatically at their request; if you
believe that there is a problem with it please contact the archive
administrators by mailing [email-masked])

Format: 1.8
Date: Wed, 15 Feb 2023 22:57:46 -0800
Source: mariadb
Binary: libmariadb-dev libmariadb-dev-compat libmariadb3 libmariadbd19 libmariadbd-dev mariadb-common mariadb-client-core mariadb-client mariadb-server-core mariadb-server mariadb-backup mariadb-plugin-connect mariadb-plugin-s3 mariadb-plugin-rocksdb mariadb-plugin-oqgraph mariadb-plugin-mroonga mariadb-plugin-spider mariadb-plugin-gssapi-server mariadb-plugin-gssapi-client mariadb-plugin-cracklib-password-check mariadb-plugin-hashicorp-key-management mariadb-plugin-provider-bzip2 mariadb-plugin-provider-lz4 mariadb-plugin-provider-lzma mariadb-plugin-provider-lzo mariadb-plugin-provider-snappy mariadb-test mariadb-test-data
Architecture: source
Version: 1:10.11.1-5
Distribution: unstable
Urgency: medium
Maintainer: Debian MySQL Maintainers <[email-masked]>
Changed-By: Otto Kekäläinen <[email-masked]>
Description:
 libmariadb-dev - MariaDB database development files
 libmariadb-dev-compat - MariaDB Connector/C, compatibility symlinks
 libmariadb3 - MariaDB database client library
 libmariadbd-dev - MariaDB embedded database, development files
 libmariadbd19 - MariaDB embedded database, shared library
 mariadb-backup - Backup tool for MariaDB server
 mariadb-client - MariaDB database client binaries
 mariadb-client-core - MariaDB database core client binaries
 mariadb-common - MariaDB common configuration files
 mariadb-plugin-connect - Connect storage engine for MariaDB
 mariadb-plugin-cracklib-password-check - CrackLib Password Validation Plugin for MariaDB
 mariadb-plugin-gssapi-client - GSSAPI authentication plugin for MariaDB client
 mariadb-plugin-gssapi-server - GSSAPI authentication plugin for MariaDB server
 mariadb-plugin-hashicorp-key-management - Hashicorp Key Management plugin for MariaDB
 mariadb-plugin-mroonga - Mroonga storage engine for MariaDB
 mariadb-plugin-oqgraph - OQGraph storage engine for MariaDB
 mariadb-plugin-provider-bzip2 - BZip2 compression support in the server and storage engines
 mariadb-plugin-provider-lz4 - LZ4 compression support in the server and storage engines
 mariadb-plugin-provider-lzma - LZMA compression support in the server and storage engines
 mariadb-plugin-provider-lzo - LZO compression support in the server and storage engines
 mariadb-plugin-provider-snappy - Snappy compression support in the server and storage engines
 mariadb-plugin-rocksdb - RocksDB storage engine for MariaDB
 mariadb-plugin-s3 - Amazon S3 archival storage engine for MariaDB
 mariadb-plugin-spider - Spider storage engine for MariaDB
 mariadb-server - MariaDB database server binaries
 mariadb-server-core - MariaDB database core server files
 mariadb-test - MariaDB database regression test suite
 mariadb-test-data - MariaDB database regression test suite - data files
Closes: 1030581 1030908 1031116 1031244
Changes:
 mariadb (1:10.11.1-5) unstable; urgency=medium
 .
   [ Otto Kekäläinen ]
   * Packages mariadb-plugin-provider-* must depend at least on MariaDB 10.11
   * Make postinstall check work with more than one result (Closes: #1031244)
   * Revert "Compression plugins as Depends for mariadb-server" (Closes: #1031116)
     to not break the Cacti autopkgtests and allow the mariadb-10.6 autopkgtest
     to fail instead (re-introducing Bug#1031116)
 .
   [ Bubu ]
   * Update French translation of debconf messages (Closes: #1030581)
 .
   [ Adriano Rafael Gomes ]
   * Update Brazilian translation of debconf messages (Closes: #1030908)
Checksums-Sha1:
 8aa644a1f236bc56d82875fd93ec98884bca842e 5004 mariadb_10.11.1-5.dsc
 bc2c1088be56416c761600d80a5d8c240303390d 268460 mariadb_10.11.1-5.debian.tar.xz
 5b7ba84013ef28b4ef2a884e629d16c865898e8d 9517 mariadb_10.11.1-5_source.buildinfo
Checksums-Sha256:
 46d1b92d06fa0745b1b3a16495ced56cba552e6e77b119a582d9172d0cf42eae 5004 mariadb_10.11.1-5.dsc
 167644c1305edddb76e9935ec56636aeed663b1a9c283bf6754faaef580ff9c4 268460 mariadb_10.11.1-5.debian.tar.xz
 c5ed2e84d99f5d03e0b1a8bb5b584241bffd5fd0b356247c23c1e7e5a9c0d16a 9517 mariadb_10.11.1-5_source.buildinfo
Files:
 d06920f5bad39db5edeebf03ff1f9f8b 5004 database optional mariadb_10.11.1-5.dsc
 c7fe492dc1c378266a11473883086fa1 268460 database optional mariadb_10.11.1-5.debian.tar.xz
 b71641159f6fb7e6cd4392d6ff15963e 9517 database optional mariadb_10.11.1-5_source.buildinfo