RoundCube gives 504 Gateway Time-out on fresh install

rcshoemaker · August 6, 2023, 4:48am

Hi all,

First time MAIB user here.
What does work:

I have everything up and running.
I can send and receive email via IMAP/SMTP to a gmail address.
Admin portal works.
All SSL certificates from Let’sEncrypt

What doesn’t work:
Logging in to RoundCube.

Details:
I am able to get to the login page at MyDomain Login, but then clicking “Login” times out and takes me to an error page showing “504 Gateway Time-out | nginx”.

Looking at the nginx error logs, here are the last 2 repeating errors (ips and domains obscured):

<Apparently, I can’t post logs without getting the error that new users can’t post multiple links in a post>

I appreciate your time. Let me know if this makes sense to anyone.

rcshoemaker · August 6, 2023, 4:50am

Pic of logs, sorry the forum won’t let me post the text directly.

system · August 13, 2023, 4:50am

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.

alento · September 17, 2023, 9:41pm

Reopening as I am having the same issue.

@rcshoemaker did you ever resolve this issue? Which provider are you using?

An observation – the timeout only occurs when you enter a correct password. This is on a Contabo VM.

alento · September 18, 2023, 2:10pm

Interesting development … today, after nightly maintenance, all works fine.

scheeeli · November 7, 2023, 1:45pm

I an having the same issue. Have been for a while now and still not sure what is wrong. I was on v64 but just upgraded to v65 and still get the 504 error on RoundCube login when the correct password is used.

Does anyone have a solution for this???

dms · November 7, 2023, 5:25pm

So, this error was already occurring on v64 and continues to occur after upgrading to v65?
Can you log into the admin page?
If so are there any errors in the system status page?
Can you provide the nginx logs of a login attempt?
Have you tried other accounts?
When did this problem begin?
Have you tried multiple clients?

dms · November 7, 2023, 7:00pm

I just spent some time perusing through my MiaB server to see how some of this works. Please take my musings with a grain of salt because some of what I say may be incorrect or lacking important details, but here’s what I see.

The web mail connects to the server internally as an imap client. Furthermore, it appears on my system that this connection to the imap service is using IPv6 locally. Now, the 504 timeout means the nginx server is timing out waiting on another service. So, it’s possible that nginx is timing out waiting on the response from the imap service.

You might be able to investigate this avenue on the server, using networking tools such as netstat, iptables and tcpdump to try to determine if roundcube is just unable to connect to imap in whatever way it’s trying, e.g., by using an interface that imap isn’t listening on or some firewall/fail2ban rules blocking the traffic. That sort of thing.

I hope some of this is helpful, and I haven’t led you down a wrong path.

dms · November 7, 2023, 7:02pm

Sorry, that was a really long-winded response, but the summary is, if I were you, I’d first look at whether roundcube is able to connect to the imap service, and if not, then try to find out why.

scheeeli · November 7, 2023, 7:04pm

Yes it was occurring even before the upgrade but I really don’t know when it started. I don’t use RoundCube much myself but it was another use on the who reported the problem to me and I have tried multiple browsers and always get the error but only when attempting to login with a valid username and password.

I can login to that admin fine and there are no errors on the system status page. I can check mail using IMAP on all these accounts to but cannot login to a single on on RoundCube.

scheeeli · November 7, 2023, 7:08pm

