MySQL not Starting

[danemorgan]

ISSUE TYPE

• Bug Report

Checklist

• [ x ] .env file is attached
  csm.env.zip

• docker-compose.override.yml is attached (if it exists) N/A

• Custom configs from cfg/ dir are attached (if customized) N/A

• [ x ] docker-compose logs and log/ output is added
  docker-compose-logs.txt

• [ x ] I've looked through the docs: https://devilbox.readthedocs.io/en/latest/

• [x ] I've looked through existing issues: https://github.com/cytopia/devilbox/issues

OS / ENVIRONMENT

1. Host operating system and version: Windows 10
2. (Windows) Native Docker or Docker Toolbox: Native Docker
3. Docker version: 2.0.0.2 (30215)
4. Docker Compose version: 1.23.2
5. (Linux) Is SELinux enabled?: N/A
6. What git commit hash are you on?: master

SUMMARY

This afternoon docker-compose up failed to start my containers. This has happened in the past and I would pull the latest update from git, update my environment file, reboot my computer and everything would start working again after it pulled some new PHP or MySQL images.

Today, though, it seems like everything is coming up except MySQL. WordPress complains about not reaching the database, and the MySQL circle in the devilbox dashboard is grayed out.

Additionally the dashboard loads, prints three warnings, and then prints the second and third warnings in a loop until, a few minutes later it loads a 502 Gateway error.

Warning: fopen(/tmp/devilbox-intranet/error.log): failed to open stream: No such file or directory in /var/www/default/include/lib/Logger.php on line 197

Warning: feof() expects parameter 1 to be resource, boolean given in /var/www/default/include/lib/Logger.php on line 198

Warning: fgets() expects parameter 1 to be resource, boolean given in /var/www/default/include/lib/Logger.php on line 199

STEPS TO REPRODUCE

Run docker-compose up -d bind httpd php mysql and try to lad a website or open the Devilbox dashboard.

EXPECTED BEHAVIOUR

the docker containers start up and I start working on the websites in it.

ACTUAL BEHAVIOUR

it seems like everything is coming up except MySQL. WordPress complains about not reaching the database, and the MySQL circle in the devilbox dashboard is grayed out.

Additionally the dashboard loads, prints three warnings, and then prints the second and third warnings in a loop until, a few minutes later it loads a 502 Gateway error.

Warning: fopen(/tmp/devilbox-intranet/error.log): failed to open stream: No such file or directory in /var/www/default/include/lib/Logger.php on line 197

Warning: feof() expects parameter 1 to be resource, boolean given in /var/www/default/include/lib/Logger.php on line 198

Warning: fgets() expects parameter 1 to be resource, boolean given in /var/www/default/include/lib/Logger.php on line 199

### OTHER INFORMATION

#### Start command
<!-- Add the command you have used to start the devilbox -->

docker-compose up -d bind httpd php mysql

#### File and user permissions (Linux & MacOS)
<!-- User and group information -->
N/A

<!-- File permissions of the Devilbox directory -->

