Cannot start MySQL Server 5.7.12 on FreeBSD 10.3

Code:
root@w:/var/db # pkg install mysql57-server mysql57-client
Updating FreeBSD repository catalogue...
FreeBSD repository is up-to-date.
All repositories are up-to-date.
Checking integrity... done (0 conflicting)
The following 6 package(s) will be affected (of 0 checked):

New packages to be INSTALLED:
        mysql57-server: 5.7.12
        mysql57-client: 5.7.12
        liblz4: 131
        libevent2: 2.0.22_1
        perl5: 5.20.3_12
        libedit: 3.1.20150325_2

The process will require 293 MiB more space.

Proceed with this action? [y/N]: y
[1/6] Installing liblz4-131...
[1/6] Extracting liblz4-131: 100%
[2/6] Installing libevent2-2.0.22_1...
[2/6] Extracting libevent2-2.0.22_1: 100%
[3/6] Installing perl5-5.20.3_12...
[3/6] Extracting perl5-5.20.3_12: 100%
[4/6] Installing libedit-3.1.20150325_2...
[4/6] Extracting libedit-3.1.20150325_2: 100%
[5/6] Installing mysql57-client-5.7.12...
[5/6] Extracting mysql57-client-5.7.12: 100%
[6/6] Installing mysql57-server-5.7.12...
===> Creating users and/or groups.
Using existing group 'mysql'.
Using existing user 'mysql'.
[6/6] Extracting mysql57-server-5.7.12: 100%
Message from perl5-5.20.3_12:
The /usr/bin/perl symlink has been removed starting with Perl 5.20.
For shebangs, you should either use:

#!/usr/local/bin/perl

or

#!/usr/bin/env perl

The first one will only work if you have a /usr/local/bin/perl,
the second will work as long as perl is in PATH.
Message from mysql57-client-5.7.12:
* * * * * * * * * * * * * * * * * * * * * * * *

This is the mysql CLIENT without the server.
for complete server and client, please install databases/mysql57-server

* * * * * * * * * * * * * * * * * * * * * * * *
Message from mysql57-server-5.7.12:
*****************************************************************************

Remember to run mysql_upgrade the first time you start the MySQL server
after an upgrade from an earlier version.

Initial password for first time use of MySQL is saved in $HOME/.mysql_secret
ie. when you want to use "mysql -u root -p" first you should see password
in /root/.mysql_secret

*****************************************************************************

*****************************************************************************

Please keep in mind that the default location for my.cnf will be changed
from "/var/db/mysql/my.cnf" to "/usr/local/etc/mysql/my.cnf" in the near
future.  If you do not want to move your my.cnf to the new location then
you must set "mysql_optfile" in /etc/rc.conf to "/var/db/mysql/my.cnf".

*****************************************************************************
root@w:/var/db # service mysql-server start
/usr/local/etc/rc.d/mysql-server: WARNING: failed precmd routine for mysql

Freshly created /var/db/mysql is empty. No detailed log gets generated.

When I run

Code:
root@w:/usr/home# /usr/local/bin/mysqld_safe
2016-05-16T03:54:08.6NZ mysqld_safe Logging to '/var/db/mysql/w.err'.
2016-05-16T03:54:08.6NZ mysqld_safe Starting mysqld daemon with databases from /var/db/mysql
2016-05-16T03:54:30.6NZ mysqld_safe mysqld from pid file /var/db/mysql/w.pid ended

/var/db/mysql gets populated with error log containing:

Code:
root@w:/usr/home# cat /var/db/mysql/w.err
2016-05-16T03:54:08.6NZ mysqld_safe Starting mysqld daemon with databases from /var/db/mysql
2016-05-16T03:54:08.544447Z 0 [Warning] Could not increase number of max_open_files to more than 28782 (request: 32929)
2016-05-16T03:54:08.546962Z 0 [Warning] Changed limits: table_open_cache: 14310 (requested 16384)
2016-05-16T03:54:08.877416Z 0 [Warning] 'NO_ZERO_DATE', 'NO_ZERO_IN_DATE' and 'ERROR_FOR_DIVISION_BY_ZERO' sql modes should be used with strict mode. They will be merged with strict mode in a future release.
2016-05-16T03:54:08.877476Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2016-05-16T03:54:08.879883Z 0 [Note] /usr/local/libexec/mysqld (mysqld 5.7.12-log) starting as process 5817 ...
2016-05-16T03:54:09.009616Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-05-16T03:54:09.009717Z 0 [Note] InnoDB: Uses event mutexes
2016-05-16T03:54:09.009740Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2016-05-16T03:54:09.009760Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2016-05-16T03:54:09.010701Z 0 [Note] InnoDB: Number of pools: 1
2016-05-16T03:54:09.011155Z 0 [Note] InnoDB: Not using CPU crc32 instructions
2016-05-16T03:54:09.099785Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2016-05-16T03:54:09.137209Z 0 [Note] InnoDB: Completed initialization of buffer pool
2016-05-16T03:54:09.155602Z 0 [Note] InnoDB: The first innodb_system data file 'ibdata1' did not exist. A new tablespace will be created!
2016-05-16T03:54:09.155939Z 0 [Note] InnoDB: Setting file '/var/db/mysql/ibdata1' size to 128 MB. Physically writing the file full; Please wait ...
2016-05-16T03:54:09.157965Z 0 [Note] InnoDB: Progress in MB:
 100
