[debian-mysql] Bug#1058706: mariadb-server-core: mariadbd fails to start on fresh install on armel

Scott Barker scott at mostlylinux.ca
Wed Dec 20 22:20:06 GMT 2023


On my secondard ARM NAS, I downgraded from bookworm to bullseye, and 
installed mariadb 10.5 from scratch (no pre-existing /var/lib/mysql or 
/etc/mysql). Everything worked without issues. From syslog:

mysqld_safe: Starting mariadbd daemon with databases from /var/lib/mysql
mysqld: 2023-12-20  7:58:07 0 [Note] Starting MariaDB 10.5.21-MariaDB-0+deb11u1 source revision bed70468ea08c2820647f5e3ac006a9ff88144ac as process 2250
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Uses event mutexes
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Number of pools: 1
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Using generic crc32 instructions
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Using Linux native AIO
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Completed initialization of buffer pool
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: 128 rollback segments are active.
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Creating shared tablespace for temporary tables
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: 10.5.21 started; log sequence number 45079; transaction id 20
mysqld: 2023-12-20  7:58:07 0 [Note] Plugin 'FEEDBACK' is disabled.
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysqld: 2023-12-20  7:58:07 0 [Note] InnoDB: Buffer pool(s) load completed at 231220  7:58:07
mysqld: 2023-12-20  7:58:07 0 [Note] Server socket created on IP: '127.0.0.1'.
mysqld: 2023-12-20  7:58:07 0 [Note] Reading of all Master_info entries succeeded
mysqld: 2023-12-20  7:58:07 0 [Note] Added new Master_info '' to hash table
mysqld: 2023-12-20  7:58:07 0 [Note] /usr/sbin/mariadbd: ready for connections.
mysqld: Version: '10.5.21-MariaDB-0+deb11u1'  socket: '/run/mysqld/mysqld.sock'  port: 3306  Debian 11

