Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

502 Bad Gateway after Fresh Install #2939

Closed
4 of 5 tasks
ghost opened this issue Sep 15, 2019 · 32 comments
Closed
4 of 5 tasks

502 Bad Gateway after Fresh Install #2939

ghost opened this issue Sep 15, 2019 · 32 comments

Comments

@ghost
Copy link

ghost commented Sep 15, 2019

Prior to placing the issue, please check following: (fill out each checkbox with a X once done)

  • I understand that not following below instructions might result in immediate closing and deletion of my issue.
  • I have understood that answers are voluntary and community-driven, and not commercial support.
  • I have verified that my issue has not been already answered in the past. I also checked previous issues.

Description of the bug: What kind of issue have you exactly come across?

I got a new Server and did a fresh install of both OS and mailcow (tested with Debian 9.11 and Debian 10.1). I did it like ... 6 times now and everything is ending in an 502 Bad Gateway output of nginx so i couldnt reach the UI a single time. I read a few of the other 502 Issues in here but none of the hints was working for me.

Reproduction of said bug: How exactly do you reproduce the bug?

So what i did:

After that i try to open mail.xxxxxx.de and i get the 502 Bad Gateways Error

I have tried or I do... (fill out each checkbox with a X if applicable)

  • In case of WebUI issue, I have tried clearing the browser cache and the issue persists.
  • I do run mailcow on a Synology, QNAP or any other sort of NAS.

System information

Further information (where applicable):

Question Answer
My operating system Debian 9.11 / 10.1
Is Apparmor, SELinux or similar active? No
Virtualization technlogy (KVM, VMware, Xen, etc) No
Server/VM specifications (Memory, CPU Cores) i7 8 Cores, 64GB Ram, 4TB HDD
Docker Version (docker version) 19.03.2
Docker-Compose Version (docker-compose version) 1.24.1, build 4667896b
Reverse proxy (custom solution) tried it with and without nginx as reverse proxy

Further notes:

  • Output of git diff origin/master, any other changes to the code? If so, please post them.
  • All third-party firewalls and custom iptables rules are unsupported. Please check the Docker docs about how to use Docker with your own ruleset. Nevertheless, iptabels output can help us to help you: iptables -L -vn, ip6tables -L -vn, iptables -L -vn -t nat and ip6tables -L -vn -t nat

Chain INPUT (policy ACCEPT 1354 packets, 101K bytes)
pkts bytes target prot opt in out source destination
1385 103K MAILCOW all -- * * 0.0.0.0/0 0.0.0.0/0

Chain FORWARD (policy DROP 170 packets, 8428 bytes)
pkts bytes target prot opt in out source destination
1886 165K MAILCOW all -- * * 0.0.0.0/0 0.0.0.0/0
26796 188M DOCKER-USER all -- * * 0.0.0.0/0 0.0.0.0/0
26796 188M DOCKER-ISOLATION-STAGE-1 all -- * * 0.0.0.0/0 0.0.0.0/0
14596 188M ACCEPT all -- * br-mailcow 0.0.0.0/0 0.0.0.0/0 ctstate RELATED,ESTABLISHED
310 19839 DOCKER all -- * br-mailcow 0.0.0.0/0 0.0.0.0/0
11608 559K ACCEPT all -- br-mailcow !br-mailcow 0.0.0.0/0 0.0.0.0/0
302 19423 ACCEPT all -- br-mailcow br-mailcow 0.0.0.0/0 0.0.0.0/0
0 0 ACCEPT all -- * docker0 0.0.0.0/0 0.0.0.0/0 ctstate RELATED,ESTABLISHED
0 0 DOCKER all -- * docker0 0.0.0.0/0 0.0.0.0/0
0 0 ACCEPT all -- docker0 !docker0 0.0.0.0/0 0.0.0.0/0
0 0 ACCEPT all -- docker0 docker0 0.0.0.0/0 0.0.0.0/0

Chain OUTPUT (policy ACCEPT 1693 packets, 1178K bytes)
pkts bytes target prot opt in out source destination