2016-05-16T03:54:11.334877Z 0 [Note] InnoDB: File '/var/db/mysql/ibdata1' size is now 128 MB.
2016-05-16T03:54:11.336349Z 0 [Note] InnoDB: Setting log file /var/db/mysql/ib_logfile101 size to 256 MB
2016-05-16T03:54:11.337459Z 0 [Note] InnoDB: Progress in MB:
 100 200
2016-05-16T03:54:18.938775Z 0 [Note] InnoDB: Setting log file /var/db/mysql/ib_logfile1 size to 256 MB
2016-05-16T03:54:18.940833Z 0 [Note] InnoDB: Progress in MB:
 100 200
2016-05-16T03:54:23.966828Z 0 [Note] InnoDB: Renaming log file /var/db/mysql/ib_logfile101 to /var/db/mysql/ib_logfile0
2016-05-16T03:54:23.967235Z 0 [Warning] InnoDB: New log files created, LSN=45790
2016-05-16T03:54:23.967333Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2016-05-16T03:54:23.967563Z 0 [Note] InnoDB: Setting file '/var/db/mysql/ibtmp1' size to 128 MB. Physically writing the file full; Please wait ...
2016-05-16T03:54:23.967885Z 0 [Note] InnoDB: Progress in MB:
 100
2016-05-16T03:54:26.098879Z 0 [Note] InnoDB: File '/var/db/mysql/ibtmp1' size is now 128 MB.
2016-05-16T03:54:26.099216Z 0 [Note] InnoDB: Doublewrite buffer not found: creating new
2016-05-16T03:54:26.431555Z 0 [Note] InnoDB: Doublewrite buffer created
2016-05-16T03:54:26.448924Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2016-05-16T03:54:26.448975Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2016-05-16T03:54:26.456331Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
2016-05-16T03:54:26.498113Z 0 [Note] InnoDB: Foreign key constraint system tables created
2016-05-16T03:54:26.498261Z 0 [Note] InnoDB: Creating tablespace and datafile system tables.
2016-05-16T03:54:26.500368Z 0 [Note] InnoDB: Tablespace and datafile system tables created.
2016-05-16T03:54:26.500416Z 0 [Note] InnoDB: Creating sys_virtual system tables.
2016-05-16T03:54:26.502198Z 0 [Note] InnoDB: sys_virtual table created
2016-05-16T03:54:26.502471Z 0 [Note] InnoDB: Waiting for purge to start
2016-05-16T03:54:26.556412Z 0 [Note] InnoDB: 5.7.12 started; log sequence number 0
2016-05-16T03:54:26.557067Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 17410ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2016-05-16T03:54:26.573311Z 0 [Note] Plugin 'FEDERATED' is disabled.
mysqld: Table 'mysql.plugin' doesn't exist
2016-05-16T03:54:26.590491Z 0 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
mysqld: Error on delete of './auto.cnf' (Errcode: 2 - No such file or directory)
2016-05-16T03:54:26.654121Z 0 [Warning] World-writable config file './auto.cnf' has been removed.

2016-05-16T03:54:26.654286Z 0 [Note] Salting uuid generator variables, current_pid: 5817, server_start_time: 1463370848, bytes_sent: 0,
2016-05-16T03:54:26.657718Z 0 [Note] Generated uuid: 'e252a097-1b19-11e6-97db-06754000002e', server_start_time: 1637339940989262617, bytes_sent: 35009826816
2016-05-16T03:54:26.657779Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: e252a097-1b19-11e6-97db-06754000002e.
2016-05-16T03:54:26.663993Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
2016-05-16T03:54:27.860239Z 0 [Note] Auto generated SSL certificates are placed in data directory.
2016-05-16T03:54:27.869223Z 0 [Warning] CA certificate ca.pem is self signed.
2016-05-16T03:54:28.691388Z 0 [Note] Auto generated RSA key files are placed in data directory.
2016-05-16T03:54:28.693717Z 0 [Note] Server hostname (bind-address): '127.0.0.1'; port: 3306
2016-05-16T03:54:28.693842Z 0 [Note]   - '127.0.0.1' resolves to '127.0.0.1';
2016-05-16T03:54:28.695028Z 0 [Note] Server socket created on IP: '127.0.0.1'.
2016-05-16T03:54:28.702943Z 0 [Warning] Failed to open optimizer cost constant tables

