MySQL Bugs: #88490: Cannot start a container from zero

Bug #88490	Cannot start a container from zero
Submitted:	14 Nov 2017 22:48	Modified:	17 Jan 2019 8:02
Reporter:	Tran Minh-Quan	Email Updates:
Status:	Won't fix	Impact on me:	None
Category:	MySQL Package Repos	Severity:	S2 (Serious)
Version:	5.7.20-1.1.2	OS:	Windows
Assigned to:	Lars Tangvald	CPU Architecture:	Any

Description:
I use the image in docker-compose, datadir is bind to an empty folder. there is nothing in /var/log/mysqld.log, the only logs are:

mysql_1  | [Entrypoint] MySQL Docker Image 5.7.20-1.1.2
mysql_1  | [Entrypoint] Initializing database
mysql_1  | [Entrypoint] Database initialized
mysql_1  | Initialization of mysqld failed: 0

Configuration:
  mysql:
    image: mysql/mysql-server:5.7
    volumes:
      - ./.docker/mysql:/var/lib/mysql
    environment:
      MYSQL_ROOT_HOST: "%"
      MYSQL_ROOT_PASSWORD: root
      MYSQL_DATABASE: db
      MYSQL_USER: user
      MYSQL_PASSWORD: user

Thank you.

How to repeat:
Create a docker-compose.yml with:

  mysql:
    image: mysql:5.7
    image: mysql/mysql-server:5.7
    volumes:
      - ./.docker/mysql:/var/lib/mysql
    environment:
      MYSQL_ROOT_HOST: "%"
      MYSQL_ROOT_PASSWORD: root
      MYSQL_DATABASE: db
      MYSQL_USER: user
      MYSQL_PASSWORD: user

Windows 17025.1000
Docker  17.09.0-ce

Hi,

This might be a windows-specific issue, but can you try adding MYSQL_LOG_CONSOLE: true to your environment list and see if you get more information?

--
Lars

On Windows:

mysql_1    | [Entrypoint] MySQL Docker Image 5.7.20-1.1.2
mysql_1    | [Entrypoint] Initializing database
mysql_1    | 2017-11-15T08:42:33.003166Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
mysql_1    | 2017-11-15T08:42:33.994228Z 0 [Warning] InnoDB: New log files created, LSN=45790
php_1      | [14-Nov-2017 23:48:05] NOTICE: fpm is running, pid 1
php_1      | [14-Nov-2017 23:48:05] NOTICE: ready to handle connections
adminer_1  | PHP 7.0.25 Development Server started at Tue Nov 14 22:48:05 2017
mysql_1    | 2017-11-15T08:42:34.147010Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
mysql_1    | 2017-11-15T08:42:34.226305Z 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: ece33f8e-c9e0-11e7-a7d5-0242ac160004.
mysql_1    | 2017-11-15T08:42:34.238256Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
mysql_1    | 2017-11-15T08:42:34.582039Z 0 [Warning] CA certificate ca.pem is self signed.
mysql_1    | 2017-11-15T08:42:34.691308Z 1 [Warning] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
mysql_1    | 2017-11-15T08:42:38.869324Z 1 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
mysql_1    | 2017-11-15T08:42:38.869383Z 1 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
mysql_1    | 2017-11-15T08:42:38.869398Z 1 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
mysql_1    | 2017-11-15T08:42:38.869418Z 1 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
mysql_1    | 2017-11-15T08:42:38.869528Z 1 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
mysql_1    | 2017-11-15T08:42:38.869547Z 1 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
mysql_1    | 2017-11-15T08:42:38.869764Z 1 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
mysql_1    | 2017-11-15T08:42:38.869871Z 1 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
mysql_1    | [Entrypoint] Database initialized
mysql_1    | 2017-11-15T08:42:42.560872Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
mysql_1    | 2017-11-15T08:42:42.566234Z 0 [Note] mysqld (mysqld 5.7.20) starting as process 52 ...
mysql_1    | 2017-11-15T08:42:42.577144Z 0 [Note] InnoDB: PUNCH HOLE support available
mysql_1    | 2017-11-15T08:42:42.577194Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
mysql_1    | 2017-11-15T08:42:42.577199Z 0 [Note] InnoDB: Uses event mutexes
mysql_1    | 2017-11-15T08:42:42.577203Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
mysql_1    | 2017-11-15T08:42:42.577207Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
mysql_1    | 2017-11-15T08:42:42.577212Z 0 [Note] InnoDB: Using Linux native AIO
mysql_1    | 2017-11-15T08:42:42.577577Z 0 [Note] InnoDB: Number of pools: 1
mysql_1    | 2017-11-15T08:42:42.577822Z 0 [Note] InnoDB: Using CPU crc32 instructions
mysql_1    | 2017-11-15T08:42:42.579447Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
mysql_1    | 2017-11-15T08:42:42.585806Z 0 [Note] InnoDB: Completed initialization of buffer pool
mysql_1    | 2017-11-15T08:42:42.587465Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
mysql_1    | 2017-11-15T08:42:42.624433Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
mysql_1    | 2017-11-15T08:42:42.697321Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
mysql_1    | 2017-11-15T08:42:42.698626Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mysql_1    | 2017-11-15T08:42:42.789751Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mysql_1    | 2017-11-15T08:42:42.800514Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
mysql_1    | 2017-11-15T08:42:42.800572Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
mysql_1    | 2017-11-15T08:42:42.801043Z 0 [Note] InnoDB: Waiting for purge to start
mysql_1    | 2017-11-15T08:42:42.851859Z 0 [Note] InnoDB: 5.7.20 started; log sequence number 2565857
mysql_1    | 2017-11-15T08:42:42.852366Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysql_1    | 2017-11-15T08:42:42.852460Z 0 [Note] Plugin 'FEDERATED' is disabled.
mysql_1    | 2017-11-15T08:42:42.906595Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
mysql_1    | 2017-11-15T08:42:42.906642Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
mysql_1    | 2017-11-15T08:42:42.912365Z 0 [Note] InnoDB: Buffer pool(s) load completed at 171115  8:42:42
mysql_1    | 2017-11-15T08:42:42.915070Z 0 [Warning] CA certificate ca.pem is self signed.
mysql_1    | 2017-11-15T08:42:42.915441Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
mysql_1    | 2017-11-15T08:42:42.925234Z 0 [ERROR] Can't start server : Bind on unix socket: Operation not permitted
mysql_1    | 2017-11-15T08:42:42.925273Z 0 [ERROR] Do you already have another mysqld server running on socket: /var/lib/mysql/mysql.sock ?
mysql_1    | 2017-11-15T08:42:42.925289Z 0 [ERROR] Aborting
mysql_1    |
mysql_1    | Initialization of mysqld failed: 0
ssu_mysql_1 exited with code 1