Chain DOCKER (2 references)
pkts bytes target prot opt in out source destination
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.9 tcp dpt:587
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.9 tcp dpt:465
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.9 tcp dpt:25
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.7 tcp dpt:3306
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.250 tcp dpt:12345
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.250 tcp dpt:4190
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.250 tcp dpt:995
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.250 tcp dpt:993
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.250 tcp dpt:143
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.250 tcp dpt:110
0 0 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.13 tcp dpt:443
4 208 ACCEPT tcp -- !br-mailcow br-mailcow 0.0.0.0/0 172.22.1.13 tcp dpt:80

Chain DOCKER-ISOLATION-STAGE-1 (1 references)
pkts bytes target prot opt in out source destination
11608 559K DOCKER-ISOLATION-STAGE-2 all -- br-mailcow !br-mailcow 0.0.0.0/0 0.0.0.0/0
0 0 DOCKER-ISOLATION-STAGE-2 all -- docker0 !docker0 0.0.0.0/0 0.0.0.0/0
26842 188M RETURN all -- * * 0.0.0.0/0 0.0.0.0/0

Chain DOCKER-ISOLATION-STAGE-2 (2 references)
pkts bytes target prot opt in out source destination
0 0 DROP all -- * br-mailcow 0.0.0.0/0 0.0.0.0/0
0 0 DROP all -- * docker0 0.0.0.0/0 0.0.0.0/0
11608 559K RETURN all -- * * 0.0.0.0/0 0.0.0.0/0

Chain DOCKER-USER (1 references)
pkts bytes target prot opt in out source destination
26842 188M RETURN all -- * * 0.0.0.0/0 0.0.0.0/0

Chain MAILCOW (2 references)
pkts bytes target prot opt in out source destination

  • Check docker exec -it $(docker ps -qf name=acme-mailcow) dig +short stackoverflow.com @172.22.1.254 (set the IP accordingly, if you changed the internal mailcow network) and docker exec -it $(docker ps -qf name=acme-mailcow) dig +short stackoverflow.com @1.1.1.1 - output? Timeout?

docker exec -it $(docker ps -qf name=acme-mailcow) dig +short stackoverflow.com @172.22.1.254
---> 151.101.1.69
151.101.65.69
151.101.129.69
151.101.193.69

docker exec -it $(docker ps -qf name=acme-mailcow) dig +short stackoverflow.com @1.1.1.1
---> 151.101.129.69
151.101.193.69
151.101.1.69
151.101.65.69

General logs:
NGinx:

docker-compose logs nginx-mailcow
WARNING: The WATCHDOG_NOTIFY_EMAIL variable is not set. Defaulting to a blank string.
Attaching to mailcowdockerized_nginx-mailcow_1
nginx-mailcow_1 | 2019/09/15 10:33:57 [emerg] 13#13: host not found in upstream "rspamd" in /etc/nginx/conf.d/site.conf:115
nginx-mailcow_1 | nginx: [emerg] host not found in upstream "rspamd" in /etc/nginx/conf.d/site.conf:115
nginx-mailcow_1 | nginx: configuration file /etc/nginx/nginx.conf test failed
nginx-mailcow_1 | 172.22.1.11 - - [15/Sep/2019:10:34:07 +0200] "HEAD /settings.php HTTP/1.1" 502 0 "-" "rspamd-1.9.4"
nginx-mailcow_1 | 172.22.1.11 - - [15/Sep/2019:10:34:07 +0200] "HEAD /forwardinghosts.php HTTP/1.1" 502 0 "-" "rspamd-1.9.4"
nginx-mailcow_1 | 2019/09/15 10:34:07 [error] 18#18: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 172.22.1.11, server: _, request: "HEAD /settings.php HTTP/1.1", upstream: "fastcgi://172.22.1.10:9001", host: "nginx"
nginx-mailcow_1 | 2019/09/15 10:34:07 [error] 18#18: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 172.22.1.11, server: _, request: "HEAD /settings.php HTTP/1.1", upstream: "fastcgi://[fd4d:6169:6c63:6f77::e]:9001", host: "nginx"
nginx-mailcow_1 | 2019/09/15 10:34:07 [error] 18#18: *4 no live upstreams while connecting to upstream, client: 172.22.1.11, server: _, request: "HEAD /forwardinghosts.php HTTP/1.1", upstream: "fastcgi://phpfpm", host: "nginx"

