MySQL init process in progress... MySQL init process failed.

[27Bslash6]

I have no idea how to debug this problem installing mysql:latest on CoreOS Alpha - 723.0.0, using either the simplest docker run command as supplied in the docs, or more realistic environment variables.

$ docker version
Client version: 1.7.0
Client API version: 1.19
Go version (client): go1.4.2
Git commit (client): 0baf609-dirty
OS/Arch (client): linux/amd64
Server version: 1.7.0
Server API version: 1.19
Go version (server): go1.4.2
Git commit (server): 0baf609-dirty
OS/Arch (server): linux/amd64

$ docker run --name some-mysql -e MYSQL_ROOT_PASSWORD=my-secret-pw -d mysql
2f4e7656c7427f812ea0cc78c410e387a12636f6d476418a911517bcb72ba9bc

$ docker logs some-mysql
Running mysql_install_db
2015-06-26 03:19:46 0 [Note] /usr/sbin/mysqld (mysqld 5.6.25) starting as process 28 ...
2015-06-26 03:19:46 28 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-06-26 03:19:46 28 [Note] InnoDB: The InnoDB memory heap is disabled
2015-06-26 03:19:46 28 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-06-26 03:19:46 28 [Note] InnoDB: Memory barrier is not used
2015-06-26 03:19:46 28 [Note] InnoDB: Compressed tables use zlib 1.2.7
2015-06-26 03:19:46 28 [Note] InnoDB: Using Linux native AIO
2015-06-26 03:19:46 28 [Note] InnoDB: Using CPU crc32 instructions
2015-06-26 03:19:46 28 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2015-06-26 03:19:46 28 [Note] InnoDB: Completed initialization of buffer pool
2015-06-26 03:19:46 28 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
2015-06-26 03:19:46 28 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB
2015-06-26 03:19:46 28 [Note] InnoDB: Database physically writes the file full: wait...
2015-06-26 03:19:46 28 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
2015-06-26 03:19:46 28 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
2015-06-26 03:19:46 28 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2015-06-26 03:19:46 28 [Warning] InnoDB: New log files created, LSN=45781
2015-06-26 03:19:46 28 [Note] InnoDB: Doublewrite buffer not found: creating new
2015-06-26 03:19:46 28 [Note] InnoDB: Doublewrite buffer created
2015-06-26 03:19:46 28 [Note] InnoDB: 128 rollback segment(s) are active.
2015-06-26 03:19:46 28 [Warning] InnoDB: Creating foreign key constraint system tables.
2015-06-26 03:19:46 28 [Note] InnoDB: Foreign key constraint system tables created
2015-06-26 03:19:46 28 [Note] InnoDB: Creating tablespace and datafile system tables.
2015-06-26 03:19:46 28 [Note] InnoDB: Tablespace and datafile system tables created.
2015-06-26 03:19:46 28 [Note] InnoDB: Waiting for purge to start
2015-06-26 03:19:46 28 [Note] InnoDB: 5.6.25 started; log sequence number 0
2015-06-26 03:19:47 28 [Note] Binlog end
2015-06-26 03:19:47 28 [Note] InnoDB: FTS optimize thread exiting.
2015-06-26 03:19:47 28 [Note] InnoDB: Starting shutdown...
2015-06-26 03:19:48 28 [Note] InnoDB: Shutdown completed; log sequence number 1625977


2015-06-26 03:19:48 0 [Note] /usr/sbin/mysqld (mysqld 5.6.25) starting as process 51 ...
2015-06-26 03:19:48 51 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-06-26 03:19:48 51 [Note] InnoDB: The InnoDB memory heap is disabled
2015-06-26 03:19:48 51 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-06-26 03:19:48 51 [Note] InnoDB: Memory barrier is not used
2015-06-26 03:19:48 51 [Note] InnoDB: Compressed tables use zlib 1.2.7
2015-06-26 03:19:48 51 [Note] InnoDB: Using Linux native AIO
2015-06-26 03:19:48 51 [Note] InnoDB: Using CPU crc32 instructions
2015-06-26 03:19:48 51 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2015-06-26 03:19:48 51 [Note] InnoDB: Completed initialization of buffer pool
2015-06-26 03:19:48 51 [Note] InnoDB: Highest supported file format is Barracuda.
2015-06-26 03:19:48 51 [Note] InnoDB: 128 rollback segment(s) are active.
2015-06-26 03:19:48 51 [Note] InnoDB: Waiting for purge to start
2015-06-26 03:19:48 51 [Note] InnoDB: 5.6.25 started; log sequence number 1625977
2015-06-26 03:19:49 51 [Note] Binlog end
2015-06-26 03:19:49 51 [Note] InnoDB: FTS optimize thread exiting.
2015-06-26 03:19:49 51 [Note] InnoDB: Starting shutdown...
2015-06-26 03:19:50 51 [Note] InnoDB: Shutdown completed; log sequence number 1625987




PLEASE REMEMBER TO SET A PASSWORD FOR THE MySQL root USER !
To do so, start the server, then issue the following commands:

  /usr/bin/mysqladmin -u root password 'new-password'
  /usr/bin/mysqladmin -u root -h 2f4e7656c742 password 'new-password'