λ ls -la
total 318
drwxr-xr-x 1 DM 197609 0 Jan 30 21:20 ./
drwxr-xr-x 1 DM 197609 0 Jan 30 20:55 ../
drwxr-xr-x 1 DM 197609 0 Jun 28 2018 .devilbox/
-rw-r--r-- 1 DM 197609 2445 Jan 30 16:59 .editorconfig
-rw-r--r-- 1 DM 197609 18132 Jan 30 20:55 .env
drwxr-xr-x 1 DM 197609 0 Jan 30 16:59 .git/
drwxr-xr-x 1 DM 197609 0 Aug 19 01:50 .github/
-rw-r--r-- 1 DM 197609 3656 Jan 30 16:59 .gitignore
drwxr-xr-x 1 DM 197609 0 Jan 30 16:59 .tests/
-rw-r--r-- 1 DM 197609 9510 Jan 30 16:59 .travis.yml
-rw-r--r-- 1 DM 197609 894 Aug 19 01:50 CONTRIBUTING.md
-rw-r--r-- 1 DM 197609 1064 Jun 28 2018 LICENSE.md
-rw-r--r-- 1 DM 197609 55056 Jan 30 16:59 README.md
drwxr-xr-x 1 DM 197609 0 Jan 30 16:59 autostart/
drwxr-xr-x 1 DM 197609 0 Jul 18 2018 backups/
drwxr-xr-x 1 DM 197609 0 Jun 28 2018 bash/
drwxr-xr-x 1 DM 197609 0 Jul 20 2018 ca/
drwxr-xr-x 1 DM 197609 0 Jan 30 16:59 cfg/
drwxr-xr-x 1 DM 197609 0 Jan 30 16:59 compose/
drwxr-xr-x 1 DM 197609 0 Dec 13 10:24 data/
-rw-r--r-- 1 DM 197609 91181 Jan 30 21:19 docker-compose-logs.txt
-rw-r--r-- 1 DM 197609 743 Jun 28 2018 docker-compose.override.yml-example
-rw-r--r-- 1 DM 197609 12815 Jan 30 16:59 docker-compose.yml
drwxr-xr-x 1 DM 197609 0 Jan 30 16:59 docs/
-rw-r--r-- 1 DM 197609 18081 Jan 30 16:59 env-example
drwxr-xr-x 1 DM 197609 0 Jan 30 21:00 log/
drwxr-xr-x 1 DM 197609 0 Jan 22 03:42 mail/
drwxr-xr-x 1 DM 197609 0 Jun 28 2018 mod/
-rw-r--r-- 1 DM 197609 86 Jan 30 16:59 shell.bat
-rwxr-xr-x 1 DM 197609 59 Jun 28 2018 shell.sh*
-rwxr-xr-x 1 DM 197609 2375 Aug 19 01:50 update-docker.sh*

<!-- File permissions of your projects -->

λ ls -la ../projects/csm
total 49
drwxr-xr-x 1 DM 197609 0 Jan 30 21:12 ./
drwxr-xr-x 1 DM 197609 0 Aug 15 10:06 ../
drwxr-xr-x 1 DM 197609 0 Jan 23 09:55 .assets/
drwxr-xr-x 1 DM 197609 0 Aug 8 07:15 .documents/
drwxr-xr-x 1 DM 197609 0 Jul 7 2018 caninejournal/
drwxr-xr-x 1 DM 197609 0 Aug 9 00:37 csm-plugins/
-rw-r--r-- 1 DM 197609 18132 Jan 30 17:04 csm.env
-rw-r--r-- 1 DM 197609 5195 Jan 30 21:11 csm.env.zip
drwxr-xr-x 1 DM 197609 0 Jul 7 2018 earthsfriends/
drwxr-xr-x 1 DM 197609 0 Jul 7 2018 exploringlifesmysteries/
drwxr-xr-x 1 DM 197609 0 Jan 30 21:00 mongo/
drwxr-xr-x 1 DM 197609 0 Jul 22 2018 mysql/
drwxr-xr-x 1 DM 197609 0 Jul 7 2018 mywinston-salem/
drwxr-xr-x 1 DM 197609 0 Jan 30 21:00 pgsql/
drwxr-xr-x 1 DM 197609 0 Oct 28 15:14 safesmartliving/
drwxr-xr-x 1 DM 197609 0 Nov 29 16:20 test/
-rw-r--r-- 1 DM 197609 114 Jul 22 2018 up.sh
drwxr-xr-x 1 DM 197609 0 Dec 15 14:38 werockyourweb/

[cytopia]

@danemorgan I cannot see any errors in your docker-compose log output nor do I see that MySQL shuts down. It might be related to this issue: #473

Which is about Docker versoin 2.x. Can you downgrade to Docker version 1.x again and see if this resolved your problem?

[danemorgan]

What about option 3 from #473?

The only real issue here is that I would have to restore my databases, right? I have multiple redundancies for this and ultimately all of these databases are periodically written over from their production versions on live servers.

I'm reluctant to try reverting Docker for a couple of reasons. First, it has been a multiday process each time I've done it in the past, often involving resetting my machine, largely down to a number of crazy things involved in getting the system to share the drive. Second, because I went to Docker to see about getting a copy of the last 1.x and all I can find are forum posts saying that they do not make previous versions available for Windows users.

If you really need that done, I could try, but I would need to limp along with working from staging sites instead of my development sites to get some time sensitive work done and do that next week.

[cytopia]

Yes, option 3 is the preferred way and you will probably wanna stay on that branch until merge to master. I wasn't sure if you do have backups in place.

Let me know how this works out for you.

Be warned, that I regularly force-push to that branch due to rebase from master.

[danemorgan]

One quick question.