This my netstat:

tcp 0 0 127.0.0.1:19991 0.0.0.0:* LISTEN 12596/docker-proxy
tcp 0 0 127.0.0.1:13306 0.0.0.0:* LISTEN 12111/docker-proxy
tcp6 0 0 :::587 :::* LISTEN 12309/docker-proxy
tcp6 0 0 :::110 :::* LISTEN 12672/docker-proxy
tcp6 0 0 :::143 :::* LISTEN 12659/docker-proxy
tcp6 0 0 :::80 :::* LISTEN 14131/docker-proxy
tcp6 0 0 :::465 :::* LISTEN 12321/docker-proxy
tcp6 0 0 :::22 :::* LISTEN 535/sshd
tcp6 0 0 :::25 :::* LISTEN 12334/docker-proxy
tcp6 0 0 :::443 :::* LISTEN 14118/docker-proxy
tcp6 0 0 :::4190 :::* LISTEN 12615/docker-proxy
tcp6 0 0 :::993 :::* LISTEN 12646/docker-proxy
tcp6 0 0 :::995 :::* LISTEN 12632/docker-proxy

another thing i see is:

postfix-mailcow_1 | Waiting for database to come up...
postfix-mailcow_1 | Waiting for database to come up...
postfix-mailcow_1 | Waiting for database to come up...

sogo-mailcow_1 | Waiting for database to come up...
sogo-mailcow_1 | Waiting for database to come up...
sogo-mailcow_1 | Waiting for database to come up...

php-fpm-mailcow_1 | Waiting for SQL...
php-fpm-mailcow_1 | Waiting for SQL...
php-fpm-mailcow_1 | Waiting for SQL...

the mysql log shows:

mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] mysqld (mysqld 10.2.27-MariaDB-1:10.2.27+mariabionic) starting as process 1 ...
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Uses event mutexes
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Compressed tables use zlib 1.2.11
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Using Linux native AIO
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Number of pools: 1
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Using SSE2 crc32 instructions
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Completed initialization of buffer pool
mysql-mailcow_1 | 2019-09-15 20:28:23 140339111360256 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
mysql-mailcow_1 | 2019-09-15 20:28:23 140339836097856 [Note] InnoDB: Highest supported file format is Barracuda.
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Note] InnoDB: 128 out of 128 rollback segments are active.
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Note] InnoDB: Creating shared tablespace for temporary tables
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Note] InnoDB: 5.7.27 started; log sequence number 8838877
mysql-mailcow_1 | 2019-09-15 20:28:24 140338945562368 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Note] Server socket created on IP: '::'.
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Warning] 'user' entry 'root@bb138afe0035' ignored in --skip-name-resolve mode.
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Warning] 'proxies_priv' entry '@% root@bb138afe0035' ignored in --skip-name-resolve mode.
mysql-mailcow_1 | 2019-09-15 20:28:24 140339668272896 [Note] Event Scheduler: scheduler thread started with id 6
mysql-mailcow_1 | 2019-09-15 20:28:24 140339836097856 [Note] mysqld: ready for connections.
mysql-mailcow_1 | Version: '10.2.27-MariaDB-1:10.2.27+maria~bionic' socket: '/var/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution
mysql-mailcow_1 | 2019-09-15 20:28:24 140338945562368 [Note] InnoDB: Buffer pool(s) load completed at 190915 20:28:24

@simonvizzini
Copy link

