Devilbox: MySQL works on first run, then won't connect again

[pnoeric]

ISSUE TYPE

• Bug Report
  

Checklist

• [x] .env file is attached - my-dot-env.txt - note that I did nothing except what is in the docs and selected MariaDB 5.5 since it matches the production server, otherwise it is same as default-env
• [x] docker-compose.override.yml is attached (if it exists) - DOES NOT EXIST
• [x] Custom configs from cfg/ dir are attached (if customized) - NONE
• [x] docker-compose logs and log/ output is added

my-docker-compose-logs.txt

in the mariadb-5.5 folder are 3 files (error.log, query.log, slow.log), all of them are 0 bytes

• [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
• [x] I've read troubleshooting: https://devilbox.readthedocs.io/en/latest/support/troubleshooting.html

OS / ENVIRONMENT

1. Host operating system and version: Mac OS X 10.14.3
2. (Windows) Native Docker or Docker Toolbox: n/a
3. Docker version: Docker version 18.09.2, build 6247962
4. Docker Compose version: 1.23.2

also I am using Mac Docker Desktop, the latest version which is Version 2.0.0.3 (31259)

1. (Linux) Is SELinux enabled?: n/a
2. What git commit hash are you on?: commit 57b2a5c59992ca5b9603a48465b8fbfa80bdca29 (HEAD -> release/v1.0.0, tag: v1.0.0-alpha1, origin/release/v1.0.0)

SUMMARY

Short summary - Everything works great on first startup, then I shut down as the docs describe, start the box again, and MySQL is dead. Possible same as issue #500 ?

Longer explanation - I installed devilbox following the docs exactly and it worked perfectly first try. Wow! Then I exported a 1.5 GB MySQL db from another server and imported it into the local MariaDB inside of devilbox. No errors and I could use my site locally with the db, everything was perfect.

I shut down (following the steps in the docs) and then started it up again... and now can't connect to the MySQL server. There are no errors on startup that I notice, but as you can see the server is unhappy:

STEPS TO REPRODUCE

• Install devilbox exactly like it says on the tin, be sure mysql is running fine
• Import large database (may not be necessary, if #500 is same issue, that user did not)
• Shut down devilbox correctly
• Start devilbox again - now MySQL can't connect
• Optional: shutdown again, upgrade to 1.0.0 branch, startup again - did not fix the problem

EXPECTED BEHAVIOUR

MySQL can always connect

ACTUAL BEHAVIOUR

MySQL craps out after the 1st run

OTHER INFORMATION

Start command

$ docker-compose up php mysql httpd bind

File and user permissions (Linux & MacOS)

$ id
uid=501(ericmueller) gid=20(staff) groups=20(staff),12(everyone),61(localaccounts),79(_appserverusr),80(admin),81(_appserveradm),98(_lpadmin),33(_appstore),100(_lpoperator),204(_developer),250(_analyticsusers),395(com.apple.access_ftp),398(com.apple.access_screensharing),399(com.apple.access_ssh)

$ ls -la

$ ls -la data/www

[cytopia]

@pnoeric thanks for the very detailed bug description. As I've never experienced this bug myself (running Linux), I made a few searches and what I came up with:

In case your OS went to sleep once the container where running, this might have caused it.

https://github.com/docker/for-mac/issues/1990

Once suggestion is not only to stop the Docker container, but to also restart the Docker engine.
Can you give it a shot and let me know afterwards.

[cytopia]

As a second step to try (once the first thing did not succeed) is to

1. Stop container docker-compose stop
2. Remove stopped container docker-compose rm -f
3. Remove Devilbox docker network (see below for an example)
4. Restart Docker engine

$ docker network ls
NETWORK ID          NAME                    DRIVER              SCOPE
14f15146ee03        bridge                  bridge              local
ad26b2d09381        devilbox_app_net       bridge              local

$ docker network rm ad26b2d09381

[pnoeric]

Ok - I just quit the Docker Desktop completely (which I assume restarts the docker engine) and relaunched it. Let's see what happens when I spin up the box now... nope, no luck.

Now I'll try the 2nd step, stopping the container, removing it, removing the devilbox network and restarting the engine too. By the way, I don't know if this is a clue, but when I do docker network ls (step 3 above), I get this:

FWIW I have no idea what the 'bridge' 'host' and 'null' networks are... not sure if those are supposed to be there or not... Docker is a bit foreign to me. ;-) I can tell you that I'm not running any other Docker projects or whatever right now... could those be anything related to the problem?

Anyhow. Ok. Docker just restarted so now let me spin up Devilbox again... no luck :-(

I really appreciate your help in trying to get to the bottom of this; Devilbox is exactly what I had in mind when I posted this on StackExchange. ;-)

What else can I do or provide? Could it be something in the container holding the mysql engine... anything I can check there?

[cytopia]

FWIW I have no idea what the 'bridge' 'host' and 'null' networks are...

These are also shown on my output and come by default. I just cut it as I had lots of networks.

By looking at your provided .env file I can tell that this is not the one created out of env-example from the v1.0.0 release branch. So are you on the latest commit on release/v1.0.0 branch?

Three other things that could come to my mind are:

1. Full MacOS reboot
2. Docker reset
3. Your current Docker Version 18.09.2 Use any version older than 18.09.0, for example: 18.07.x

[pnoeric]

Ok, thanks. It's late here in Switzerland so I'll give this a crack tomorrow and report back.

You're absolutely right that the .env example was my old one from before I upgraded to 1.0.0 branch-- my mistake, I'm sorry about that. I should be on the latest commit otherwise; just didn't delete the .env and re-create it from the new env-example after checking out that branch.

[cytopia]

Also note that if you've already added data to MySQL when you where on the master branch, it won't be available in the release branch as the two branches use different concepts of where to store the data.

• master branch: stores MySQL data in data/mysql
• release branch: stores MySQL data in named volumes

Additionally on the master branch, the Devilbox uses custom Docker images for MySQL and on the release branch the official Docker images for MySQL are used.

So can you give their issue tracker a shot as well and see if anything related can be found there: https://github.com/docker-library/mysql/issues

[pnoeric]

Hmmm let me ask you this... I don't care about blowing away my current installation, my data, whatever. I'd rather get it working reliably and then build from there. What's the best way to start over everything from scratch from my machine? I'm thinking delete everything, then download a fresh devilbox per the instructions, then switch the 1.0.0 branch so I get whatever new MySQL server, I'll make a fresh .env from the env example, etc. See what I mean?

Do I just drag the entire devilbox folder to the trash and start cold that way? Is there anything else I need to delete?

[cytopia]

Cleanest way is to (Ensure needed data is backed up):

1. docker-compose stop; docker-compose kill; docker-compose rm -f;
2. Delete directory
3. Delete Devilbox volumes
4. Delete Devilbox network
5. Clone Devilbox
6. Checkout release/v1.0.0
7. Create .env file

How to view/remove volumes

$ docker volume ls
DRIVER              VOLUME NAME
local               devilbox_devilbox-mail
local               devilbox-data-www-sync
local               devilbox-intranet-sync

# Automate deletion
$ docker volume ls | grep devilbox | awk -F' ' '{print $2}' | xargs docker volume rm

[cytopia]

Just to be extra cautious, also restart the Docker engine before starting the newly cloned Devilbox stack.

[pnoeric]

1. Removed everything old per your steps above, including volumes and networks. Quit Mac Docker Desktop app completely.

2. Cloned devilbox fresh from git

3. Immeditely followed steps in #416 to switch to 1.0.0 branch

4. Copied example .env file, added my group/ID, set MOUNT_OPTIONS=,cached, set MYSQL_SERVER=mariadb-5.5

5. Relaunched Docker Desktop app, started up devilbox for first time, all seems good on localhost.

6. Shut down devilbox (down, rm -f), started it up again. DB still ok and connected! Excellent!

7. Testing with small data set: importing this "US 500" test data CSV using phpMyAdmin - https://www.briandunning.com/sample-data/

8. Start up, shut down, no problems! Excellent!

9. So let's try it now with the real data. Start up, importing my huge database... ok database is imported, you can see how big it is...

1. Note that I have NOT stopped devilbox yet, and EVERYTHING IS WORKING GREAT - my site, the database is there, the data works, etc. No problems at all.

2. Shut down, start up - and now the MariaDB can't connect. Devilbox is unhappy. Now we see the problem.

SO... it looks like the issue is something with my giant database making the MariaDB unhappy. However there are no error messages in the startup, just a few small warnings. Here is what I see from the most recent startup:

Maybe a way to attack this would be to go into the database container and get more details about what's going on? Or, what do you think?

[pnoeric]

By the way, after the above, to fix the situation, I did this:

1. Shut down (always: down, rm -f)
2. Delete the docker volumes only

docker volume ls | grep devilbox | awk -F' ' '{print $2}' | xargs docker volume rm

1. Restart, re-import database... all is good and I can work on my app/data!

So now I just need to NOT shut down the docker container or else I have to repeat this whole process again. The import takes a while since the db is so big! This is not ideal but it's a workaround for now. But I would love to find the problem so we can solve it.

Thank you for all your help!

[cytopia]

Try to go into the MySQL container:

docker-compose exec mysql bash

And then connect locally to the database for further inspection:

mysql -uroot -h127.0.0.1 -p`

[cytopia]

It could very well also just be a simple bug in the intranet code for querying the database for display.

[cytopia]

You could actually check this right away: If the Database is shown as not available, does phpMyAdmin still work?

[pnoeric]

both PhpMyAdmin AND my app can't connect to the database once it's messed up.

So, yeah, the database (or connection to the database) is definitely not happy. I'll try logging directly into the container and see if I can find anything.

[pnoeric]

Ok, I went logged in directly to the db container (docker-compose exec mysql bash) and it seems ok. I can get into the database, SHOW DATABASES shows the big db, and I can then use that db and SELECT * FROM tblMembers LIMIT 10 and it works.

root@mysql:/# mysqladmin status
Uptime: 364 Threads: 1 Questions: 45 Slow queries: 0 Opens: 35 Flush tables: 2 Open tables: 61 Queries per second avg: 0.123

root@mysql:/# mysqladmin version
mysqladmin Ver 9.0 Distrib 5.5.63-MariaDB, for debian-linux-gnu on x86_64
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Server version 5.5.63-MariaDB-1~trusty
Protocol version 10
Connection Localhost via UNIX socket
UNIX socket /var/run/mysqld/mysqld.sock
Uptime: 6 min 18 sec

Threads: 1 Questions: 46 Slow queries: 0 Opens: 35 Flush tables: 2 Open tables: 61 Queries per second avg: 0.121

So... hmm. Seems like the issue is definitely in docker somewhere, like devilbox can't connect to that other container any longer. What can I do next?

[cytopia]

In the MySQL container can you check/provide

• netstat -tulpn
• Check if it knows itself: ping mysql
• Check if php container is reachable ping php and ping 172.16.238.10

In the PHP container can you check/provide

• Check if php can reach the MySQL container via IP address ping 172.16.238.12 and mysql -uroot -h172.16.238.12 -p

[pnoeric]

In MySQL container -- netstat

root@mysql:/# netstat -tulpn
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:3306            0.0.0.0:*               LISTEN      -
tcp        0      0 127.0.0.11:34283        0.0.0.0:*               LISTEN      -
udp        0      0 127.0.0.11:36940        0.0.0.0:*                           -

In MySQL container -- pinging self

root@mysql:/# ping mysql
PING mysql (172.16.238.12) 56(84) bytes of data.
64 bytes from mysql (172.16.238.12): icmp_seq=1 ttl=64 time=0.034 ms
64 bytes from mysql (172.16.238.12): icmp_seq=2 ttl=64 time=0.051 ms
64 bytes from mysql (172.16.238.12): icmp_seq=3 ttl=64 time=0.049 ms
64 bytes from mysql (172.16.238.12): icmp_seq=4 ttl=64 time=0.069 ms

In MySQL container -- pinging php container

root@mysql:/# ping php
PING php (172.16.238.10) 56(84) bytes of data.
64 bytes from devilbox_php_1.devilbox_app_net (172.16.238.10): icmp_seq=1 ttl=64 time=0.075 ms
64 bytes from devilbox_php_1.devilbox_app_net (172.16.238.10): icmp_seq=2 ttl=64 time=0.113 ms
64 bytes from devilbox_php_1.devilbox_app_net (172.16.238.10): icmp_seq=3 ttl=64 time=0.069 ms
64 bytes from devilbox_php_1.devilbox_app_net (172.16.238.10): icmp_seq=4 ttl=64 time=0.152 ms

root@mysql:/# ping 172.16.238.10
PING 172.16.238.10 (172.16.238.10) 56(84) bytes of data.
64 bytes from 172.16.238.10: icmp_seq=1 ttl=64 time=0.105 ms
64 bytes from 172.16.238.10: icmp_seq=2 ttl=64 time=0.085 ms
64 bytes from 172.16.238.10: icmp_seq=3 ttl=64 time=0.082 ms
64 bytes from 172.16.238.10: icmp_seq=4 ttl=64 time=0.103 ms
64 bytes from 172.16.238.10: icmp_seq=5 ttl=64 time=0.084 ms

In PHP container - pinging MySQL container

[email protected] in /shared/httpd $ ping 172.16.238.12
PING 172.16.238.12 (172.16.238.12) 56(84) bytes of data.
64 bytes from 172.16.238.12: icmp_seq=1 ttl=64 time=0.095 ms
64 bytes from 172.16.238.12: icmp_seq=2 ttl=64 time=0.115 ms
64 bytes from 172.16.238.12: icmp_seq=3 ttl=64 time=0.088 ms
64 bytes from 172.16.238.12: icmp_seq=4 ttl=64 time=0.085 ms
64 bytes from 172.16.238.12: icmp_seq=5 ttl=64 time=0.086 ms
64 bytes from 172.16.238.12: icmp_seq=6 ttl=64 time=0.112 ms
64 bytes from 172.16.238.12: icmp_seq=7 ttl=64 time=0.076 ms

In PHP container - trying to connect to mysql

[email protected] in /shared/httpd $ mysql -uroot -h172.16.238.12 -p
Enter password:
ERROR 1130 (HY000): Host '172.16.238.10' is not allowed to connect to this MariaDB server

I'm not sure how to interpret any of these results but hopefully that gives us some useful data...

[cytopia]

Are these the results when the MySQL container is working or is broken?

[cytopia]

And what about ping mysql from within the PHP container? (when the MySQL container is broken)

[pnoeric]

Oh hell. Just had a thought. I wonder if I am importing some access rules into MySQL, when I do the big import?

[pnoeric]

Don't you just hate that moment of discovery, when you realize it was something stupid all along? ;-)

That was it. Apparently the production server dramatically restricted access to the db, so the mysql.user table was set in a way that didn't let an outside user (like the php container) connect to the database.

I did a quick GRANT ALL PRIVILEGES ON *.* TO 'root'@'%'; and boom, everything is now good. I can start up and shut down devilbox without problems.

Now I see why it worked until I rebooted: on import, the new access rules were in place but those are only loaded when the MySQL server starts up. So the current session (at that time) would continue to run just fine. But on the next startup, the new access rules would be parsed and the php container was then locked out.

Thank you so much, cytopia, for all your help along the way.

Perhaps we can salvage some of this work and add it to the troubleshooting section of the documentation, as things to try. Or maybe if there is a 'sanity check' script on the mysql container, this could be something it checks, that the php container has access.

I'm kind of embarrassed! And at the same time, very happy to have this working!

[cytopia]

Docs will be available here shortly: https://devilbox.readthedocs.io/en/latest/support/troubleshooting.html

[cytopia]

https://devilbox.readthedocs.io/en/latest/support/troubleshooting.html#sqlstate-hy000-1130-host-172-16-238-10-is-not-allowed-to-connect-to-this-mariadb-server