I usually do docker-compose down at the end of each day and sometimes a couple of times throughout the day as I move from one project to another ( I have different project folders for different clients ).

If the databases are in the docker volumes, will I need to restore them every time I run docker-compose up?

[danemorgan]

I am on the docker-volumes branch now and there is no change in the results.

I'm attaching a new docker-compose log.
docker-compose-logs.log

There is no /mysql in /var/lib

devilbox@php-7.0.33 in /shared/httpd $ ls /var/lib
apt/     dictionaries-common/  emacsen-common/  git/     misc/  php/      snmp/  systemd/  vim/
aspell/  dpkg/                 gems/            ispell/  pam/   postfix/  sudo/  ucf/

[danemorgan]

C:\Users\danea\devilbox (docker-volumes -> origin)
λ docker-compose down
Stopping devilbox_httpd_1 ... done
Stopping devilbox_php_1   ... done
Stopping devilbox_bind_1  ... done
Removing devilbox_mysql_1 ... done
Removing devilbox_httpd_1 ... done
Removing devilbox_php_1   ... done
Removing devilbox_bind_1  ... done
Removing network devilbox_app_net

C:\Users\danea\devilbox (docker-volumes -> origin)
λ docker-compose up -d bind httpd php 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

C:\Users\danea\devilbox (docker-volumes -> origin)
λ docker ps
CONTAINER ID        IMAGE                            COMMAND                  CREATED             STATUS              PORTS
  NAMES
5853348807a5        devilbox/nginx-stable:0.28       "/docker-entrypoint.…"   11 seconds ago      Up 10 seconds       0.0.0.0:80->80/tcp, 0.0.0.0:443->443/tcp
  devilbox_httpd_1
c99b9d13f017        devilbox/php-fpm:7.0-work-0.72   "/docker-entrypoint.…"   12 seconds ago      Up 11 seconds       9000/tcp
  devilbox_php_1
8252701ecbb1        cytopia/bind:0.15                "/docker-entrypoint.…"   13 seconds ago      Up 12 seconds       0.0.0.0:1053->53/tcp, 0.0.0.0:1053->53/udp
  devilbox_bind_1

[danemorgan]

docker-compose-logs.log

[danemorgan]

devilbox@php-7.0.33 in /shared/httpd $ ls -lah /var/lib/mysql/
ls: cannot access '/var/lib/mysql/': No such file or directory

devilbox@php-7.0.33 in /shared/httpd $ /usr/bin/mysql_install_db --defaults-file=~/.my.cnf
bash: /usr/bin/mysql_install_db: No such file or directory

devilbox@php-7.0.33 in /shared/httpd $ /usr/sbin/mysqld --skip-grant --general-log &
[1] 3386
devilbox@php-7.0.33 in /shared/httpd $ bash: /usr/sbin/mysqld: No such file or directory

[cytopia]

If the databases are in the docker volumes, will I need to restore them every time I run docker-compose up?

No, its the same behaviour as now. Data persists.

You should probably do a

docker-compose down
docker-compose rm -f
docker-compose up

and then import the data for the new branch.

[danemorgan]

import the data for the new branch.
??

[danemorgan]

I did

docker-compose down
docker-compose rm -f
docker-compose up
docker-compose pull

Now the Devilbox dashboard loads correctly, but the MySQL service is still not started.

The log shows