I have the same problem, culprit seems to be that database login does not work (hence the Waiting for database to come up... messages). Today is the first time I installed mailcow and I've been running in circles for the past hours. Glad I'm not the only one and that it seems to be a problem with the current mailcow version itself.

@andryyy
Copy link
Contributor

andryyy commented Sep 16, 2019

Tested it on two new servers right now and cannot replicate it.

You should try docker-compose down -v (which deletes all data), delete the mailcow-dockerized folder path, clone mailcow and generate a new config. Don't change the config, use the default generated stuff for testing and run docker-compose pull && docker-compose up -d again.

@pew
Copy link

pew commented Sep 16, 2019

having the same issue but by running the update.sh script

@andryyy
Copy link
Contributor

andryyy commented Sep 16, 2019

New installation No. 3 (edit: on Debian 10 btw.) ...

php-fpm-mailcow_1    | Waiting for SQL...
php-fpm-mailcow_1    | Waiting for SQL...
php-fpm-mailcow_1    | Waiting for SQL...
php-fpm-mailcow_1    | Waiting for SQL...
php-fpm-mailcow_1    | Waiting for SQL...
php-fpm-mailcow_1    | Waiting for SQL...
php-fpm-mailcow_1    | Waiting for SQL...
php-fpm-mailcow_1    | Uptime: 2  Threads: 8  Questions: 10  Slow queries: 0  Opens: 17  Flush tables: 1  Open tables: 11  Queries per second avg: 5.000
php-fpm-mailcow_1    | OK
php-fpm-mailcow_1    | OK
php-fpm-mailcow_1    | MySQL @ 864d573f0550ab30a947b593528c21eb61c41ee442561ccec757864032f30a12
php-fpm-mailcow_1    | MySQL applied an upgrade
php-fpm-mailcow_1    | Restarting Postfix
php-fpm-mailcow_1    | command completed successfully
php-fpm-mailcow_1    | Sleeping 10 seconds...
php-fpm-mailcow_1    | Restarting PHP-FPM, bye
php-fpm-mailcow_1    | Uptime: 13  Threads: 8  Questions: 28  Slow queries: 0  Opens: 17  Flush tables: 1  Open tables: 11  Queries per second avg: 2.153
php-fpm-mailcow_1    | MySQL @ 864d573f0550ab30a947b593528c21eb61c41ee442561ccec757864032f30a12
php-fpm-mailcow_1    | MySQL is up-to-date
php-fpm-mailcow_1    | Running DB init...
php-fpm-mailcow_1    | Cleaned up memcached
php-fpm-mailcow_1    | DB initialization completed
php-fpm-mailcow_1    | 0
php-fpm-mailcow_1    | [16-Sep-2019 06:56:13] NOTICE: fpm is running, pid 1
php-fpm-mailcow_1    | [16-Sep-2019 06:56:13] NOTICE: ready to handle connections
php-fpm-mailcow_1    | 172.22.1.11 -  16/Sep/2019:06:56:18 +0200 "GET /index.php" 200

Works.

I also run update.sh multiple times on multiple machines and cannot replicate that on any supported mailcow installation.

@simonvizzini
Copy link

Hmm strange, I just tried again and still same problem:

root@mailcow:/opt/mailcow-dockerized# docker-compose exec mysql-mailcow bash
root@367583f4c361:/# mysqladmin status --socket=/var/run/mysqld/mysqld.sock -u${MYSQL_USER} -p${MYSQL_PASSWORD}
mysqladmin: connect to server at 'localhost' failed
error: 'Access denied for user 'mailcow'@'localhost' (using password: YES)'
root@367583f4c361:/# echo $MYSQL_USER
mailcow
root@367583f4c361:/# echo $MYSQL_PASSWORD
--REDACTED--

I can confirm hat $MYSQL_USER and $MYSQL_PASSWORD is the same as DBNAME and DBPASS in mailcow.conf

MySQ container logs:

mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] mysqld (mysqld 10.2.27-MariaDB-1:10.2.27+maria~bionic) starting as process 1 ...
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Uses event mutexes
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Compressed tables use zlib 1.2.11
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Using Linux native AIO
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Number of pools: 1
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Using SSE2 crc32 instructions
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Completed initialization of buffer pool
mysql-mailcow_1      | 2019-09-16  7:13:51 139891767469824 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
mysql-mailcow_1      | 2019-09-16  7:13:51 139892496864576 [Note] InnoDB: Highest supported file format is Barracuda.
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] InnoDB: 128 out of 128 rollback segments are active.
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] InnoDB: Creating shared tablespace for temporary tables
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] InnoDB: Waiting for purge to start
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] InnoDB: 5.7.27 started; log sequence number 6702514
mysql-mailcow_1      | 2019-09-16  7:13:53 139891759077120 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] Server socket created on IP: '::'.
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Warning] 'user' entry 'root@3675b0cc6b78' ignored in --skip-name-resolve mode.
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Warning] 'proxies_priv' entry '@% root@3675b0cc6b78' ignored in --skip-name-resolve mode.
mysql-mailcow_1      | 2019-09-16  7:13:53 139891759077120 [Note] InnoDB: Buffer pool(s) load completed at 190916  7:13:53
mysql-mailcow_1      | 2019-09-16  7:13:53 139892202522368 [Note] Event Scheduler: scheduler thread started with id 6
mysql-mailcow_1      | 2019-09-16  7:13:53 139892496864576 [Note] mysqld: ready for connections.
mysql-mailcow_1      | Version: '10.2.27-MariaDB-1:10.2.27+maria~bionic'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution

Any ideas how to further debug this?

@andryyy
Copy link
Contributor

andryyy commented Sep 16, 2019

Don't know. I cannot fix what does not fail on various installations of my machines or any machine in support. :/

Try to reset your SQL passwords. Or try to repair the table, perhaps it is broken. That would not explain the broken installation, but your upgrading problems.

@pew
Copy link

pew commented Sep 16, 2019

ran update.sh again and it's working again. Whatever changed between Saturday morning and Today did fix it for me.

@andryyy
Copy link
Contributor

andryyy commented Sep 16, 2019

I don't think much changed. It is very important you wait a few minutes, if you run into the 502 page. We should change the default 502 to a "please wait" screen. :)

@pew
Copy link

pew commented Sep 16, 2019

I don't think much changed. It is very important you wait a few minutes, if you run into the 502 page. We should change the default 502 to a "please wait" screen. :)

well, I waited at least 24 hours :P - but a docker-compose down might have helped as well, I think that's something the update script does when there's something to update (a new ipv6nat container was available)

@simonvizzini
Copy link

Running Mailcow in a LXC container was causing this problem for me. I now installed Mailcow in a KVM and it works perfectly fine now.

@fvezzoli
Copy link

I think the problem is related to MariaDB/mariadb-docker#262

@andryyy
Copy link
Contributor

andryyy commented Oct 20, 2019

Their logs read "mysqld 10.2.27"

@fvezzoli
Copy link

Yes, but I see in the log there is missed MySQL init process done. Ready for start up. line in the log.
I think the problem is error in database creation.
I try the version 10.2.27 and the problem is present, I update to 10.3.17 problem disappear.

@andryyy
Copy link
Contributor

andryyy commented Oct 20, 2019

Ah, I understand. :)

Not sure if that's the reason though:

Affects Version/s: 10.4.3, 10.1.38, 10.2.22, 10.3.13, 10.0.38-galera
Fix Version/s: 10.1.42, 10.2.27, 10.3.18, 10.4.8

