[MDEV-13326] After several different attempts, MariaDB remains unwilling to start. Created: 2017-07-14  Updated: 2017-09-18  Resolved: 2017-09-18

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.2.7
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: C.J.S. Hayward Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: need_feedback
Environment:

Linux Mint 19.2 "Soja" "multitool"VM and appliance (Alfresco, Request Tracker, SuiteCRM, etc.) running under VirtualBox on a Macintosh host.


Attachments: File mysql.tgz    

 Description   

The question I posted on StackOverflow reads as below; my inability to start the MariaDB server (and have it be live a second later) appears to be a bug. I am attempting to quietly run the MariaDB server as a service.

My apologies for a spotchy paste; I don't know how to avoid BLOB labels etc.

For a particular project I wanted to have Mint (Sonja) appliance with all MariaDB and only MariaDB doing MySQL's work, without a hint of MySQL so I know I'm working with MariaDB.

The appliance is one where I've installed multiple open source projects that power their own website (Alfresco, Request Tracker, SuiteCRM, etc.), and all of them seem to have worked either with MariaDB, or just used Postgres without interesting difficulty, and up until I tried to create a new MariaDB database to add a clone of a specific Wordpress site, MariaDB worked predictably well with no headaches on the same system. Until now, where I can't seem to find a pulse.

The MariaDB troubleshooting page confirmed what I'd found in my investigations (in particular, a ps wwaux | grep mysql only turned up the grep process). The basic problem as I'd encountered it was when I tried to log in to create a database:

monk@toolchest ~ $ mysql -uroot -p
Enter password: 
ERROR 2002 (HY000): Can't connect to local MySQL server through socket 
'/var/run/mysqld/mysqld.sock' (2 "No such file or directory")

I've never gotten involved with MySQL's or MariaDB's /etc configuration files, but I looked briefly. They appeared sane to my uneducated eye.

Neither an aptitude reinstall mariadb-server nor a service mysql start produce any changes so far as I could tell.

For service mysql start, I got:

# service mysql start
Job for mysql.service failed because the control process exited with error code. See "systemctl status mysql.service" and "journalctl -xe" for details.
The details for systemctl status mysql.service were:
 
● mysql.service - LSB: Start and stop the mysql database server daemon
   Loaded: loaded (/etc/init.d/mysql; bad; vendor preset: enabled)
   Active: failed (Result: exit-code) since Fri 2017-07-14 18:16:38 EEST; 1min 11s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 5011 ExecStart=/etc/init.d/mysql start (code=exited, status=1/FAILURE)
 
Jul 14 18:16:38 toolchest /etc/init.d/mysql[5479]: 0 processes alive and '/usr/bin/mysql
Jul 14 18:16:38 toolchest /etc/init.d/mysql[5479]: [61B blob data]
Jul 14 18:16:38 toolchest /etc/init.d/mysql[5479]: error: 'Can't connect to local MySQL 
Jul 14 18:16:38 toolchest /etc/init.d/mysql[5479]: Check that mysqld is running and that
Jul 14 18:16:38 toolchest /etc/init.d/mysql[5479]: 
Jul 14 18:16:38 toolchest mysql[5011]:    ...fail!
Jul 14 18:16:38 toolchest systemd[1]: mysql.service: Control process exited, code=exited
Jul 14 18:16:38 toolchest systemd[1]: Failed to start LSB: Start and stop the mysql data
Jul 14 18:16:38 toolchest systemd[1]: mysql.service: Unit entered failed state.
Jul 14 18:16:38 toolchest systemd[1]: mysql.service: Failed with result 'exit-code'.

The recent (i.e. non-cronned) content of journalctl -xe ran:

-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit mysql.service has failed.
-- 
-- The result is failed.
Jul 14 18:16:38 toolchest systemd[1]: mysql.service: Unit entered failed state.
Jul 14 18:16:38 toolchest systemd[1]: mysql.service: Failed with result 'exit-code'.

