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

Thu Dec 21 07:25:20 GMT 2023

Hello,
Memory is still 512 MB?
Thing that pops to my eye in 10.11 is
mysqld: 2023-12-20 10:23:53 0 [ERROR] InnoDB: File ./ibdata1: 'aio read' 
returned OS error 0. Cannot continue operation
As on 10.5 is used fsync not O_DIRECT which is default from 10.6 you can 
try (not promising anything) get it 10.11 working (more slowly though) with:
|innodb_flush_method=fsync|
|More on change here:
|
|https://mariadb.com/kb/en/innodb-system-variables/#innodb_use_native_aio
|
Sincerely,
Tuukka

Scott Barker kirjoitti 21.12.2023 klo 0.20:
> 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.
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://alioth-lists.debian.net/pipermail/pkg-mysql-maint/attachments/20231221/ba5233c6/attachment-0001.htm>