I setup new mailcows from time to time and did not run into that problem. :( I think we can close this issue. We upgraded to 10.3 (whereas 10.3.18 is the latest) and should check if that errors persists. Feel free to reopen the issue then.

@andryyy andryyy closed this as completed Oct 20, 2019
@macskay
Copy link

macskay commented Oct 22, 2019

Same thing happened to me today after running update.sh.

@andryyy
Copy link
Contributor

andryyy commented Oct 22, 2019

Logs?

@ClundXIII
Copy link

ClundXIII commented Nov 8, 2019

I can confirm this problem still exists with a fresh installation (from today).

I guess this part of the log describes the issue:

mysql-mailcow_1      | 2019-11-08 13:41:23 0 [Warning] 'user' entry 'root@0e810eb1849a' ignored in --skip-name-resolve mode.
mysql-mailcow_1      | 2019-11-08 13:41:23 0 [Warning] 'user' entry '@0e810eb1849a' ignored in --skip-name-resolve mode.
mysql-mailcow_1      | 2019-11-08 13:41:23 0 [Warning] 'proxies_priv' entry '@% root@0e810eb1849a' ignored in --skip-name-resolve mode.

I am running this on a fresh installation on debian 10 buster.

@andryyy
Copy link
Contributor

andryyy commented Nov 8, 2019

I installed it a few minutes ago without a problem.

@ClundXIII
Copy link

ClundXIII commented Nov 8, 2019

The mailcow system is installed on a virtual machine with one complete IP address being redirected towards it. Also I have 2 virtual networks connected to it, one is isolated. Other than that I cannot think of any reason why I have a different setup than you.

Are there any other logfiles or system information I can provide to you?

Is there a way to wipe the container and rerun the setup?

@andryyy
Copy link
Contributor

andryyy commented Nov 8, 2019

I think that's related to MYSQL_INITDB_SKIP_TZINFO (and that being empty, which is fine).

I can try to move that part to another stage. Hm. Don't know if we reaaaally need it anyway. I will figure it out.

@andryyy
Copy link
Contributor

andryyy commented Nov 8, 2019

Please try to change docker-compose.yml like this:

    mysql-mailcow:
      image: mariadb:10.3
      stop_grace_period: 45s
      volumes:
        - mysql-vol-1:/var/lib/mysql/
        - mysql-socket-vol-1:/var/run/mysqld/
        - ./data/conf/mysql/:/etc/mysql/conf.d/:ro
      environment:
        - TZ=${TZ}
        - MYSQL_ROOT_PASSWORD=${DBROOT}
        - MYSQL_DATABASE=${DBNAME}
        - MYSQL_USER=${DBUSER}
        - MYSQL_PASSWORD=${DBPASS}
        - MYSQL_INITDB_SKIP_TZINFO=1
      restart: always
      ports:
        - "${SQL_PORT:-127.0.0.1:13306}:3306"
      networks:
        mailcow-network:
          aliases:
            - mysql

MYSQL_INITDB_SKIP_TZINFO is new and set to 1 here.

We don't use the TZINFO anywhere. Not sure about Roundcube etc. ... we could still import the zones at a later stage as mentioned previously.

Please try and report back. :)

@ClundXIII
Copy link

No change :(

oot@mail:/opt/mailcow-dockerized# docker-compose logs --tail=200 mysql-mailcow
WARNING: The WATCHDOG_NOTIFY_EMAIL variable is not set. Defaulting to a blank string.
Attaching to mailcowdockerized_mysql-mailcow_1
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] mysqld (mysqld 10.3.18-MariaDB-1:10.3.18+maria~bionic) starting as process 1 ...
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Using Linux native AIO
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Uses event mutexes
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Number of pools: 1
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Using SSE2 crc32 instructions
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Completed initialization of buffer pool
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Creating shared tablespace for temporary tables
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Waiting for purge to start
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: 10.3.18 started; log sequence number 8495463; transaction id 7346
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] InnoDB: Buffer pool(s) load completed at 191109  0:25:12
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] Server socket created on IP: '::'.
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Warning] 'user' entry 'root@0e810eb1849a' ignored in --skip-name-resolve mode.
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Warning] 'user' entry '@0e810eb1849a' ignored in --skip-name-resolve mode.
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Warning] 'proxies_priv' entry '@% root@0e810eb1849a' ignored in --skip-name-resolve mode.
mysql-mailcow_1      | 2019-11-09  0:25:12 6 [Note] Event Scheduler: scheduler thread started with id 6
mysql-mailcow_1      | 2019-11-09  0:25:12 0 [Note] mysqld: ready for connections.
mysql-mailcow_1      | Version: '10.3.18-MariaDB-1:10.3.18+maria~bionic'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution

@ClundXIII
Copy link

ClundXIII commented Nov 8, 2019

Nothing else changed in the configs

root@mail:/opt/mailcow-dockerized# git diff origin/HEAD
diff --git a/docker-compose.yml b/docker-compose.yml
index 0478527e..dacf7bfb 100644
--- a/docker-compose.yml
+++ b/docker-compose.yml
@@ -30,6 +30,7 @@ services:
         - MYSQL_DATABASE=${DBNAME}
         - MYSQL_USER=${DBUSER}
         - MYSQL_PASSWORD=${DBPASS}
+        - MYSQL_INITDB_SKIP_TZINFO=1
       restart: always
       ports:
         - "${SQL_PORT:-127.0.0.1:13306}:3306"

@andryyy
Copy link
Contributor

andryyy commented Nov 9, 2019

You need to run "docker-compose down -v" and "docker-compose up -d". The volume needs to be purged before testing.

@andryyy
Copy link
Contributor

andryyy commented Nov 9, 2019

Can you try again and tell me if it still fails? If it does, please send me a mail to [email protected]

@ClundXIII
Copy link

That did it, thank you.

I ran update.sh before thinking that would reset the container.

@JohnGalt1717
Copy link

I'm getting this even with docker-compose down -v and then docker-compose up -d. I've even added --rmi all to remove all images on the down and it doesn't work. It worked the first time, but then on restart it started failing even with defaults.

The logs that it refers to just says "waiting for sql" endlessly for over 24 hours.

I purged all of the volumes and manually deleted the contents of anything left.

The only changes to my conf is disabling lets encrypt because I use pfsense to generate my lets encrypt certs and have a script that copies them in (and they're full 777) and I changed smtp to 2225 instead of 25 because of a conflict with something else using postfix on port 25.

What other logs do you need?

@Kinark
Copy link

Kinark commented Mar 10, 2020

Having the same issue as @JohnGalt1717 :(

@Adorfer
Copy link

Adorfer commented Mar 10, 2020

Having the same issue

can't reproducte. This is not a support ticket system.
if you assume that's an issue for mailcow-dockerized: Please open a new issue with the full template filled in.
(or alternativly: Seek help in the forum or the TG channel.)

@Elwin00
Copy link

Elwin00 commented Apr 13, 2020

Hello, just want to remark that I just tried to install mailcow-dockerized (master branch, commit 44f3b079) and was getting the same error(s) with the database (waiting for database to come up etc etc). Tried to login to mysql in mysql-mailcow container but couldn't (access denied for both mailcow and root users, using generated passwords form mailcow.conf). I attempted this multiple times (~5-6), always deleting everything and starting afresh.

It started working after I removed the line from docker-compose.yml that was suggested here by @andryyy (and that is already pushed into master branch).

MYSQL_INITDB_SKIP_TZINFO=1

I removed that and now I get the login screen instead of error 502.

@andryyy
Copy link
Contributor

andryyy commented Apr 13, 2020

We initialize the tzdata always via PHP-FPM. No matter what you set it to. You probably made a mistake somewhere along your tries or did not properly cleanup the volumes (I always read "freshly installed" but everyone seems to forget the volumes).

It should not happen and you should really check your installation. Make sure you are not using ultra slow disks.

@Elwin00
Copy link

Elwin00 commented Apr 15, 2020

I shutdown mailcow with docker-compose down -v when testing out but could be that I forgot -v in some instances. My setup is a bit complicated so it's possible I got all confused :-)

I just tried out again with a "fresh" install (including checking that the volumes were not left behind!) and it worked (well, kind of, I could log-in), so it's not the TZ info. Thanks for chiming in!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

10 participants