on Linux Ubuntu 17.10

Attachment: dockerlinux.txt (text/plain), 20.38 KiB.

On Linux Ubuntu 17.10, the same config works. Please see attachment.

You don't have any other servers running on ./.docker/mysql? What's in that directory when you try starting up?

the directory ./.docker/mysql does not exist when I start the container. the container is the only one that uses that directory.

Attachment: log.txt (text/plain), 9.93 KiB.

I haven't looked in the entrypoint.sh yet, but I think there is Something not right with the second start of MySQL after the database is initialized, it seems, in this test case, it tries to start earlier than the shutdown completes

Bug reproduced on windows.

The problem occurs when the socket option is set to be in the datadir (which is the default) you map to the windows filesystem. Probably something to do with how the filesystem sharing works with Docker for Windows.

As a workaround, can you try adding:
 command: mysqld --socket=/tmp/mysqld.sock
to your yml file?

mysql_1    | 2017-11-17T12:56:49.261203Z 0 [Note] Event Scheduler: Loaded 0 events
mysql_1    | 2017-11-17T12:56:49.262526Z 0 [Note] mysqld: ready for connections.
It works when change to a file which is not exposed to Windows. In Windows the binded volumes are less reactive than in Linux environment.

mysql_1    | Version: '5.7.20'  socket: '/tmp/mysql.sock'  port: 3306  MySQL Community Server (GPL)
mysql_1    | 2017-11-17T12:56:49.262582Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
mysql_1    | 2017-11-17T12:56:49.262608Z 0 [Note] Beginning of list of non-natively partitioned tables
mysql_1    | 2017-11-17T12:56:51.938758Z 0 [Note] End of list of non-natively partitioned tables

It works when change to a file which is not exposed to Windows. In Windows the binded volumes are less reactive than in Linux environment.

Changing the default setting to move the file out of datadir would fix this on Windows, but possibly break existing use cases for other users.

This is an issue with other unix containers on Windows as well, and there doesn't seem to be a general fix, so for now we may have to just document the workaround for Windows.

For my curiosity, why the choice to put sock file into datadir? the _/mysql uses /var/run/mysqld which seems to me a more common way.

Is it possible to have an ENV variable to change the default path  of  sock file instead of modifying the command?

There are a few differences between the default file layout for RHEL (OracleLinux, which mysql/mysql-server is based on) and Debian (which _/mysql is based on) platforms, such as the location of the socket file and my.cnf. It's mostly just historic reasons.

We may want to make a change to make them more similar, to make it easier for users to switch from one to the other, but changes that can cause issues for users upgrading will generally only be made to non-GA releases (8.0).

Posted by developer:
 
Added a new section to the MySQL 5.7 manual (https://dev.mysql.com/doc/refman/5.7/en/deploy-mysql-nonlinux-docker.html), which warns about using Oracle's MySQL containers on non-Linux platforms and documents this limitation.

Closing this as it's a consequence of how Docker works on Windows with the server's default socket location (but as mentioned, the workaround has been documented)