here is what is listening root@mail001:~# netstat -natp
Active Internet connections Proto Recv-Q Send-Q Local Address tcp 0 0 127.0.0.1:8893 tcp 0 0 127.0.0.1:8891 tcp 0 0 127.0.0.1:8952 tcp 0 0 0.0.0.0:587 tcp 0 0 127.0.0.1:953 tcp 0 0 127.0.0.1:953 tcp 0 0 127.0.0.1:10222 tcp 0 0 127.0.0.1:10023 tcp 0 0 127.0.0.1:10026 tcp 0 0 127.0.0.1:10025 tcp 0 0 5.161.187.163:53 tcp 0 0 0.0.0.0:995 tcp 0 0 0.0.0.0:993 tcp 0 0 0.0.0.0:25 tcp 0 0 127.0.0.1:143 tcp 0 0 0.0.0.0:4190 tcp 0 0 0.0.0.0:80 tcp 0 0 127.0.0.1:53 tcp 0 0 127.0.0.1:53 tcp 0 0 0.0.0.0:2200 tcp 0 0 0.0.0.0:443 tcp 0 0 127.0.0.1:5432 tcp 0 0 0.0.0.0:465 tcp6 0 0 :::587 tcp6 0 0 ::1:8952 tcp6 0 0 :::4949 tcp6 0 0 :::995 tcp6 0 0 :::993 tcp6 0 0 :::25 tcp6 0 0 :::4190 tcp6 0 0 :::80 tcp6 0 0 :::2200 tcp6 0 0 ::1:5432 tcp6 0 0 :::443 tcp6 0 0 :::465 tcp6 0 0 2a01:4ff:f0:200e::1:53 on netstat…
(servers and established)
Foreign Address State PID/Program name
0.0.0.0:* LISTEN 1551700/opendmarc
0.0.0.0:* LISTEN 1554284/opendkim
0.0.0.0:* LISTEN 705/nsd
0.0.0.0:* LISTEN 1552292/master
0.0.0.0:* LISTEN 1549865/named
0.0.0.0:* LISTEN 1549865/named
0.0.0.0:* LISTEN 1552910/python
0.0.0.0:* LISTEN 1550772/postgrey –
0.0.0.0:* LISTEN 1552356/dovecot
0.0.0.0:* LISTEN 1552571/perl
0.0.0.0:* LISTEN 705/nsd
0.0.0.0:* LISTEN 1552356/dovecot
0.0.0.0:* LISTEN 1552356/dovecot
0.0.0.0:* LISTEN 1552292/master
0.0.0.0:* LISTEN 1552356/dovecot
0.0.0.0:* LISTEN 1552356/dovecot
0.0.0.0:* LISTEN 1552414/nginx: mast
0.0.0.0:* LISTEN 1549865/named
0.0.0.0:* LISTEN 1549865/named
0.0.0.0:* LISTEN 766/sshd: /usr/sbin
0.0.0.0:* LISTEN 1552414/nginx: mast
0.0.0.0:* LISTEN 815/postgres
0.0.0.0:* LISTEN 1552292/master
:::* LISTEN 1552292/master
:::* LISTEN 705/nsd
:::* LISTEN 1553430/perl
:::* LISTEN 1552356/dovecot
:::* LISTEN 1552356/dovecot
:::* LISTEN 1552292/master
:::* LISTEN 1552356/dovecot
:::* LISTEN 1552414/nginx: mast
:::* LISTEN 766/sshd: /usr/sbin
:::* LISTEN 815/postgres
:::* LISTEN 1552414/nginx: mast
:::* LISTEN 1552292/master
:::* LISTEN 705/nsd

dms · November 7, 2023, 7:17pm

Try this: log into your MiaB server and run the following tcpdump command, and while it’s running, attempt to log into your web mail. So, here’s what I ran, and then what I saw (at least a short snippet of it) when I logged into web mail:

sudo tcpdump -i lo port 993

Now, do the web mail login…

And this is what comes out under my tcpdump command:

11:12:47.197881 IP6 localhost.53672 > localhost.imaps: Flags [S], seq 89971811, win 65476, options [mss 65476,sackOK,TS val 1244492844 ecr 0,nop,wscale 7], length 0
11:12:47.197894 IP6 localhost.imaps > localhost.53672: Flags [S.], seq 69462281, ack 89971812, win 65464, options [mss 65476,sackOK,TS val 1244492844 ecr 1244492844,nop,wscale 7], length 0
11:12:47.197906 IP6 localhost.53672 > localhost.imaps: Flags [.], ack 1, win 512, options [nop,nop,TS val 1244492844 ecr 1244492844], length 0
11:12:47.204383 IP6 localhost.53672 > localhost.imaps: Flags [P.], seq 1:518, ack 1, win 512, options [nop,nop,TS val 1244492851 ecr 1244492844], length 517
...

