Mysql docker container aborts with fatal errro #741

jameswadsworth · 2020-11-06T19:45:31Z

devilbox_env_compose_override.zip

ISSUE TYPE

Bug Report

Checklist

.env file is attached
docker-compose.override.yml is attached (if it exists)
Custom configs from cfg/ dir are attached (if customized)
docker-compose logs and log/ output is added
I've looked through the docs: https://devilbox.readthedocs.io/en/latest/
I've looked through existing issues: https://github.com/cytopia/devilbox/issues
I've read troubleshooting: https://devilbox.readthedocs.io/en/latest/support/troubleshooting.html
devilbox_env_compose_override.zip

OS / ENVIRONMENT

Host operating system and version:
Fedora release 31
(Windows) Native Docker or Docker Toolbox:
Docker version:
Docker version 19.03.13, build 4484c46d9d
Docker Compose version:
docker-compose version 1.25.4, build unknown
(Linux) Is SELinux enabled?:
Disabled
What git commit hash are you on?:
4b23dd6

SUMMARY

The Mysql / mariadb container aborts with fatal error

STEPS TO REPRODUCE

After pulling the latest version of version devilbox with git pull origin master I launch with $ docker-compose up and it gives the following error:
mysql_1 | 2020-11-06 17:43:22+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
mysql_1 | 2020-11-06 17:43:22+00:00 [ERROR] [Entrypoint]: mysqld failed while attempting to check config
mysql_1 | command was: mysqld --verbose --help --log-bin-index=/tmp/tmp.gthcf15EW7
mysql_1 | mysqld: Can't read dir of '/etc/mysql/docker-default.d/' (Errcode: 13 "Permission denied")
mysql_1 | Fatal error in defaults handling. Program aborted

I leave the containers running and enter the php shell with ./shell.sh. I run cd /etc/mysql/docker-default.d/ and it gives bash: cd: /etc/mysql/docker-default.d/: No such file or directory.

Inspection of the folder /etc/mysql shows that there isn't any folder called docker-default.d. Running $ ls in the folder shows:
drwxr-xr-x 2 root root 4096 Oct 24 04:07 conf.d/
drwxr-xr-x 1 root root 4096 Oct 24 04:08 mariadb.conf.d/
-rw-r--r-- 1 root root 869 Oct 12 17:46 mariadb.cnf
lrwxrwxrwx 1 root root 24 Oct 24 04:07 my.cnf -> /etc/alternatives/my.cnf
-rw-r--r-- 1 root root 839 Aug 3 2016 my.cnf.fallback

It is impossible to access the devilbox

EXPECTED BEHAVIOUR

the mysql container launches correctly
The devilbox web interface is accessible.

ACTUAL BEHAVIOUR

the mysql container fails with error message as above
The devilbox web interface is inaccessible.

OTHER INFORMATION

I stop the containers with ctrl+C, then remove the containers with $ docker-compose rm -f. I change line 341 in the docker-compose.yml file from

${DEVILBOX_PATH}/cfg/${MYSQL_SERVER}:/etc/mysql/docker-default.d:ro${MOUNT_OPTIONS}
in
${DEVILBOX_PATH}/cfg/${MYSQL_SERVER}:/etc/mysql/mariadb.conf.d:ro${MOUNT_OPTIONS}

and I run $ docker-compose up. Checking the logs

mysql_1 | 2020-11-06 18:14:13+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+mariafocal started.
mysql_1 | mysqld: Can't read dir of '/etc/mysql/mariadb.conf.d/' (Errcode: 13 "Permission denied")
mysql_1 | 2020-11-06 18:14:13 0 [Note] mysqld (mysqld 10.3.26-MariaDB-1:10.3.26+mariafocal) starting as process 1 ...
mysql_1 | 2020-11-06 18:14:14 0 [Note] InnoDB: Using Linux native AIO
mysql_1 | 2020-11-06 18:14:14 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
mysql_1 | 2020-11-06 18:14:14 0 [Note] InnoDB: Uses event mutexes
mysql_1 | 2020-11-06 18:14:14 0 [Note] InnoDB: Compressed tables use zlib 1.2.11

Now the devilbox web interface is accessible.

The text was updated successfully, but these errors were encountered:

cytopia · 2020-11-06T20:46:52Z

I leave the containers running and enter the php shell with ./shell.sh. I run cd /etc/mysql/docker-default.d/ and it gives bash: cd: /etc/mysql/docker-default.d/: No such file or directory.

With the ./shell.sh script, you're entering the PHP container (Not the mysql container). In the PHP container, there is no such /etc/mysql/docker-default.d/ directory. So this part is all good.

Telling by your .env file, you're using MariaDB 10.13. So Let's start to do this manually:

# 1. Create temporary directory
mkdir dvl-cfg