Alternatively you can run:

  /usr/bin/mysql_secure_installation

which will also give you the option of removing the test
databases and anonymous user created by default.  This is
strongly recommended for production servers.

See the manual for more instructions.

Please report any problems at http://bugs.mysql.com/

The latest information about MySQL is available on the web at

  http://www.mysql.com

Support MySQL by buying support/licenses at http://shop.mysql.com

Note: new default config file not created.
Please make sure your config file is current

WARNING: Default config file /etc/mysql/my.cnf exists on the system
This file will be read by default by the MySQL server
If you do not want to use this, either remove it, or use the
--defaults-file argument to mysqld_safe when starting the server

Finished mysql_install_db
MySQL init process in progress...
MySQL init process in progress...
/entrypoint.sh: line 39:    74 Killed                  mysqld --user=mysql --datadir="$DATADIR" --skip-networking
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process failed.

[tianon]

This one's really strange -- how much RAM does the system you're running into this on have?

[27Bslash6]

I get the same result on a 16GB bare metal and 512MB droplet.

[ioggstream]

2015-07-07 1:00 GMT+02:00 Ray Walker notifications@github.com:

I get the same result on a 16GB bare metal and 256GB droplet.

Try to run from the command line.
Check via ulimits.
Attach via strace -f from the docker host.

[clinyong]

I think your RAM is too small, resize to 1GB

[27Bslash6]

You were correct, my apologies. The cause of the failure to init was docker-compose.yml memory limits.

[raabbajam]

Hi, I kind of having a same issue. Do you mind to tell me how to change docker-compost.yml memory limits? Or maybe some documentation how to do this?
Thanks 🍵

[thaJeztah]

@raabbajam see https://docs.docker.com/compose/compose-file/#cpu-shares-cpu-quota-cpuset-domainname-hostname-ipc-mac-address-mem-limit-memswap-limit-privileged-read-only-restart-stdin-open-tty-user-working-dir, but if you didn't set memory limits yourself, chances are there's just not enough RAM on the machine you're using

[27Bslash6]

The standard docker argument mem_limit is usable in your docker-compose.yml file see: https://docs.docker.com/compose/compose-file/#cpu-shares-cpu-quota-cpuset-domainname-hostname-ipc-mac-address-mem-limit-memswap-limit-privileged-read-only-restart-stdin-open-tty-user-working-dir

But if your system has less than 1GB of RAM the default MySQL docker image will fail to init regardless of mem_limit.

You can change the MySQL's memory limits by mounting .cnf configuration files in /etc/mysql/conf.d/ to override the defaults, as per instructions at https://hub.docker.com/_/mysql/ though I'm not sure exactly which configuration option is the culprit.

[turiphro]

This doesn't resolve the issue for me. There are no limits set in docker-compose.yml. There is 8GB available, and nothing else really is running (fresh boot doesn't change anything). Another setup using mysql initialised earlier is able to run, though. Docker-compose version 1.8.0-rc1.

Full output:

docker-compose up db
Creating volume "foo_mysql-data" with default driver
Creating foo_db_1
Attaching to foo_db_1
db_1   | Initializing database
db_1   | 2016-07-04T13:09:25.978647Z 0 [Warning] InnoDB: New log files created, LSN=45790
db_1   | 2016-07-04T13:09:26.163157Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
db_1   | 2016-07-04T13:09:26.256321Z 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: 88abe263-41e8-11e6-997b-0242ac140002.
db_1   | 2016-07-04T13:09:26.264167Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
db_1   | 2016-07-04T13:09:26.266225Z 1 [Warning] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
db_1   | 2016-07-04T13:09:28.929995Z 1 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:28.930024Z 1 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:28.930040Z 1 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:28.930053Z 1 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:28.930093Z 1 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
db_1   | Database initialized
db_1   | MySQL init process in progress...
db_1   | 2016-07-04T13:09:31.598953Z 0 [Note] mysqld (mysqld 5.7.12) starting as process 50 ...
db_1   | 2016-07-04T13:09:31.601423Z 0 [Note] InnoDB: PUNCH HOLE support available
db_1   | 2016-07-04T13:09:31.601440Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
db_1   | 2016-07-04T13:09:31.601444Z 0 [Note] InnoDB: Uses event mutexes
db_1   | 2016-07-04T13:09:31.601447Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
db_1   | 2016-07-04T13:09:31.601450Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
db_1   | 2016-07-04T13:09:31.601453Z 0 [Note] InnoDB: Using Linux native AIO
db_1   | 2016-07-04T13:09:31.601624Z 0 [Note] InnoDB: Number of pools: 1
db_1   | 2016-07-04T13:09:31.601717Z 0 [Note] InnoDB: Using CPU crc32 instructions
db_1   | 2016-07-04T13:09:31.607076Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
db_1   | 2016-07-04T13:09:31.612170Z 0 [Note] InnoDB: Completed initialization of buffer pool
db_1   | 2016-07-04T13:09:31.613400Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
db_1   | 2016-07-04T13:09:31.624783Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
db_1   | 2016-07-04T13:09:31.637688Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
db_1   | 2016-07-04T13:09:31.637914Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
db_1   | 2016-07-04T13:09:31.694617Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
db_1   | 2016-07-04T13:09:31.698637Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
db_1   | 2016-07-04T13:09:31.698691Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
db_1   | 2016-07-04T13:09:31.700461Z 0 [Note] InnoDB: Waiting for purge to start
db_1   | 2016-07-04T13:09:31.750742Z 0 [Note] InnoDB: 5.7.12 started; log sequence number 2522067
db_1   | 2016-07-04T13:09:31.751403Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
db_1   | 2016-07-04T13:09:31.751565Z 0 [Note] Plugin 'FEDERATED' is disabled.
db_1   | 2016-07-04T13:09:31.754709Z 0 [Note] InnoDB: Buffer pool(s) load completed at 160704 13:09:31
db_1   | 2016-07-04T13:09:31.754859Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
db_1   | 2016-07-04T13:09:31.766519Z 0 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:31.766618Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:31.766676Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:31.766718Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:31.770959Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
db_1   | 2016-07-04T13:09:31.790516Z 0 [Note] Event Scheduler: Loaded 0 events
db_1   | 2016-07-04T13:09:31.790963Z 0 [Note] mysqld: ready for connections.
db_1   | Version: '5.7.12'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server (GPL)
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process in progress...
db_1   | MySQL init process failed.
foo_db_1 exited with code 1