/etc/mysql/mariadb.cnf and /etc/mysql/my.cnf both read (comments stripped):

[client-server]
!includedir /etc/mysql/conf.d/
!includedir /etc/mysql/mariadb.conf.d/

/etc/mysql/my.cnf.fallback dropps the latter !includedir. Commenting out the latter /etc/mysql/my.cnf to match the fallback file produced identical results.

I can edit my question to include more of /etc/mysql/*, but I wanted to ask. Error messages similar to the ERROR 2002 are to be found in questions like Can't connect to local MySQL server through socket '/var/mysql/mysql.sock' (38), but these appear to be MySQL rather than MariaDB, and I suspect this may be a MariaDB-specific fluke.



 Comments   
Comment by C.J.S. Hayward [ 2017-07-14 ]

One other comment:

I can, as an option, provide a complete copy of the appliance.

I don't think I'm doing anything interesting enough that the VM would matter, but I can provide it if requested.

Comment by C.J.S. Hayward [ 2017-07-14 ]

Thanks for tidying up the initial crude formatting, Elena!

Comment by Elena Stepanova [ 2017-07-14 ]

CJSHayward,

ERROR 2002 are to be found in questions like Can't connect to local MySQL server through socket '/var/mysql/mysql.sock' (38), but these appear to be MySQL rather than MariaDB, and I suspect this may be a MariaDB-specific fluke

This message is as non-specific as it gets, both in MySQL and MariaDB it simply means what it says, the client cannot connect to the server through a socket. Maybe the server is not running (which appears to be your case), maybe it's running but does not accept connections, maybe it's running with a different socket – all the same. So yes, we'll need more information.

Were you running journalctl under root/sudo? If not, please try it, it might show more.
If it doesn't show anything, please try to find the error log that the MariaDB server produces.

Please check if you have any config files inside /etc/mysql/conf.d/, and if so, paste/attach their contents as well.

Please run dpkg -l | grep -iE 'mysql|maria' and paste the output.

Comment by C.J.S. Hayward [ 2017-07-15 ]

Thank you.

Were you running journalctl under root/sudo? If not, please try it, it might show more.
If it doesn't show anything, please try to find the error log that the MariaDB server produces.

Yes, I was running those as root. As far as the MariaDB server's error log, I have three files: error.log, which is empty, error.log.1 which has some real content, and also error.log.6, which I believe was originally compressed. error.log.1 reads:

170714 18:40:42 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170714 18:40:42 [Note] InnoDB: The InnoDB memory heap is disabled
170714 18:40:42 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170714 18:40:42 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory ba
rrier
170714 18:40:42 [Note] InnoDB: Compressed tables use zlib 1.2.8
170714 18:40:42 [Note] InnoDB: Using Linux native AIO
170714 18:40:42 [Note] InnoDB: Using CPU crc32 instructions
170714 18:40:42 [Note] InnoDB: Initializing buffer pool, size = 128.0M
170714 18:40:42 [Note] InnoDB: Completed initialization of buffer pool
170714 18:40:42 [Note] InnoDB: Highest supported file format is Barracuda.
170714 18:40:42 [Note] InnoDB: Log scan progressed past the checkpoint lsn 106969363
170714 18:40:42 [Note] InnoDB: Database was not shutdown normally!
170714 18:40:42 [Note] InnoDB: Starting crash recovery.
170714 18:40:42 [Note] InnoDB: Reading tablespace information from the .ibd files...
170714 18:40:42 [Note] InnoDB: Restoring possible half-written data pages
170714 18:40:42 [Note] InnoDB: from the doublewrite buffer...
170714 18:40:42 [Warning] InnoDB: A page in the doublewrite buffer is not within space b
ounds; space id 824 page number 774, page 4 in doublewrite buf.
170714 18:40:42 [Warning] InnoDB: A page in the doublewrite buffer is not within space b
ounds; space id 824 page number 683, page 8 in doublewrite buf.
170714 18:40:42 [Warning] InnoDB: A page in the doublewrite buffer is not within space b
ounds; space id 824 page number 705, page 9 in doublewrite buf.
170714 18:40:42 [Warning] InnoDB: A page in the doublewrite buffer is not within space b
ounds; space id 824 page number 889, page 14 in doublewrite buf.
170714 18:40:42 [Warning] InnoDB: A page in the doublewrite buffer is not within space b
ounds; space id 824 page number 750, page 19 in doublewrite buf.
170714 18:40:42 [Warning] InnoDB: A page in the doublewrite buffer is not within space b
ounds; space id 824 page number 897, page 55 in doublewrite buf.
170714 18:40:42 [Warning] InnoDB: A page in the doublewrite buffer is not within space b
ounds; space id 824 page number 908, page 88 in doublewrite buf.
InnoDB: Doing recovery: scanned up to log sequence number 106985694
170714 18:40:43 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 2017-07-14 18:40:43 7f60f13fb700 InnoDB: Assertion failure
in thread 140054341072640 in file rem0rec.cc line 578
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
170714 18:40:43 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.

To report this bug, see https://mariadb.com/kb/en/reporting-bugs

We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

Server version: 10.0.29-MariaDB-0ubuntu0.16.04.1
key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=0
max_threads=153
thread_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 352324 K bytes of
memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x0 thread_stack 0x30000
3 4 5 6 7 8 9 10 11 12 13 14 15 Fatal signal 11 while backtracing
addr2line: 'mysqld': No such file

error.log.6 reads:

170703 20:33:49 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170703 20:33:49 [Note] InnoDB: The InnoDB memory heap is disabled
170703 20:33:49 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170703 20:33:49 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory ba
rrier
170703 20:33:49 [Note] InnoDB: Compressed tables use zlib 1.2.8
170703 20:33:49 [Note] InnoDB: Using Linux native AIO
170703 20:33:49 [Note] InnoDB: Using CPU crc32 instructions
170703 20:33:49 [Note] InnoDB: Initializing buffer pool, size = 128.0M
170703 20:33:49 [Note] InnoDB: Completed initialization of buffer pool
170703 20:33:49 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a
new database to be created!
170703 20:33:49 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB
170703 20:33:49 [Note] InnoDB: Database physically writes the file full: wait...
170703 20:33:49 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
170703 20:33:49 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
170703 20:33:49 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
170703 20:33:49 [Warning] InnoDB: New log files created, LSN=45781
170703 20:33:49 [Note] InnoDB: Doublewrite buffer not found: creating new
170703 20:33:49 [Note] InnoDB: Doublewrite buffer created
170703 20:33:49 [Note] InnoDB: 128 rollback segment(s) are active.
170703 20:33:49 [Warning] InnoDB: Creating foreign key constraint system tables.
170703 20:33:49 [Note] InnoDB: Foreign key constraint system tables created
170703 20:33:49 [Note] InnoDB: Creating tablespace and datafile system tables.
170703 20:33:49 [Note] InnoDB: Tablespace and datafile system tables created.
170703 20:33:49 [Note] InnoDB: Waiting for purge to start
170703 20:33:49 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.34-79.1 star
ted; log sequence number 0
170703 20:33:49 [Note] InnoDB: FTS optimize thread exiting.
170703 20:33:49 [Note] InnoDB: Starting shutdown...
170703 20:33:50 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer poo
l
170703 20:33:52 [Note] InnoDB: Shutdown completed; log sequence number 1616697
170703 20:33:52 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170703 20:33:52 [Note] InnoDB: The InnoDB memory heap is disabled
170703 20:33:52 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170703 20:33:52 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory ba
rrier
170703 20:33:52 [Note] InnoDB: Compressed tables use zlib 1.2.8
170703 20:33:52 [Note] InnoDB: Using Linux native AIO
170703 20:33:52 [Note] InnoDB: Using CPU crc32 instructions
170703 20:33:52 [Note] InnoDB: Initializing buffer pool, size = 128.0M
170703 20:33:52 [Note] InnoDB: Completed initialization of buffer pool
170703 20:33:52 [Note] InnoDB: Highest supported file format is Barracuda.
170703 20:33:52 [Note] InnoDB: 128 rollback segment(s) are active.
170703 20:33:52 [Note] InnoDB: Waiting for purge to start
170703 20:33:52 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.34-79.1 star
ted; log sequence number 1616697
170703 20:33:52 [Note] InnoDB: FTS optimize thread exiting.
170703 20:33:52 [Note] InnoDB: Starting shutdown...
170703 20:33:53 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer poo
l
170703 20:33:54 [Note] InnoDB: Shutdown completed; log sequence number 1616707
170703 20:33:54 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170703 20:33:54 [Note] InnoDB: The InnoDB memory heap is disabled
170703 20:33:54 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170703 20:33:54 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory ba
rrier
170703 20:33:54 [Note] InnoDB: Compressed tables use zlib 1.2.8
170703 20:33:54 [Note] InnoDB: Using Linux native AIO
170703 20:33:54 [Note] InnoDB: Using CPU crc32 instructions
170703 20:33:54 [Note] InnoDB: Initializing buffer pool, size = 128.0M
170703 20:33:54 [Note] InnoDB: Completed initialization of buffer pool
170703 20:33:54 [Note] InnoDB: Highest supported file format is Barracuda.
170703 20:33:54 [Note] InnoDB: 128 rollback segment(s) are active.
170703 20:33:54 [Note] InnoDB: Waiting for purge to start
170703 20:33:55 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.34-79.1 star
ted; log sequence number 1616707
170703 20:33:55 [Note] Plugin 'FEEDBACK' is disabled.
170703 20:33:55 [Note] InnoDB: FTS optimize thread exiting.
170703 20:33:55 [Note] InnoDB: Starting shutdown...
170703 20:33:56 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer poo
l
170703 20:33:57 [Note] InnoDB: Shutdown completed; log sequence number 1616717

I've attached a tarball of /etc/mysql.

Regarding the requested dpkg output, it is:

ii libdbd-mysql-perl 4.033-1ubuntu0.1 amd64 Perl5 database interface to the MySQL database
ii libmysqlclient20:amd64 5.7.18-0ubuntu0.16.04.1 amd64 MySQL database client library
ii mariadb-client 10.0.29-0ubuntu0.16.04.1 all MariaDB database client (metapackage depending on the latest version)
ii mariadb-client-10.0 10.0.29-0ubuntu0.16.04.1 amd64 MariaDB database client binaries
ii mariadb-client-core-10.0 10.0.29-0ubuntu0.16.04.1 amd64 MariaDB database core client binaries
ii mariadb-common 10.0.29-0ubuntu0.16.04.1 all MariaDB common metapackage
ii mariadb-server 10.0.29-0ubuntu0.16.04.1 all MariaDB database server (metapackage depending on the latest version)
ii mariadb-server-10.0 10.0.29-0ubuntu0.16.04.1 amd64 MariaDB database server binaries
ii mariadb-server-core-10.0 10.0.29-0ubuntu0.16.04.1 amd64 MariaDB database core server files
ii mysql-common 5.7.18-0ubuntu0.16.04.1 all MySQL database common files, e.g. /etc/mysql/my.cnf
ii php-mysql 1:7.0+35ubuntu6 all MySQL module for PHP [default]
ii php7.0-mysql 7.0.18-0ubuntu0.16.04.1 amd64 MySQL module for PHP

Thanks!

Comment by Elena Stepanova [ 2017-07-15 ]

CJSHayward,

Thanks for this.

So, error.log.6, of July 3rd, is from a bootstrap process of MariaDB 10.0.29, creating a new database. It seemed to have gone fine, I don't see anything bad in there.

error.log.1 is of July 14, which corresponds to the time when you were trying to start the server. There are three issues with it.

  • you are saying in the "affects version" that it's 10.2.7, but according to the log and the list of packages, it's still 10.0.29. So, if you think you are trying to run 10.2, it is not so;
  • the log shows that the server is attempting a crash recovery. It means that the server crashed (or was brutally killed) before, but we don't have logs for the time between July 3rd and July 14th, so we don't know what actually happened there;
  • the crash recovery fails. It is in itself a problem, but to investigate it, we'll need a coredump and probably either the datadir, or at least the idea of what was happening before the crash occurred.

Additionally, the package list also shows a potential problem. We don't have information of how mysql-common 5.7 and libmysqlclient20 live together with MariaDB 10.0.29, but generally it's much better not to mix packages from different distributions. However, since your MariaDB is installed from the Ubuntu repo (package names point at that), it's possible that it's their choice to mix up distributions this way, then there isn't much you can do about it.

So, first of all, if you just need the instance up and running, and you don't know/don't care about the contents of the database that was installed before, I suggest:

  • remove and purge all mariadb/mysql packages;
  • remove /var/lib/mysql, /var/log/mysql, /etc/mysql and /etc/my.cnf if they still exist;
  • install mariadb-server again.

IMPORTANT: It will remove all the data that the database contained before, configuration, privileges etc. Only do it if you really don't need it anymore. It will possibly also install a newer version of MariaDB, e.g. 10.0.31.

Since your failure happens upon crash recovery, when you get rid of the crashed (and possibly corrupt) database, the problem should go away.

If you cannot do it this way on whatever reason, or if it doesn't work, please let us know, I'll keep the item open till then.

Comment by C.J.S. Hayward [ 2017-07-17 ]

Thanks for your detailed help. I was probably wrong about "affects version."

Am I correct in guessing that php-mysql should itself be kept?

I'm wiping things to start over. My system does not (yet) have especially valuable database information; this is a correction before deployment for real use. I'll need to re-establish databases and do basic setup, but perhaps little beyond that.

I looked for a core dump, and didn't find any files named "core" that looked like core dumps instead of being some feature in some package that someone chose to name "core" (probably for some core functionality).

Thanks,

Comment by C.J.S. Hayward [ 2017-07-17 ]

After wiping, I got a request to include mysql-common:

# aptitude install libmariadb2 libmariadbd-dev libmariadbd18 mariadb-client-10.0 mariadb-client-core-10.0 mariadb-common mariadb-server-10.0 mariadb-server-core-10.0
The following NEW packages will be installed:
libaio1#a# libdbd-mysql-perl#a# libdbi-perl#a# libmariadb2
libmariadbd-dev libmariadbd18 libmysqlclient20#a# libterm-readkey-perl#a#
mariadb-client-10.0 mariadb-client-core-10.0 mariadb-common
mariadb-server-10.0 mariadb-server-core-10.0 mysql-common#a#

Is my list of packages OK? (If another list of packages would be better, what is it?)

What (if anything) should I do to the proposed inclusion of mysql-common (and libdbd-mysql-perl)? Let it install and then uninstall it? Something else?

Many thanks,

Comment by Elena Stepanova [ 2017-07-17 ]

Would it still insist on installing libmysqlclient20 if you specify installing libmysqlclient18? (Maybe it will, it's Debian packaging, it has its specifics; I suppose pulling mysql-common of 5.7 also comes from it).

If it insists on installing it, I don't think you'll be able to remove it later without breaking the installation, so let it be. Hopefully just the fact that you got rid of the old-ish broken datadir and installed it clean from scratch will fix the problem.

Comment by Elena Stepanova [ 2017-08-20 ]

CJSHayward, have you managed to fix the installation?

Comment by Sergei Golubchik [ 2017-09-18 ]

No feedback for a month — closing. The issue can be reopened, if new information will be added.

Generated at Thu Feb 08 08:04:43 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.