I then proceeded to upgrade from bookworm all packages containing libraries 
to which /usr/sbin/mariadbd and /usr/lib/mysql/plugin/* were linked, one at 
a time, restarting mariadb after each package was installed, and there were 
no issues.

I then upgraded the rest of the system to bookworm, a few packages at a 
time, excluding the mariadb packages. I restarted mariadb after each batch 
of packages, and there were no issues, including after reboot into the new 
kernel.

I then renamed /var/lib/mysql to /var/lib/mysql.bak and ran:

dpkg-reconfigure -plow mariadb-server-10.5 mariadb-server-core-10.5

Again, no issues - /var/lib/mysql was re-created and mariadbd started just 
fine, with the same syslog entries as above.

I then copied /var/lib/mysql to /var/lib/mysql-10.5 and upgraded mariadb 
with:

apt upgrade mariadb-server-10.5

Here is the entire output, you can see the errors at the end:

Reading package lists... Done
Building dependency tree... Done
Reading state information... Done
Calculating upgrade... Done
The following packages will be REMOVED:
   mariadb-client-10.5 mariadb-client-core-10.5 mariadb-server-core-10.5
The following NEW packages will be installed:
   libnuma1 liburing2 mariadb-client mariadb-client-core mariadb-server mariadb-server-core
The following packages will be upgraded:
   mariadb-server-10.5
1 upgraded, 6 newly installed, 3 to remove and 0 not upgraded.
Need to get 12.7 MB of archives.
After this operation, 28.0 MB of additional disk space will be used.
Do you want to continue? [Y/n]
Get:1 https://deb.debian.org/debian bookworm/main armel mariadb-server-10.5 armel 1:10.11.4-1~deb12u1 [22.7 kB]
Get:2 https://deb.debian.org/debian bookworm/main armel mariadb-client-core armel 1:10.11.4-1~deb12u1 [754 kB]
Get:3 https://deb.debian.org/debian bookworm/main armel mariadb-client armel 1:10.11.4-1~deb12u1 [2,510 kB]
Get:4 https://deb.debian.org/debian bookworm/main armel libnuma1 armel 2.0.16-1 [18.3 kB]
Get:5 https://deb.debian.org/debian bookworm/main armel liburing2 armel 2.3-3 [13.2 kB]
Get:6 https://deb.debian.org/debian bookworm/main armel mariadb-server-core armel 1:10.11.4-1~deb12u1 [6,328 kB]
Get:7 https://deb.debian.org/debian bookworm/main armel mariadb-server armel 1:10.11.4-1~deb12u1 [3,027 kB]
Fetched 12.7 MB in 5s (2,486 kB/s)
Preconfiguring packages ...
(Reading database ... 24167 files and directories currently installed.)
Preparing to unpack .../mariadb-server-10.5_1%3a10.11.4-1~deb12u1_armel.deb ...
Stopping MariaDB database server: mariadbd.
Unpacking mariadb-server-10.5 (1:10.11.4-1~deb12u1) over (1:10.5.21-0+deb11u1) ...
(Reading database ... 24042 files and directories currently installed.)
Removing mariadb-client-10.5 (1:10.5.21-0+deb11u1) ...
Removing mariadb-client-core-10.5 (1:10.5.21-0+deb11u1) ...
Removing mariadb-server-core-10.5 (1:10.5.21-0+deb11u1) ...
Selecting previously unselected package mariadb-client-core.
(Reading database ... 23850 files and directories currently installed.)
Preparing to unpack .../0-mariadb-client-core_1%3a10.11.4-1~deb12u1_armel.deb ...
Unpacking mariadb-client-core (1:10.11.4-1~deb12u1) ...
Selecting previously unselected package mariadb-client.
Preparing to unpack .../1-mariadb-client_1%3a10.11.4-1~deb12u1_armel.deb ...
Unpacking mariadb-client (1:10.11.4-1~deb12u1) ...
Selecting previously unselected package libnuma1:armel.
Preparing to unpack .../2-libnuma1_2.0.16-1_armel.deb ...
Unpacking libnuma1:armel (2.0.16-1) ...
Selecting previously unselected package liburing2:armel.
Preparing to unpack .../3-liburing2_2.3-3_armel.deb ...
Unpacking liburing2:armel (2.3-3) ...
Selecting previously unselected package mariadb-server-core.
Preparing to unpack .../4-mariadb-server-core_1%3a10.11.4-1~deb12u1_armel.deb ...
Unpacking mariadb-server-core (1:10.11.4-1~deb12u1) ...
Selecting previously unselected package mariadb-server.
Preparing to unpack .../5-mariadb-server_1%3a10.11.4-1~deb12u1_armel.deb ...
/var/lib/mysql: found previous version 10.5
Unpacking mariadb-server (1:10.11.4-1~deb12u1) ...
Setting up mariadb-client-core (1:10.11.4-1~deb12u1) ...
Setting up libnuma1:armel (2.0.16-1) ...
Setting up liburing2:armel (2.3-3) ...
Setting up mariadb-client (1:10.11.4-1~deb12u1) ...
Setting up mariadb-server-core (1:10.11.4-1~deb12u1) ...
Setting up mariadb-server (1:10.11.4-1~deb12u1) ...
Installing new version of config file /etc/init.d/mariadb ...
Installing new version of config file /etc/logrotate.d/mariadb ...
Installing new version of config file /etc/mysql/debian-start ...
Installing new version of config file /etc/mysql/mariadb.conf.d/50-server.cnf ...
Stopping MariaDB database server: mariadbd.
Starting MariaDB database server: mariadbd . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . failed!
invoke-rc.d: initscript mariadb, action "start" failed.
dpkg: error processing package mariadb-server (--configure):
  installed mariadb-server package post-installation script subprocess returned error exit status 1
dpkg: dependency problems prevent configuration of mariadb-server-10.5:
  mariadb-server-10.5 depends on mariadb-server (>= 1:10.11); however:
   Package mariadb-server is not configured yet.

dpkg: error processing package mariadb-server-10.5 (--configure):
  dependency problems - leaving unconfigured
Processing triggers for libc-bin (2.36-9+deb12u3) ...
Errors were encountered while processing:
  mariadb-server
  mariadb-server-10.5
E: Sub-process /usr/bin/dpkg returned an error code (1)

Here is what was logged to syslog:

mariadb-server.postinst[3596]: mysql.user table already exists!
mariadb-server.postinst[3596]: Run mysql_upgrade, not mysql_install_db
mysqld_safe: Starting mariadbd daemon with databases from /var/lib/mysql
mysqld: 2023-12-20 10:23:51 0 [Note] Starting MariaDB 10.11.4-MariaDB-1~deb12u1 source revision  as process 3765
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Number of transaction pools: 1
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Using generic crc32 instructions
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Using liburing
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Completed initialization of buffer pool
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: File system buffers for log disabled (block size=4096 bytes)
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Upgrading redo log: 96.000MiB; LSN=45767
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: File system buffers for log disabled (block size=4096 bytes)
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: 128 rollback segments are active.
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
mysqld: 2023-12-20 10:23:52 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
mysqld: 2023-12-20 10:23:53 0 [Note] InnoDB: log sequence number 45767; transaction id 20
mysqld: 2023-12-20 10:23:53 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysqld: 2023-12-20 10:23:53 0 [Note] Plugin 'FEEDBACK' is disabled.
mysqld: 2023-12-20 10:23:53 0 [ERROR] InnoDB: File ./ibdata1: 'aio read' returned OS error 0. Cannot continue operation
mysqld: 231220 10:23:53 [ERROR] mysqld got signal 6 ;
mysqld: This could be because you hit a bug. It is also possible that this binary
mysqld: or one of the libraries it was linked against is corrupt, improperly built,
mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
mysqld: 
mysqld: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
mysqld: 
mysqld: We will try our best to scrape up some info that will hopefully help
mysqld: diagnose the problem, but since we have already crashed, 
mysqld: something is definitely wrong and this may fail.
mysqld: 
mysqld: Server version: 10.11.4-MariaDB-1~deb12u1 source revision: 
mysqld: key_buffer_size=134217728
mysqld: read_buffer_size=131072
mysqld: max_used_connections=0
mysqld: max_threads=153
mysqld: thread_count=1
mysqld: It is possible that mysqld could use up to 
mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 466625 K  bytes of memory
mysqld: Hope that's ok; if not, decrease some variables in the equation.
mysqld: 
mysqld: Thread pointer: 0x0
mysqld: Attempting backtrace. You can use the following information to find out
mysqld: where mysqld died. If you see no messages after this, something went
mysqld: terribly wrong...
mysqld: stack_bottom = 0x0 thread_stack 0x49000
mysqld: The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
mysqld: information that should help you find out what is causing the crash.
mysqld: Writing a core file...
mysqld: Working directory at /var/lib/mysql
mysqld: Resource Limits:
mysqld: Limit                     Soft Limit           Hard Limit           Units     
mysqld: Max cpu time              unlimited            unlimited            seconds   
mysqld: Max file size             unlimited            unlimited            bytes     
mysqld: Max data size             unlimited            unlimited            bytes     
mysqld: Max stack size            8388608              unlimited            bytes     
mysqld: Max core file size        0                    unlimited            bytes     
mysqld: Max resident set          unlimited            unlimited            bytes     
mysqld: Max processes             1904                 1904                 processes 
mysqld: Max open files            32183                32183                files     
mysqld: Max locked memory         8388608              8388608              bytes     
mysqld: Max address space         unlimited            unlimited            bytes     
mysqld: Max file locks            unlimited            unlimited            locks     
mysqld: Max pending signals       1904                 1904                 signals   
mysqld: Max msgqueue size         819200               819200               bytes     
mysqld: Max nice priority         0                    0                    
mysqld: Max realtime priority     0                    0                    
mysqld: Max realtime timeout      unlimited            unlimited            us        
mysqld: Core pattern: core
mysqld: 
mysqld: Kernel version: Linux version 6.1.0-16-marvell (debian-kernel at lists.debian.org) (gcc-12 (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #1 Debian 6.1.67-1 (2023-12-12)
mysqld: 
mysqld_safe: mysqld from pid file /run/mysqld/mysqld.pid ended
/etc/init.d/mariadb[4054]: 0 processes alive and '/usr/bin/mariadb-admin --defaults-file=/etc/mysql/debian.cnf ping' resulted in
/etc/init.d/mariadb[4054]: #007/usr/bin/mariadb-admin: connect to server at 'localhost' failed
/etc/init.d/mariadb[4054]: error: 'Can't connect to local server through socket '/run/mysqld/mysqld.sock' (2)'
/etc/init.d/mariadb[4054]: Check that mariadbd is running and that the socket: '/run/mysqld/mysqld.sock' exists!

After the upgrade, a "diff" on the two mysql folders shows:

Only in mysql/: ddl_recovery.log
Only in mysql/: debian-10.11.flag
Only in mysql-10.5/: debian-10.5.flag
Binary files mysql-10.5/ib_logfile0 and mysql/ib_logfile0 differ
Only in mysql/: ibtmp1

No other files changed.

I then added these two lines in the [server] section of 
/etc/mysql/mariadb.conf.d/50-server.cnf:

innodb = OFF
default-storage-engine = MyISAM

Then I ran:

apt install -f

After this, mariadbd started successfully, but without the InnoDB engine, as 
can be seen in syslog:

mysqld_safe: Starting mariadbd daemon with databases from /var/lib/mysql
mysqld: 2023-12-20 11:01:31 0 [Note] Starting MariaDB 10.11.4-MariaDB-1~deb12u1 source revision  as process 5560
mysqld: 2023-12-20 11:01:32 0 [Note] Plugin 'InnoDB' is disabled.
mysqld: 2023-12-20 11:01:32 0 [Note] Plugin 'FEEDBACK' is disabled.
mysqld: 2023-12-20 11:01:32 0 [Warning] You need to use --log-bin to make --expire-logs-days or --binlog-expire-logs-seconds work.
mysqld: 2023-12-20 11:01:32 0 [Note] Server socket created on IP: '127.0.0.1'.
mysqld: 2023-12-20 11:01:32 0 [Note] /usr/sbin/mariadbd: ready for connections.
mysqld: Version: '10.11.4-MariaDB-1~deb12u1'  socket: '/run/mysqld/mysqld.sock'  port: 3306  Debian 12
/etc/mysql/debian-start[5589]: Upgrading MySQL tables if necessary.
/etc/mysql/debian-start[5599]: Checking for insecure root accounts.
/etc/mysql/debian-start[5603]: Triggering myisam-recover for all MyISAM tables and aria-recover for all Aria tables

On Tue, Dec 19, 2023 at 08:07:16AM -0700, Scott Barker wrote:
>For myself, I am not using XEN/KVM/Docker. I am installing this on a 
>NAS device with an ARM chip and only 512M of RAM. I tried adding a 2G 
>swap file, but it did not make a difference. I was able to start 
>mariadb by disabling INNODB and using MyISAM instead with the options:
>
>--innodb=OFF --default-storage-engine=MyISAM
>
>On Mon, Dec 18, 2023 at 09:23:55AM +0200, Tuukka Pasanen wrote:
>>Hello,
>>
>>Have you monitored that is memory exhausted at the installation? 
>>This could lead error like that.
>>
>>I assume your XEN/KVM/Docker base machine is some older system with 
>>not so fancy CPU or is there any particular reason to use armel 
>>build?
>>
>>Sincerly,
>>
>>Tuukka
>>
>>Scott Barker kirjoitti 17.12.2023 klo 19.15:
>>>Same result with the latest kernel:
>>>
>>>Linux nas-1 6.1.0-16-marvell #1 Debian 6.1.67-1 (2023-12-12) 
>>>armv5tel GNU/Linux
>>>
>>>On Sun, Dec 17, 2023 at 09:59:23AM -0700, Scott Barker wrote:
>>>>Prior to the installation, /var/lib/mysql did not exist. After 
>>>>installation:
>>>>
>>>>61559     4 drwxr-xr-x 2 mysql  mysql      4096 Dec 17 09:56 
>>>>/var/lib/mysql
>>>>61975     4 -rw-rw---- 1 mysql  mysql        52 Dec 17 09:56 
>>>>/var/lib/mysql/aria_log_control
>>>>61983 12304 -rw-rw---- 1 mysql  mysql  12582912 Dec 17 09:56 
>>>>/var/lib/mysql/ibdata1
>>>>61963     0 -rw-r--r-- 1 root   root          0 Dec 17 09:56 
>>>>/var/lib/mysql/debian-10.11.flag
>>>>61990 98404 -rw-rw---- 1 mysql  mysql 100663296 Dec 17 09:56 
>>>>/var/lib/mysql/ib_logfile101
>>>>61982    16 -rw-rw---- 1 mysql  mysql     16384 Dec 17 09:56 
>>>>/var/lib/mysql/aria_log.00000001
>>>>
>>>>uname -a reports:
>>>>
>>>>Linux nas-1 5.10.0-26-marvell #1 Debian 5.10.197-1 (2023-09-29) 
>>>>armv5tel GNU/Linux
>>>>
>>>>On Sun, Dec 17, 2023 at 11:48:16PM +0800, Otto Kekäläinen wrote:
>>>>>Hi Scott and Kr!
>>>>>
>>>>>Did you note this line?
>>>>>
>>>>>2023-12-14 14:51:33 0 [Note] InnoDB: Header page consists of 
>>>>>zero bytes in
>>>>>datafile: ./ibdata1, Space ID:0, Flags: 0
>>>>>
>>>>>Can you include the output of  `find /var/lib/mysql -ls` so we 
>>>>>can see what
>>>>>files your system has?
>>>>>
>>>>>What is the hardware you have? The report shows 'Linux 
>>>>>5.10.0-26-marvell '.
>>>>>What does `uname -a` yield?
>>>>>
>>>>>The test suite passes on armhf at 
>>>>>e.g. https://launchpad.net/~mysql-ubuntu/
>>>>>+archive/ubuntu/mariadb-10.11/+builds?build_text=&build_state=all. 
>>>>>At https://
>>>>>ci.debian.net/packages/m/mariadb/unstable/armel/ it fails due 
>>>>>to regression in
>>>>>subselect which is unrelated to what you reported.
>>>>>
>>>>
>>>>-- 
>>>>Scott Barker
>>>>
>>>>-- 
>>>>To unsubscribe, send mail to 1058706-unsubscribe at bugs.debian.org.
>>>
>
>-- 
>Scott Barker
>
>-- 
>To unsubscribe, send mail to 1058706-unsubscribe at bugs.debian.org.

-- 
Scott Barker



More information about the pkg-mysql-maint mailing list