[turiphro]

Sorry, found it: turns out, the env_file included the MYSQL_HOST environment variable - as it was used by another container - but it should be empty.

services:

    web:
        build: ./src
        links:
            - db
        env_file:
            - ./vars.env

    db:
        image: mysql
        env_file:
            - ./vars.env
        environment:
            - MYSQL_HOST=   # override from env file to be empty

[laggingreflex]

Unsetting MYSQL_HOST solved it for me too. related

[activatedgeek]

I have built an image based on mariadb:10 which basically adds a new cluster.conf. But facing the following error on the second node after the first node started working successfully. Can somebody help me debug here?

Error log tail

2016-09-28 10:12:55 139799503415232 [ERROR] WSREP: failed to open gcomm backend connection: 110: failed to reach primary view: 110 (Connection timed out)
     at gcomm/src/pc.cpp:connect():162
2016-09-28 10:12:55 139799503415232 [ERROR] WSREP: gcs/src/gcs_core.cpp:gcs_core_open():208: Failed to open backend connection: -110 (Connection timed out)
2016-09-28 10:12:55 139799503415232 [ERROR] WSREP: gcs/src/gcs.cpp:gcs_open():1380: Failed to open channel 'test_cluster' at 'gcomm://172.17.0.2,172.17.0.3,172.17.0.4': -110 (Connection timed out)
2016-09-28 10:12:55 139799503415232 [ERROR] WSREP: gcs connect failed: Connection timed out
2016-09-28 10:12:55 139799503415232 [ERROR] WSREP: wsrep::connect(gcomm://172.17.0.2,172.17.0.3,172.17.0.4) failed: 7
2016-09-28 10:12:55 139799503415232 [ERROR] Aborting

MySQL init process failed.

Debugging steps

1. To ensure networking between containers is working, tried creating another container which could login to the first container's mysql instance.
2. This is definitely not related to MYSQL_HOST
3. To see if the container was running out of memory, I used docker stats and saw that the failed container was using only a meagre 142MB all through its lifecycle until it failed, which is way lesser than the total memory it was allowed (~4GB).
4. I am using Docker for Mac, but tried running the same on a CentOS VirtualBox and gives the same results. Doesn't look like Docker on Mac has a problem.

Config

[mysqld]
user=mysql
binlog_format=ROW
bind-address=0.0.0.0
default_storage_engine=innodb
innodb_autoinc_lock_mode=2
innodb_flush_log_at_trx_commit=0
innodb_buffer_pool_size=122M
innodb_file_per_table=1
innodb_doublewrite=1
query_cache_size=0
query_cache_type=0
wsrep_on=ON
wsrep_provider=/usr/lib/libgalera_smm.so
wsrep_sst_method=rsync

Steps to start containers

# bootstrap node
docker run --rm -e MYSQL_ROOT_PASSWORD=123 \ 
  activatedgeek/mariadb:devel \
    --wsrep-cluster-name=test_cluster \
    --wsrep-cluster-address=gcomm://172.17.0.2,172.17.0.3 \
    --wsrep-new-cluster

# add node into cluster
docker run --rm -e MYSQL_ROOT_PASSWORD=123 \ 
  activatedgeek/mariadb:devel \
    --wsrep-cluster-name=test_cluster \
    --wsrep-cluster-address=gcomm://172.17.0.2,172.17.0.3 \

[hanzhenbjm]

How to solve this problem？？？

[yhortuk]

Solved same issue by removing the following part from mysql config
[client]
user=
password=

maybe will be helpful for someone.

[wglambert]

@DevYK #448 (comment) seems related

". . . wonder if there are other [client] options that are going to bite us in the same way later."