2016-05-16T03:54:28.704660Z 0 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist
2016-05-16T03:54:28.705527Z 0 [ERROR] Aborting

2016-05-16T03:54:28.706304Z 0 [Note] Binlog end
2016-05-16T03:54:28.708768Z 0 [Note] Shutting down plugin 'ngram'
2016-05-16T03:54:28.708810Z 0 [Note] Shutting down plugin 'partition'
2016-05-16T03:54:28.708832Z 0 [Note] Shutting down plugin 'BLACKHOLE'
2016-05-16T03:54:28.708850Z 0 [Note] Shutting down plugin 'ARCHIVE'
2016-05-16T03:54:28.708866Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL'
2016-05-16T03:54:28.708882Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2016-05-16T03:54:28.708898Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2016-05-16T03:54:28.708913Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2016-05-16T03:54:28.708928Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2016-05-16T03:54:28.708943Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2016-05-16T03:54:28.708959Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2016-05-16T03:54:28.708975Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2016-05-16T03:54:28.708990Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2016-05-16T03:54:28.709005Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2016-05-16T03:54:28.709020Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2016-05-16T03:54:28.709035Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2016-05-16T03:54:28.709050Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2016-05-16T03:54:28.709066Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2016-05-16T03:54:28.709081Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2016-05-16T03:54:28.709096Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2016-05-16T03:54:28.709111Z 0 [Note] Shutting down plugin 'INNODB_METRICS'
2016-05-16T03:54:28.709126Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO'
2016-05-16T03:54:28.709141Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2016-05-16T03:54:28.709156Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2016-05-16T03:54:28.709171Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2016-05-16T03:54:28.709187Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2016-05-16T03:54:28.709215Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2016-05-16T03:54:28.709238Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2016-05-16T03:54:28.709255Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2016-05-16T03:54:28.709271Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2016-05-16T03:54:28.709299Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2016-05-16T03:54:28.709316Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2016-05-16T03:54:28.709331Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2016-05-16T03:54:28.709346Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2016-05-16T03:54:28.709362Z 0 [Note] Shutting down plugin 'InnoDB'
2016-05-16T03:54:28.710173Z 0 [Note] InnoDB: FTS optimize thread exiting.
2016-05-16T03:54:28.710419Z 0 [Note] InnoDB: Starting shutdown...
2016-05-16T03:54:28.817932Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/db/mysql/ib_buffer_pool
2016-05-16T03:54:28.818265Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 160516  5:54:28
2016-05-16T03:54:30.077783Z 0 [Note] InnoDB: Shutdown completed; log sequence number 1209970
2016-05-16T03:54:30.078115Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2016-05-16T03:54:30.078143Z 0 [Note] Shutting down plugin 'CSV'
2016-05-16T03:54:30.078170Z 0 [Note] Shutting down plugin 'MyISAM'
2016-05-16T03:54:30.086964Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2016-05-16T03:54:30.087053Z 0 [Note] Shutting down plugin 'MEMORY'
2016-05-16T03:54:30.087084Z 0 [Note] Shutting down plugin 'MRG_MYISAM'
2016-05-16T03:54:30.087110Z 0 [Note] Shutting down plugin 'sha256_password'
2016-05-16T03:54:30.087127Z 0 [Note] Shutting down plugin 'mysql_native_password'
2016-05-16T03:54:30.087338Z 0 [Note] Shutting down plugin 'binlog'
2016-05-16T03:54:30.094312Z 0 [Note] /usr/local/libexec/mysqld: Shutdown complete

2016-05-16T03:54:30.6NZ mysqld_safe mysqld from pid file /var/db/mysql/w.pid ended

How can I fix this?
 
Last edited by a moderator:
I have discovered by trial-and-error that the following modes(permissions) for the /usr/local/etc/mysql/my.cnf produce the following results regarding start or failure of the mysql server:

Code:
mode
777   starts
770   fail
774   fail
775   fail
776   starts
746   starts
646   starts
644   fail

Apparently the "world/other" users need write permission. . . .not good!
 
Thanks a lot Ron, this one was a real PITA to figure out - To actually get to find out what went wrong, I came across http://www.gamecreatures.com/blog/2016/02/22/freebsd-mysql-server-failed-precmd-routine/

I have a fresh installation of `mysql57-server-5.7.15` on FreeBSD 11 and changing the permissions to 646 was necessary to run the server for the first time and initialize everything. I still have to keep these permissions to be able to restart though. :/

I hope that helps others in case they think the issue was fixed. =) I also dropped a note in Bugzilla.
 
Back
Top