Bug 1640910 - MariaDB fails to start after upgrade to F29
Summary: MariaDB fails to start after upgrade to F29
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: mariadb
Version: 29
Hardware: x86_64
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Michal Schorm
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-10-19 07:11 UTC by Juan Orti
Modified: 2018-10-19 09:33 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-10-19 09:33:36 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Juan Orti 2018-10-19 07:11:25 UTC
Description of problem:
After upgrading to F29, Mariadb fails to start.


Version-Release number of selected component (if applicable):
mariadb-server-10.3.10-1.fc29.x86_64
mariadb-10.3.10-1.fc29.x86_64


oct 18 22:20:31 lithium systemd[1]: Starting MariaDB 10.3 database server...
oct 18 22:20:34 lithium mysql-prepare-db-dir[875]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
oct 18 22:20:34 lithium mysql-prepare-db-dir[875]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
oct 18 22:20:35 lithium mysqld[962]: 2018-10-18 22:20:35 0 [Note] /usr/libexec/mysqld (mysqld 10.3.9-MariaDB) starting as process 962 ...
oct 18 22:20:35 lithium mysqld[962]: 2018-10-18 22:20:35 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4182)
oct 18 22:20:35 lithium mysqld[962]: 2018-10-18 22:20:35 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
oct 18 22:20:43 lithium systemd[1]: mariadb.service: Main process exited, code=exited, status=7/NOTRUNNING
oct 18 22:20:43 lithium systemd[1]: mariadb.service: Failed with result 'exit-code'.
oct 18 22:20:43 lithium systemd[1]: Failed to start MariaDB 10.3 database server.
oct 18 22:20:46 lithium systemd[1]: Starting MariaDB 10.3 database server...
oct 18 22:20:47 lithium mysql-prepare-db-dir[1249]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
oct 18 22:20:47 lithium mysql-prepare-db-dir[1249]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
oct 18 22:20:48 lithium mysqld[1300]: 2018-10-18 22:20:48 0 [Note] /usr/libexec/mysqld (mysqld 10.3.9-MariaDB) starting as process 1300 ...
oct 18 22:20:48 lithium mysqld[1300]: 2018-10-18 22:20:48 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4182)
oct 18 22:20:48 lithium mysqld[1300]: 2018-10-18 22:20:48 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
oct 18 22:20:53 lithium systemd[1]: mariadb.service: Main process exited, code=exited, status=7/NOTRUNNING
oct 18 22:20:53 lithium systemd[1]: mariadb.service: Failed with result 'exit-code'.
oct 18 22:20:53 lithium systemd[1]: Failed to start MariaDB 10.3 database server.

Comment 1 Michal Schorm 2018-10-19 08:08:28 UTC
Hello,

can you please specify how did you upgraded?

1) from which Fedora release
2) from which MariaDB release

3) upgrade steps taken

Comment 2 Juan Orti 2018-10-19 08:14:19 UTC
I upgrade from a fully updated F28 Server edition to F29 using dnf system-upgrade like explained here:

https://fedoraproject.org/wiki/DNF_system_upgrade

In F28 I had the version: mariadb-server-10.2.18-1.fc28.x86_64

Comment 3 Michal Schorm 2018-10-19 08:17:39 UTC
Thanks, I'll try to reproduce.

--

Anything interesting in the error log?

  /var/log/mariadb/mariadb.log

Comment 4 Juan Orti 2018-10-19 08:26:00 UTC
There are some errors in that log file. My only customization to the server is in the file /etc/my.cnf.d/local.cnf:

[mysqld]
innodb_file_per_table
innodb_file_format=Barracuda
character-set-server=utf8
collation-server=utf8_general_ci


---

2018-10-19 10:19:47 0 [Note] RocksDB: 2 column families found
2018-10-19 10:19:47 0 [Note] RocksDB: Column Families at start:
2018-10-19 10:19:47 0 [Note]   cf=default
2018-10-19 10:19:47 0 [Note]     write_buffer_size=67108864
2018-10-19 10:19:47 0 [Note]     target_file_size_base=67108864
2018-10-19 10:19:47 0 [Note]   cf=__system__
2018-10-19 10:19:47 0 [Note]     write_buffer_size=67108864
2018-10-19 10:19:47 0 [Note]     target_file_size_base=67108864
2018-10-19 10:19:47 0 [ERROR] RocksDB: Error opening instance, Status Code: 5, Status: IO error: While lock file: ./#rocksdb/LOCK: Resource temporarily unavailable
2018-10-19 10:19:47 0 [ERROR] Plugin 'ROCKSDB' init function returned error.
2018-10-19 10:19:47 0 [ERROR] Plugin 'ROCKSDB' registration as a STORAGE ENGINE failed.
Couldn't start tokuft because some other tokuft process is using the same directory [/var/lib/mysql/] for [environment]
2018-10-19 10:19:47 0 [ERROR] TokuDB unknown error 11
2018-10-19 10:19:47 0 [ERROR] Plugin 'TokuDB' init function returned error.
2018-10-19 10:19:47 0 [ERROR] Plugin 'TokuDB' registration as a STORAGE ENGINE failed.
2018-10-19 10:19:47 0 [Note] InnoDB: Using Linux native AIO
2018-10-19 10:19:47 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-10-19 10:19:47 0 [Note] InnoDB: Uses event mutexes
2018-10-19 10:19:47 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2018-10-19 10:19:47 0 [Note] InnoDB: Number of pools: 1
2018-10-19 10:19:47 0 [Note] InnoDB: Using SSE2 crc32 instructions
2018-10-19 10:19:47 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2018-10-19 10:19:47 0 [Note] InnoDB: Completed initialization of buffer pool
2018-10-19 10:19:47 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2018-10-19 10:19:48 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2018-10-19 10:19:48 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2018-10-19 10:19:48 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2018-10-19 10:19:48 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2018-10-19 10:19:48 0 [Note] InnoDB: Waiting for purge to start
2018-10-19 10:19:48 0 [Note] InnoDB: 10.3.10 started; log sequence number 6941028224; transaction id 11453264
2018-10-19 10:19:48 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2018-10-19 10:19:48 0 [Note] Plugin 'FEEDBACK' is disabled.
2018-10-19 10:19:48 0 [Warning] mysqld: GSSAPI plugin : default principal 'mariadb/lithium.lan@' not found in keytab
2018-10-19 10:19:48 0 [ERROR] mysqld: Server GSSAPI error (major 851968, minor 2529639093) : gss_acquire_cred failed -Unspecified GSS failure.  Minor code may provide more information. Keytab FILE:/etc/krb5.keytab is nonexistent or empty. 
2018-10-19 10:19:48 0 [ERROR] Plugin 'gssapi' init function returned error.
2018-10-19 10:19:48 0 [ERROR] /usr/libexec/mysqld: unknown variable 'innodb_file_format=Barracuda'
2018-10-19 10:19:48 0 [ERROR] Aborting

Comment 5 Juan Orti 2018-10-19 08:29:32 UTC
Removing my configuration file makes the service start again.

Comment 6 Juan Orti 2018-10-19 08:37:29 UTC
The culprit was the option:

innodb_file_format=Barracuda

Comment 7 Michal Schorm 2018-10-19 09:33:36 UTC
Yes,

Option Removed: MariaDB 10.3.1

https://mariadb.com/kb/en/library/xtradbinnodb-server-system-variables/#innodb_file_format


Note You need to log in before you can comment on or make changes to this bug.