�[36mmysql_1  |�[0m �[0;34m[INFO] Setting docker timezone to: America/Chicago�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mrm /etc/localtime�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mln -s /usr/share/zoneinfo/America/Chicago /etc/localtime�[0m
�[36mmysql_1  |�[0m �[0;34m[INFO] Docker date set to: Thu Jan 31 17:01:48 CST 2019�[0m
�[36mmysql_1  |�[0m �[0;34m[INFO] Setting MySQL: [mysqld] general-log=0�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mtouch /etc/my.cnf.d/logging.cnf�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho '[mysqld]' >> /etc/my.cnf.d/logging.cnf�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho 'general-log = 0' >> /etc/my.cnf.d/logging.cnf�[0m
�[36mmysql_1  |�[0m �[0;34m[INFO] Setting MySQL: [client] socket=/tmp/mysql/mysqld.sock�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mtouch /etc/my.cnf.d/socket.cnf�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho '[client]' >> /etc/my.cnf.d/socket.cnf�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho 'socket = /tmp/mysql/mysqld.sock' >> /etc/my.cnf.d/socket.cnf�[0m
�[36mmysql_1  |�[0m �[0;34m[INFO] Setting MySQL: [mysql] socket=/tmp/mysql/mysqld.sock�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho '[mysql]' >> /etc/my.cnf.d/socket.cnf�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho 'socket = /tmp/mysql/mysqld.sock' >> /etc/my.cnf.d/socket.cnf�[0m
�[36mmysql_1  |�[0m �[0;34m[INFO] Setting MySQL: [mysqld] socket=/tmp/mysql/mysqld.sock�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho '[mysqld]' >> /etc/my.cnf.d/socket.cnf�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mecho 'socket = /tmp/mysql/mysqld.sock' >> /etc/my.cnf.d/socket.cnf�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mmkdir -p /tmp/mysql�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchown mysql:mysql /tmp/mysql�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchmod 0777 /tmp/mysql�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchown -R mysql:mysql /var/lib/mysql/�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchown -R mysql:mysql /var/lib/mysql�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchown -R mysql:mysql /var/log/mysql�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchown -R mysql:mysql /var/run/mysqld�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchown -R mysql:mysql /var/sock/mysqld�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchmod 0775 /var/lib/mysql/�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchmod 0775 /var/lib/mysql�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchmod 0775 /var/log/mysql�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchmod 0775 /var/run/mysqld�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mchmod 0775 /var/sock/mysqld�[0m
�[36mmysql_1  |�[0m �[0;31mroot $ �[0;32mfind /var/log/mysql/ -type f -exec chmod 0664 {} \;�[0m
�[36mmysql_1  |�[0m �[0;34m[INFO] Found existing data directory. MySQL already setup.�[0m
�[36mmysql_1  |�[0m 190131 17:01:48 [Note] mysqld (mysqld 5.5.59-MariaDB) starting as process 91 ...
�[36mmysql_1  |�[0m �[0;34m[INFO] Starting mysqld  Ver 5.5.59-MariaDB for Linux on x86_64 (MariaDB Server)�[0m
�[36mmysql_1  |�[0m 190131 17:01:48 [Note] mysqld (mysqld 5.5.59-MariaDB) starting as process 1 ...

But the dashboard database page says MySQL container is not running.

[cytopia]

Do you have any custom *.cnf files in place?

[cytopia]

�[36mmysql_1  |�[0m 190131 17:01:48 [Note] mysqld (mysqld 5.5.59-MariaDB) starting as process 91 ...
�[36mmysql_1  |�[0m �[0;34m[INFO] Starting mysqld  Ver 5.5.59-MariaDB for Linux on x86_64 (MariaDB Server)�[0m
�[36mmysql_1  |�[0m 190131 17:01:48 [Note] mysqld (mysqld 5.5.59-MariaDB) starting as process 1 ...

Looks like MySQL was already initialized and did not start from scratch, or is this just a second run?

• Did you compare your current .env vs env-example to see if you're missing some options?
• Can you reach MySQL via phpMyAdmin?

[danemorgan]

Yes. The first thing I did when I checked out the new branch was to diff the environment file. I have attached my file here.
Copy.env.txt

I cannot. I get this.

'''
Cannot log in to the MySQL server
mysqli_real_connect(): MySQL server has gone away
mysqli_real_connect(): Error while reading greeting packet. PID=2293
mysqli_real_connect(): (HY000/2006): MySQL server has gone away
'''

docker ps also shows no MySQL container

C:\Users\danea\devilbox (docker-volumes -> origin)
λ docker ps
CONTAINER ID        IMAGE                            COMMAND                  CREATED             STATUS              PORTS                                        NAMES
dfed0ea461e4        devilbox/nginx-stable:0.28       "/docker-entrypoint.…"   4 minutes ago       Up 4 minutes        0.0.0.0:80->80/tcp, 0.0.0.0:443->443/tcp     devilbox_httpd_1
0427a9c41867        devilbox/php-fpm:7.0-work-0.72   "/docker-entrypoint.…"   4 minutes ago       Up 4 minutes        9000/tcp                                     devilbox_php_1
159a18f833bd        cytopia/bind:0.15                "/docker-entrypoint.…"   4 minutes ago       Up 4 minutes        0.0.0.0:1053->53/tcp, 0.0.0.0:1053->53/udp   devilbox_bind_1

[cytopia]

1. What happens if you just start the MySQL container manually via:

docker run -it -e MYSQL_ROOT_PASSWORD= cytopia/mariadb-5.5:latest

2. And also if you run the Devilbox again, but this time with MariaDB 10.3 instead?

[danemorgan]

What happens if you just start the MySQL container manually via:
docker run -it -e MYSQL_ROOT_PASSWORD= cytopia/mariadb-5.5:latest

C:\Users\danea\devilbox (docker-volumes -> origin)
λ docker ps
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES

C:\Users\danea\devilbox (docker-volumes -> origin)
λ docker run -it -e MYSQL_ROOT_PASSWORD= cytopia/mariadb-5.5:latest
[WARN] $TIMEZONE not set.
[INFO] Docker date set to: Fri Feb  1 12:39:08 UTC 2019
[INFO] $MYSQL_GENERAL_LOG not set. Keeping default: [mysqld] general-log=FALSE
[INFO] $MYSQL_SOCKET_DIR not set. Keeping default: [client] socket=/var/sock/mysqld/mysqld.sock
[INFO] $MYSQL_SOCKET_DIR not set. Keeping default: [mysql] socket=/var/sock/mysqld/mysqld.sock
[INFO] $MYSQL_SOCKET_DIR not set. Keeping default: [mysqld] socket=/var/sock/mysqld/mysqld.sock
[INFO] No existing MySQL data directory found. Setting up MySQL for the first time.
Installing MariaDB/MySQL system tables in '/var/lib/mysql/' ...
190201 12:39:08 [Note] /usr/sbin/mysqld (mysqld 5.5.59-MariaDB) starting as process 115 ...
OK
Filling help tables...
190201 12:39:08 [Note] /usr/sbin/mysqld (mysqld 5.5.59-MariaDB) starting as process 123 ...
OK

To start mysqld at boot time you have to copy
support-files/mysql.server to the right place for your system

PLEASE REMEMBER TO SET A PASSWORD FOR THE MariaDB 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 172.17.0.2 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 MariaDB Knowledgebase at http://mariadb.com/kb or the
MySQL manual for more instructions.

You can start the MariaDB daemon with:
cd '/usr' ; /usr/bin/mysqld_safe --datadir='/var/lib/mysql/'

You can test the MariaDB daemon with mysql-test-run.pl
cd '/usr/mysql-test' ; perl mysql-test-run.pl

Please report any problems at http://mariadb.org/jira

The latest information about MariaDB is available at http://mariadb.org/.
You can find additional information about the MySQL part at:
http://dev.mysql.com
Consider joining MariaDB's strong and vibrant community:
https://mariadb.org/get-involved/

190201 12:39:08 [Note] mysqld (mysqld 5.5.59-MariaDB) starting as process 130 ...
[INFO] Initializing ...
[INFO] Initializing ...
[INFO] Setting up root user permissions.
[INFO] Shutting down MySQL.
[INFO] MySQL successfully installed.
190201 12:39:15 [Note] mysqld (mysqld 5.5.59-MariaDB) starting as process 198 ...
[INFO] Starting mysqld  Ver 5.5.59-MariaDB for Linux on x86_64 (MariaDB Server)
190201 12:39:15 [Note] mysqld (mysqld 5.5.59-MariaDB) starting as process 1 ...

I get this, but after a half hour, I still do not get the command prompt back. I have to close the terminal window and restart.

When I restart the terminal there is a mariadb container.

[danemorgan]

MariaDB 10.3 works as expected.

So does this mean there is something wrong with the 5.5.59 files on my computer? How can I overwrite those?

[danemorgan]

If live sites are using 5.5.59 and I am using 10.3 on these dev copies, does it matter? The database is never sent from dev to lie, only from live to dev.

[cytopia]

Shouldn't matter, except that you might have slightly more features. You can also try a version which comes directly after 5.5.59, such as 10.0 for MariaDB or give MySQL 5.5 a go as well.

In the meantime I will figure out how to integrate official MySQL/MariaDB/Percona Docker images instead of self-built ones.

[cytopia]

@danemorgan could you try out the release branch: #416 Please pay special attention to the instructions in the PR description.

[cytopia]

@danemorgan any updates from your side?

[cytopia]

@danemorgan see also here: #542

[cytopia]

@danemorgan this error will be fixed in: #416

This is going to be merged in a couple of hours.