# 2. Create dummy MariaDB config directive
printf "[mysqld]\ngeneral_log_file=dvl.log\n" > dvl-cfg/test.cnf

# 3. Start MariaDB
docker run -it --rm --name dvltest \
  -v $(pwd)/dvl-cfg:/etc/mysql/docker-default.d/ \
  -e MYSQL_ALLOW_EMPTY_PASSWORD=1 devilbox/mysql:mariadb-10.3

This yields the following success output:

2020-11-06 20:38:42+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
2020-11-06 20:38:42+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
2020-11-06 20:38:42+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
2020-11-06 20:38:42+00:00 [Note] [Entrypoint]: Initializing database files
...

Now in a second terminal window (while the above MariaDB container is still running), I am executing some commands in it (via its given name dvltest):

# Find mounted configuration
docker exec -it dvltest ls -lap /etc/mysql/docker-default.d/
total 12
drwxr-xr-x 2 1000 1000 4096 Nov  6 20:38 ./
drwxr-xr-x 1 root root 4096 Nov  6 01:37 ../
-rw-r--r-- 1 1000 1000   34 Nov  6 20:38 test.cnf

# Read out adjusted setting:
docker exec -it dvltest mysql -uroot --password='' -e "SHOW VARIABLES LIKE 'general_log_file';"
+------------------+---------+
| Variable_name    | Value   |
+------------------+---------+
| general_log_file | dvl.log |
+------------------+---------+

So everything seems to be working fine. Also to note, that this whole process is part of the CI (running nightly) for all flavours/versions of MySQL/MariaDB/Percona.

Can you try to follow the steps and see if that errors somehow on your machine.

With that being said, I am currently unable to re-produce your behaviour. I'm happy to get to the root though and add a few more integration tests, once it's discovered, where this issue is coming from.

jameswadsworth · 2020-11-08T20:06:41Z

I've run the first three commands as suggested. This yields

Unable to find image 'devilbox/mysql:mariadb-10.3' locally
mariadb-10.3: Pulling from devilbox/mysql
6a5697faee43: Already exists
ba13d3bc422b: Already exists
a254829d9e55: Already exists
2ee2cadd29fc: Already exists
6915a184049d: Already exists
5ca6ffdb5f56: Already exists
1537f7bbef8b: Already exists
5790e54322d1: Already exists
ea98cb829471: Already exists
d91f40693863: Already exists
13f0c0d55992: Already exists
6bfbacb89af2: Already exists
c1aebda0a191: Already exists
adb8be44b548: Pull complete
Digest: sha256:f636128ed4cc8406b66b094f74ccf0d5f020e21c3bd1f9dd4f0b818939afea5c
Status: Downloaded newer image for devilbox/mysql:mariadb-10.3
2020-11-08 19:39:44+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+mariafocal started.
2020-11-08 19:39:44+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
2020-11-08 19:39:44+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+mariafocal started.
2020-11-08 19:39:44+00:00 [Note] [Entrypoint]: Initializing database files

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

For the commands in the second window it gives:

docker exec -it dvltest ls -lap /etc/mysql/docker-default.d/
total 12
drwxrwxr-x 2 1000 1000 4096 Nov 8 19:38 ./
drwxr-xr-x 1 root root 4096 Nov 8 12:41 ../
-rw-rw-r-- 1 1000 1000 34 Nov 8 19:38 test.cnf

cytopia · 2020-11-09T09:05:27Z

Your output suggests that everything works as it should. Do you have any other custom configs set which might affect MariaDB 10.3 with the Devilbox?

Besides, there is now a new Devlibox release out: v1.8.0 Can you give this a try.

jameswadsworth · 2020-11-10T09:19:48Z

I've updated to version 1.8.0 and removed the devilbox-custom.cnf file for verison mariadb 10.3

$ git rev-parse HEAD
87fa92d931eb7dd1bc5d73f3aaeb504a47b00fcd