And that goes on for many lines. If you can do that, you can at least determine if that imap connection is ever getting done.

Note: this command assumes you have an lo and an eth0 interface. If you don’t see anything running the command on the lo interface, then try it with the eth0 interface.

scheeeli · November 7, 2023, 8:26pm

when I login to RoundCube after running that command I get this output from the command-line:

root@mail001:~# tcpdump -i lo port 993
tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on lo, link-type EN10MB (Ethernet), snapshot length 262144 bytes
15:23:10.053691 IP6 localhost.34752 > localhost.imaps: Flags [S], seq 1417417700, win 65476, options [mss 65476,sackOK,TS val 4207967620 ecr 0,nop,wscale 7], length 0
15:23:10.053704 IP6 localhost.imaps > localhost.34752: Flags [S.], seq 3499389301, ack 1417417701, win 65464, options [mss 65476,sackOK,TS val 4207967620 ecr 4207967620,nop,wscale 7], length 0
15:23:10.053732 IP6 localhost.34752 > localhost.imaps: Flags [.], ack 1, win 512, options [nop,nop,TS val 4207967620 ecr 4207967620], length 0
15:23:10.055473 IP6 localhost.34752 > localhost.imaps: Flags [P.], seq 1:518, ack 1, win 512, options [nop,nop,TS val 4207967621 ecr 4207967620], length 517
15:23:10.055480 IP6 localhost.imaps > localhost.34752: Flags [.], ack 518, win 508, options [nop,nop,TS val 4207967621 ecr 4207967621], length 0
15:23:10.063164 IP6 localhost.imaps > localhost.34752: Flags [P.], seq 1:4550, ack 518, win 512, options [nop,nop,TS val 4207967629 ecr 4207967621], length 4549
15:23:10.063178 IP6 localhost.34752 > localhost.imaps: Flags [.], ack 4550, win 490, options [nop,nop,TS val 4207967629 ecr 4207967629], length 0
15:23:10.064973 IP6 localhost.34752 > localhost.imaps: Flags [P.], seq 518:598, ack 4550, win 512, options [nop,nop,TS val 4207967631 ecr 4207967629], length 80
15:23:10.064985 IP6 localhost.imaps > localhost.34752: Flags [.], ack 598, win 512, options [nop,nop,TS val 4207967631 ecr 4207967631], length 0
15:23:10.065139 IP6 localhost.imaps > localhost.34752: Flags [P.], seq 4550:5060, ack 598, win 512, options [nop,nop,TS val 4207967631 ecr 4207967631], length 510
15:23:10.065164 IP6 localhost.imaps > localhost.34752: Flags [P.], seq 5060:5205, ack 598, win 512, options [nop,nop,TS val 4207967631 ecr 4207967631], length 145
15:23:10.065208 IP6 localhost.34752 > localhost.imaps: Flags [.], ack 5205, win 512, options [nop,nop,TS val 4207967631 ecr 4207967631], length 0
15:23:10.065347 IP6 localhost.34752 > localhost.imaps: Flags [P.], seq 598:683, ack 5205, win 512, options [nop,nop,TS val 4207967631 ecr 4207967631], length 85
15:23:10.065352 IP6 localhost.imaps > localhost.34752: Flags [.], ack 683, win 512, options [nop,nop,TS val 4207967631 ecr 4207967631], length 0
15:23:10.071309 IP6 localhost.imaps > localhost.34752: Flags [P.], seq 5205:5647, ack 683, win 512, options [nop,nop,TS val 4207967637 ecr 4207967631], length 442
15:23:10.071578 IP6 localhost.34752 > localhost.imaps: Flags [P.], seq 683:722, ack 5647, win 512, options [nop,nop,TS val 4207967638 ecr 4207967637], length 39
15:23:10.071585 IP6 localhost.imaps > localhost.34752: Flags [.], ack 722, win 512, options [nop,nop,TS val 4207967638 ecr 4207967638], length 0
15:23:10.071722 IP6 localhost.imaps > localhost.34752: Flags [P.], seq 5647:5753, ack 722, win 512, options [nop,nop,TS val 4207967638 ecr 4207967638], length 106
15:23:10.072761 IP6 localhost.34752 > localhost.imaps: Flags [P.], seq 722:797, ack 5753, win 512, options [nop,nop,TS val 4207967639 ecr 4207967638], length 75
15:23:10.072769 IP6 localhost.imaps > localhost.34752: Flags [.], ack 797, win 512, options [nop,nop,TS val 4207967639 ecr 4207967639], length 0
15:23:10.073501 IP6 localhost.imaps > localhost.34752: Flags [P.], seq 5753:6019, ack 797, win 512, options [nop,nop,TS val 4207967639 ecr 4207967639], length 266
15:23:10.116566 IP6 localhost.34752 > localhost.imaps: Flags [.], ack 6019, win 512, options [nop,nop,TS val 4207967683 ecr 4207967639], length 0