$ docker-compose up mysql
.....
d872f06ccdfa: Pull complete
Digest: sha256:3751d6538458e4ee0898144f2bbfc3bc0a62cd7ad5b3665ce74c0f003227b0b5
Status: Downloaded newer image for devilbox/php-fpm:7.3-work-0.114
Pulling mysql (devilbox/mysql:mariadb-10.3-0.6)...
mariadb-10.3-0.6: Pulling from devilbox/mysql
6a5697faee43: Already exists
ba13d3bc422b: Already exists
a254829d9e55: Already exists
2ee2cadd29fc: Already exists
6915a184049d: Already exists
5ca6ffdb5f56: Already exists
1537f7bbef8b: Already exists
5790e54322d1: Already exists
ea98cb829471: Already exists
d91f40693863: Already exists
13f0c0d55992: Already exists
6bfbacb89af2: Already exists
c1aebda0a191: Already exists
f0c1dcc12a03: Pull complete
Digest: sha256:777e2c2d1fa38d83ea984c8b25e71efcc12674e45a86e0cd727845a4823caac6
Status: Downloaded newer image for devilbox/mysql:mariadb-10.3-0.6
Creating devilbox_bind_1 ... done
Creating devilbox_php_1  ... done
Creating devilbox_httpd_1 ... done
Creating devilbox_mysql_1 ... done
Attaching to devilbox_mysql_1
mysql_1    | 2020-11-10 08:55:10+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
mysql_1    | 2020-11-10 08:55:11+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
mysql_1    | 2020-11-10 08:55:11+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
mysql_1    | 2020-11-10 08:55:11+00:00 [ERROR] [Entrypoint]: mysqld failed while attempting to check config
mysql_1    | 	command was: mysqld --verbose --help --log-bin-index=/tmp/tmp.qb7c9NvZpv
mysql_1    | 	mysqld: Can't read dir of '/etc/mysql/docker-default.d/' (Errcode: 13 "Permission denied")
mysql_1    | Fatal error in defaults handling. Program aborted
devilbox_mysql_1 exited with code 1

jameswadsworth · 2020-11-10T09:44:16Z

If in my docker-compose.yml file I change the line

      - ${DEVILBOX_PATH}/cfg/${MYSQL_SERVER}:/etc/mysql/docker-default.d:ro${MOUNT_OPTIONS}

to

      - ${DEVILBOX_PATH}/cfg/${MYSQL_SERVER}:/etc/mysql/test:ro${MOUNT_OPTIONS}

then run

$ docker-compose up mysql
Creating devilbox_bind_1 ... done
Creating devilbox_php_1  ... done
Creating devilbox_httpd_1 ... done
Creating devilbox_mysql_1 ... done
Attaching to devilbox_mysql_1
mysql_1    | 2020-11-10 09:21:37+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
mysql_1    | 2020-11-10 09:21:37+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
mysql_1    | 2020-11-10 09:21:37+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
mysql_1    | 2020-11-10  9:21:37 0 [Note] mysqld (mysqld 10.3.26-MariaDB-1:10.3.26+maria~focal) starting as process 1 ...
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Using Linux native AIO
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Uses event mutexes
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Number of pools: 1
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Using SSE2 crc32 instructions
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
mysql_1    | 2020-11-10  9:21:37 0 [Note] InnoDB: Completed initialization of buffer pool
mysql_1    | 2020-11-10  9:21:37 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    | 2020-11-10  9:21:40 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
mysql_1    | 2020-11-10  9:21:40 0 [Note] InnoDB: Creating shared tablespace for temporary tables
mysql_1    | 2020-11-10  9:21:40 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mysql_1    | 2020-11-10  9:21:40 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mysql_1    | 2020-11-10  9:21:40 0 [Note] InnoDB: 10.3.26 started; log sequence number 4099240677; transaction id 1380625
mysql_1    | 2020-11-10  9:21:40 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysql_1    | 2020-11-10  9:21:40 0 [Note] Plugin 'FEEDBACK' is disabled.
mysql_1    | 2020-11-10  9:21:40 0 [Note] Server socket created on IP: '::'.
mysql_1    | 2020-11-10  9:21:40 0 [Warning] 'proxies_priv' entry '@% root@mysql' ignored in --skip-name-resolve mode.
mysql_1    | 2020-11-10  9:21:41 0 [Note] Reading of all Master_info entries succeeded
mysql_1    | 2020-11-10  9:21:41 0 [Note] Added new Master_info '' to hash table
mysql_1    | 2020-11-10  9:21:41 0 [Note] mysqld: ready for connections.
mysql_1    | Version: '10.3.26-MariaDB-1:10.3.26+maria~focal'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution

and I can access the devilbox web interface

cytopia · 2020-11-10T09:51:46Z

Can you do a:

ls -lap cfg/mariadb-10.3

Could be that the permission of the local config directory are wrong

jameswadsworth · 2020-11-10T09:54:11Z

$ ls -lap cfg/mariadb-10.3
total 16
drwxrwx---  2 james james 4096 Nov 10 09:44 ./
drwxrwx--- 61 james james 4096 Nov 10 08:43 ../
-rw-rw-r--  1 james james  178 May 20  2019 devilbox-custom.cnf
-rw-rw-r--  1 james james   50 Dec  2  2019 devilbox-custom.cnf-example
-rw-rw-r--  1 james james    0 Dec  2  2019 .keepme

cytopia · 2020-11-10T09:55:19Z

Can you change this to chmod 0755 cfg/mariadb-10.3

jameswadsworth · 2020-11-10T11:51:08Z

This resolves the issue. I can now start mysql correctly with the original docker-compose.yml file

$ docker-compose up mysql
Creating network "devilbox_app_net" with driver "bridge"
Creating devilbox_bind_1 ... done
Creating devilbox_php_1  ... done
Creating devilbox_httpd_1 ... done
Creating devilbox_mysql_1 ... done
Attaching to devilbox_mysql_1
mysql_1    | 2020-11-10 10:39:30+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
mysql_1    | 2020-11-10 10:39:30+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
mysql_1    | 2020-11-10 10:39:30+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 1:10.3.26+maria~focal started.
mysql_1    | 2020-11-10 10:39:30 0 [Note] mysqld (mysqld 10.3.26-MariaDB-1:10.3.26+maria~focal) starting as process 1 ...
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Using Linux native AIO
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Uses event mutexes
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Number of pools: 1
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Using SSE2 crc32 instructions
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
mysql_1    | 2020-11-10 10:39:30 0 [Note] InnoDB: Completed initialization of buffer pool
mysql_1    | 2020-11-10 10:39:30 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    | 2020-11-10 10:39:31 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=4099303627
mysql_1    | 2020-11-10 10:39:33 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
mysql_1    | 2020-11-10 10:39:33 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
mysql_1    | 2020-11-10 10:39:33 0 [Note] InnoDB: Creating shared tablespace for temporary tables
mysql_1    | 2020-11-10 10:39:33 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mysql_1    | 2020-11-10 10:39:33 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mysql_1    | 2020-11-10 10:39:33 0 [Note] InnoDB: 10.3.26 started; log sequence number 4099303636; transaction id 1380762
mysql_1    | 2020-11-10 10:39:33 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysql_1    | 2020-11-10 10:39:33 0 [Note] Plugin 'FEEDBACK' is disabled.
mysql_1    | 2020-11-10 10:39:33 0 [Note] Recovering after a crash using tc.log
mysql_1    | 2020-11-10 10:39:33 0 [Note] Starting crash recovery...
mysql_1    | 2020-11-10 10:39:33 0 [Note] Crash recovery finished.
mysql_1    | 2020-11-10 10:39:33 0 [Note] Server socket created on IP: '::'.
mysql_1    | 2020-11-10 10:39:33 0 [Warning] 'proxies_priv' entry '@% root@mysql' ignored in --skip-name-resolve mode.
mysql_1    | 2020-11-10 10:39:33 0 [Note] Reading of all Master_info entries succeeded
mysql_1    | 2020-11-10 10:39:33 0 [Note] Added new Master_info '' to hash table
mysql_1    | 2020-11-10 10:39:33 0 [Note] mysqld: ready for connections.
mysql_1    | Version: '10.3.26-MariaDB-1:10.3.26+maria~focal'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
mysql_1    | 2020-11-10 10:39:50 0 [Note] InnoDB: Buffer pool(s) load completed at 201110 10:39:50

Thanks for the help!

cytopia · 2020-11-12T15:34:58Z

Upcoming PR #747 includes a new script: check-config.sh which will easily find this issue

jameswadsworth added the bug label Nov 6, 2020

cytopia self-assigned this Nov 9, 2020

cytopia added the mysql label Nov 10, 2020

jameswadsworth closed this as completed Nov 10, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Mysql docker container aborts with fatal errro #741

Mysql docker container aborts with fatal errro #741

jameswadsworth commented Nov 6, 2020

cytopia commented Nov 6, 2020 •

edited

Loading

jameswadsworth commented Nov 8, 2020

cytopia commented Nov 9, 2020

jameswadsworth commented Nov 10, 2020

jameswadsworth commented Nov 10, 2020

cytopia commented Nov 10, 2020

jameswadsworth commented Nov 10, 2020

cytopia commented Nov 10, 2020

jameswadsworth commented Nov 10, 2020

cytopia commented Nov 12, 2020

Mysql docker container aborts with fatal errro #741

Mysql docker container aborts with fatal errro #741

Comments

jameswadsworth commented Nov 6, 2020

ISSUE TYPE

Checklist

OS / ENVIRONMENT

SUMMARY

STEPS TO REPRODUCE

EXPECTED BEHAVIOUR

ACTUAL BEHAVIOUR

OTHER INFORMATION

cytopia commented Nov 6, 2020 • edited Loading

jameswadsworth commented Nov 8, 2020

cytopia commented Nov 9, 2020

jameswadsworth commented Nov 10, 2020

jameswadsworth commented Nov 10, 2020

cytopia commented Nov 10, 2020

jameswadsworth commented Nov 10, 2020

cytopia commented Nov 10, 2020

jameswadsworth commented Nov 10, 2020

cytopia commented Nov 12, 2020

cytopia commented Nov 6, 2020 •

edited

Loading