That means it’s connecting to the IMAP server, right?

dms · November 7, 2023, 8:53pm

Yes, that looks like what I get and I agree, it’s connecting to IMAP. So much for that theory.

Well, at least we’ve eliminated one potential issue. Do you see anything of use in the nginx access or error logs for that login attempt?

scheeeli · November 7, 2023, 9:09pm

here is the log file output from the login attempt (I changed the TLD to XXXXXXXX for privacy).

root@mail001:~# tail /var/log/nginx/access.log
2601:4c2:4200:f510:4821:d1d9:b442:7c3b - - [07/Nov/2023:16:00:23 -0500] "GET /mail/ HTTP/2.0" 200 2610 "https://mail001.XXXXXXXXXXXXXX.com/admin/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36"
2601:4c2:4200:f510:4821:d1d9:b442:7c3b - - [07/Nov/2023:16:02:10 -0500] "POST /mail/?_task=login HTTP/2.0" 504 562 "https://mail001.XXXXXXXXXXXXX.com/mail/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36"

root@mail001:~# tail /var/log/nginx/error.log
2023/11/07 16:02:10 [error] 1552416#1552416: *2422 upstream timed out (110: Unknown error) while reading response header from upstream, client: 2601:4c2:4200:f510:4821:d1d9:b442:7c3b, server: mail001.XXXXXXXXXXXXX.com, request: "POST /mail/?_task=login HTTP/2.0", upstream: "fastcgi://unix:/var/run/php/php8.0-fpm.sock", host: "mail001.XXXXXXXXXXXXX.com", referrer: "https://mail001.XXXXXXXXXXXXXX.com/mail/"

dms · November 7, 2023, 9:45pm

Sorry, I’m stumped with what I see here. On one hand, it seems to be connecting successfully to the imap server. But according to your nginx logs, the “login” task is what’s timing out.

Everything I know about this I’ve learned today, so I’m certainly no expert. Maybe someone else who knows more about the login logic flows can provide some insight.
Otherwise, my only advice would be to sift through all the logs looking for hints, make sure your server is otherwise healthy (like not out of disk space), playing around with tcpdump, etc.

If it were me and I was desperate to get to the bottom of this, I would probably start adding “printf-debugging” to the php files that are running during the login process so I could trace through the logs exactly what’s happening. But that’s a desperate measure that requires special skills.

scheeeli · November 7, 2023, 11:01pm

One skill I do have is debugging PHP scripts but I’m not at all familiar with MIAB or even nginx (I use apache on all my web-servers).

Where would I even find the PHP code of the mail admin, or more specifically, the /mail/ virtual directory that RoundCube is in (I’m embarrassed to say that I cannot find it)?

scheeeli · November 7, 2023, 11:42pm

I just figured out that I could login if I use my IP address in the URL instead of the FQDN, so I started looking for anything that would interfere with the DNS resolution of the domain and found the FQDN in the /etc/hosts file with the local IP of 127.0.0.1 and when I removed that line it all works perfectly now.

Problem solved!

LAVenetz · March 22, 2024, 4:49pm

Hi, it did not help for me! I had to reconfigure Miab because my ISP changed my IP. Before that I never had troubles with RoundCube !!! And now, I have no solution for that. But ThunderBird is working well.