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

Authentication very slow (7-11 sec) #5645

Closed
5 tasks done
mkrecek234 opened this issue Jan 17, 2024 · 12 comments
Closed
5 tasks done

Authentication very slow (7-11 sec) #5645

mkrecek234 opened this issue Jan 17, 2024 · 12 comments
Labels

Comments

@mkrecek234
Copy link

mkrecek234 commented Jan 17, 2024

Contribution guidelines

I've found a bug and checked that ...

  • ... I understand that not following the below instructions will result in immediate closure and/or deletion of my issue.
  • ... I have understood that this bug report is dedicated for bugs, and not for support-related inquiries.
  • ... 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

Since a few months, the authentication of Mailcow UI is very slow. In the logs, I can see that this event takes about 7sec, sometimes 11sec.

Seen on Google Chrome and Safari in the same way.

Logs:

17.01.2024, 22:35:51	success	2AD8BE	luxadmin	admin	2a09:bac2:2a7e:1e1::30:4c	"verified_totp_login"
17.01.2024, 22:35:43	info	622707	unauthenticated	unauthenticated	2a09:bac2:2a7e:1e1::30:4c	"awaiting_tfa_confirmation"

You can see that there are 8 seconds between awaiting_tfa_confirmation and verified_totp_login.
This issue also exists if there is no two-factor login what I can see with other logins.

Steps to reproduce:

I did a usual install on Ubuntu and always updated Mailcow to the latest version over time.
Steps to reproduce: Just login

Which branch are you using?

master

Operating System:

Ubuntu 22.04

Server/VM specifications:

AMD EPYC 7282 16-Core Processor, 6 cores, 16 GB

Is Apparmor, SELinux or similar active?

no

Virtualization technology:

None

Docker version:

24.0.7, build afdd53b

docker-compose version or docker compose version:

1.29.2, build unknown

mailcow version:

2024-01

Reverse proxy:

Apache

Logs of git diff:

No

Logs of iptables -L -vn:

# Warning: iptables-legacy tables present, use iptables-legacy to see them
Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
 217K  107M MAILCOW    all  --  *      *       0.0.0.0/0            0.0.0.0/0            /* mailcow */
  21M 1166M f2b-sshd   tcp  --  *      *       0.0.0.0/0            0.0.0.0/0            multiport dports 22

Chain FORWARD (policy DROP 1 packets, 64 bytes)
 pkts bytes target     prot opt in     out     source               destination         
 195K   46M MAILCOW    all  --  *      *       0.0.0.0/0            0.0.0.0/0            /* mailcow */
 196K   47M DOCKER-USER  all  --  *      *       0.0.0.0/0            0.0.0.0/0           
 196K   47M DOCKER-ISOLATION-STAGE-1  all  --  *      *       0.0.0.0/0            0.0.0.0/0           
 120K   34M ACCEPT     all  --  *      br-mailcow  0.0.0.0/0            0.0.0.0/0            ctstate RELATED,ESTABLISHED
 9117  571K DOCKER     all  --  *      br-mailcow  0.0.0.0/0            0.0.0.0/0           
26802 4854K ACCEPT     all  --  br-mailcow !br-mailcow  0.0.0.0/0            0.0.0.0/0           
 8990  563K ACCEPT     all  --  br-mailcow br-mailcow  0.0.0.0/0            0.0.0.0/0           
6138K 1395M ACCEPT     all  --  *      br-512ff54df376  0.0.0.0/0            0.0.0.0/0            ctstate RELATED,ESTABLISHED
89726 5384K DOCKER     all  --  *      br-512ff54df376  0.0.0.0/0            0.0.0.0/0           
 5617  575K ACCEPT     all  --  br-512ff54df376 !br-512ff54df376  0.0.0.0/0            0.0.0.0/0           
89726 5384K ACCEPT     all  --  br-512ff54df376 br-512ff54df376  0.0.0.0/0            0.0.0.0/0           
 1396  253K 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           
 1507  132K 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 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         

Chain DOCKER (3 references)
 pkts bytes target     prot opt in     out     source               destination         
    0     0 ACCEPT     tcp  --  !br-512ff54df376 br-512ff54df376  0.0.0.0/0            172.18.0.5           tcp dpt:8088
    0     0 ACCEPT     tcp  --  !docker0 docker0  0.0.0.0/0            172.17.0.2           tcp dpt:9980
    0     0 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.3           tcp dpt:8983
    0     0 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.249         tcp dpt:6379
    0     0 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.6           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
    1    40 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.250         tcp dpt:995
  104  6656 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.250         tcp dpt:993
    7   448 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.8           tcp dpt:9443
    0     0 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.8           tcp dpt:9080
    0     0 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.253         tcp dpt:587
    2   120 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.253         tcp dpt:465
   13   724 ACCEPT     tcp  --  !br-mailcow br-mailcow  0.0.0.0/0            172.22.1.253         tcp dpt:25

Chain DOCKER-ISOLATION-STAGE-1 (1 references)
 pkts bytes target     prot opt in     out     source               destination         
26802 4854K DOCKER-ISOLATION-STAGE-2  all  --  br-mailcow !br-mailcow  0.0.0.0/0            0.0.0.0/0           
 5617  575K DOCKER-ISOLATION-STAGE-2  all  --  br-512ff54df376 !br-512ff54df376  0.0.0.0/0            0.0.0.0/0           
 1507  132K DOCKER-ISOLATION-STAGE-2  all  --  docker0 !docker0  0.0.0.0/0            0.0.0.0/0           
  94M   16G RETURN     all  --  *      *       0.0.0.0/0            0.0.0.0/0           

Chain DOCKER-ISOLATION-STAGE-2 (3 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  --  *      br-512ff54df376  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           
2195K 1356M 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         
  94M   16G 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         

Chain f2b-sshd (1 references)
 pkts bytes target     prot opt in     out     source               destination         
   12   944 REJECT     all  --  *      *       143.198.43.241       0.0.0.0/0            reject-with icmp-port-unreachable
   17  1344 REJECT     all  --  *      *       62.105.137.105       0.0.0.0/0            reject-with icmp-port-unreachable
   19  1508 REJECT     all  --  *      *       162.241.90.222       0.0.0.0/0            reject-with icmp-port-unreachable
   17  1584 REJECT     all  --  *      *       61.177.172.160       0.0.0.0/0            reject-with icmp-port-unreachable
   22  1648 REJECT     all  --  *      *       134.209.100.51       0.0.0.0/0            reject-with icmp-port-unreachable
   23  1740 REJECT     all  --  *      *       103.130.212.105      0.0.0.0/0            reject-with icmp-port-unreachable
   69  4140 REJECT     all  --  *      *       161.97.68.152        0.0.0.0/0            reject-with icmp-port-unreachable
   31  2264 REJECT     all  --  *      *       134.175.122.148      0.0.0.0/0            reject-with icmp-port-unreachable
   22  1532 REJECT     all  --  *      *       36.64.68.99          0.0.0.0/0            reject-with icmp-port-unreachable
   54  3652 REJECT     all  --  *      *       40.115.18.231        0.0.0.0/0            reject-with icmp-port-unreachable
  21M 1157M RETURN     all  --  *      *       0.0.0.0/0            0.0.0.0/0

Logs of ip6tables -L -vn:

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         

Chain FORWARD (policy DROP 18 packets, 1080 bytes)
 pkts bytes target     prot opt in     out     source               destination         
53669   35M MAILCOW    all      *      *       ::/0                 ::/0                 /* mailcow */
55256   35M DOCKER-USER  all      *      *       ::/0                 ::/0                
55256   35M DOCKER-ISOLATION-STAGE-1  all      *      *       ::/0                 ::/0                
33869   32M ACCEPT     all      *      br-mailcow  ::/0                 ::/0                 ctstate RELATED,ESTABLISHED
 5994  411K DOCKER     all      *      br-mailcow  ::/0                 ::/0                
15393 2169K ACCEPT     all      br-mailcow !br-mailcow  ::/0                 ::/0                
 5989  411K ACCEPT     all      br-mailcow br-mailcow  ::/0                 ::/0                
    3   379 ACCEPT     all      *      docker0  ::/0                 ::/0                 ctstate RELATED,ESTABLISHED
  241 15996 DOCKER     all      *      docker0  ::/0                 ::/0                
    3   304 ACCEPT     all      docker0 !docker0  ::/0                 ::/0                
  241 15996 ACCEPT     all      docker0 docker0  ::/0                 ::/0                

Chain OUTPUT (policy ACCEPT 0 packets, 0 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                 fd4d:6169:6c63:6f77::b  tcp dpt:4190
    0     0 ACCEPT     tcp      !br-mailcow br-mailcow  ::/0                 fd4d:6169:6c63:6f77::b  tcp dpt:995
    5   420 ACCEPT     tcp      !br-mailcow br-mailcow  ::/0                 fd4d:6169:6c63:6f77::b  tcp dpt:993
    0     0 ACCEPT     tcp      !br-mailcow br-mailcow  ::/0                 fd4d:6169:6c63:6f77::b  tcp dpt:143
    0     0 ACCEPT     tcp      !br-mailcow br-mailcow  ::/0                 fd4d:6169:6c63:6f77::b  tcp dpt:110
    0     0 ACCEPT     tcp      !br-mailcow br-mailcow  ::/0                 fd4d:6169:6c63:6f77::f  tcp dpt:587
    0     0 ACCEPT     tcp      !br-mailcow br-mailcow  ::/0                 fd4d:6169:6c63:6f77::f  tcp dpt:465
    0     0 ACCEPT     tcp      !br-mailcow br-mailcow  ::/0                 fd4d:6169:6c63:6f77::f  tcp dpt:25

Chain DOCKER-ISOLATION-STAGE-1 (1 references)
 pkts bytes target     prot opt in     out     source               destination         
15393 2169K DOCKER-ISOLATION-STAGE-2  all      br-mailcow !br-mailcow  ::/0                 ::/0                
    0     0 DOCKER-ISOLATION-STAGE-2  all      br-512ff54df376 !br-512ff54df376  ::/0                 ::/0                
    3   304 DOCKER-ISOLATION-STAGE-2  all      docker0 !docker0  ::/0                 ::/0                
  15M 7605M RETURN     all      *      *       ::/0                 ::/0                

Chain DOCKER-ISOLATION-STAGE-2 (3 references)
 pkts bytes target     prot opt in     out     source               destination         
    0     0 DROP       all      *      br-mailcow  ::/0                 ::/0                
    0     0 DROP       all      *      br-512ff54df376  ::/0                 ::/0                
    0     0 DROP       all      *      docker0  ::/0                 ::/0                
 398K  121M RETURN     all      *      *       ::/0                 ::/0                

Chain DOCKER-USER (1 references)
 pkts bytes target     prot opt in     out     source               destination         
  15M 7605M RETURN     all      *      *       ::/0                 ::/0                

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

Logs of iptables -L -vn -t nat:

# Warning: iptables-legacy tables present, use iptables-legacy to see them
Chain PREROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
 901K   53M DOCKER     all  --  *      *       0.0.0.0/0            0.0.0.0/0            ADDRTYPE match dst-type LOCAL

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
 2838  170K DOCKER     all  --  *      *       0.0.0.0/0           !127.0.0.0/8          ADDRTYPE match dst-type LOCAL

Chain POSTROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
 7897  575K MASQUERADE  all  --  *      !br-mailcow  172.22.1.0/24        0.0.0.0/0           
   92  5520 MASQUERADE  all  --  *      !br-512ff54df376  172.18.0.0/16        0.0.0.0/0           
  842 75131 MASQUERADE  all  --  *      !docker0  172.17.0.0/16        0.0.0.0/0           
    0     0 MASQUERADE  tcp  --  *      *       172.18.0.5           172.18.0.5           tcp dpt:8088
    0     0 MASQUERADE  tcp  --  *      *       172.17.0.2           172.17.0.2           tcp dpt:9980
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.3           172.22.1.3           tcp dpt:8983
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.249         172.22.1.249         tcp dpt:6379
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.6           172.22.1.6           tcp dpt:3306
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.250         172.22.1.250         tcp dpt:12345
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.250         172.22.1.250         tcp dpt:4190
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.250         172.22.1.250         tcp dpt:995
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.250         172.22.1.250         tcp dpt:993
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.250         172.22.1.250         tcp dpt:143
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.250         172.22.1.250         tcp dpt:110
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.8           172.22.1.8           tcp dpt:9443
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.8           172.22.1.8           tcp dpt:9080
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.253         172.22.1.253         tcp dpt:587
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.253         172.22.1.253         tcp dpt:465
    0     0 MASQUERADE  tcp  --  *      *       172.22.1.253         172.22.1.253         tcp dpt:25

Chain DOCKER (2 references)
 pkts bytes target     prot opt in     out     source               destination         
    1    60 RETURN     all  --  br-mailcow *       0.0.0.0/0            0.0.0.0/0           
  290 17400 RETURN     all  --  br-512ff54df376 *       0.0.0.0/0            0.0.0.0/0           
    2   120 RETURN     all  --  docker0 *       0.0.0.0/0            0.0.0.0/0           
    0     0 DNAT       tcp  --  !br-512ff54df376 *       0.0.0.0/0            127.0.0.1            tcp dpt:8088 to:172.18.0.5:8088
    0     0 DNAT       tcp  --  !docker0 *       0.0.0.0/0            127.0.0.1            tcp dpt:9980 to:172.17.0.2:9980
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            127.0.0.1            tcp dpt:18983 to:172.22.1.3:8983
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            127.0.0.1            tcp dpt:7654 to:172.22.1.249:6379
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            127.0.0.1            tcp dpt:13306 to:172.22.1.6:3306
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            127.0.0.1            tcp dpt:19991 to:172.22.1.250:12345
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:4190 to:172.22.1.250:4190
    1    40 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:995 to:172.22.1.250:995
  104  6656 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:993 to:172.22.1.250:993
    7   448 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:143 to:172.22.1.250:143
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:110 to:172.22.1.250:110
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            127.0.0.1            tcp dpt:9443 to:172.22.1.8:9443
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            127.0.0.1            tcp dpt:9080 to:172.22.1.8:9080
    0     0 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:587 to:172.22.1.253:587
    2   120 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:465 to:172.22.1.253:465
   13   724 DNAT       tcp  --  !br-mailcow *       0.0.0.0/0            0.0.0.0/0            tcp dpt:25 to:172.22.1.253:25

Logs of ip6tables -L -vn -t nat:

Chain PREROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
51726 4183K DOCKER     all      *      *       ::/0                 ::/0                 ADDRTYPE match dst-type LOCAL

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
17684 1417K DOCKER     all      *      *       ::/0                !::1                  ADDRTYPE match dst-type LOCAL

Chain POSTROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination         
 5543  461K MASQUERADE  all      *      !br-mailcow  fd4d:6169:6c63:6f77::/64  ::/0                
    2   221 MASQUERADE  all      *      !docker0  fd00:dead:beef:c0::/80  ::/0                
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::b  fd4d:6169:6c63:6f77::b  tcp dpt:4190
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::b  fd4d:6169:6c63:6f77::b  tcp dpt:995
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::b  fd4d:6169:6c63:6f77::b  tcp dpt:993
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::b  fd4d:6169:6c63:6f77::b  tcp dpt:143
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::b  fd4d:6169:6c63:6f77::b  tcp dpt:110
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::f  fd4d:6169:6c63:6f77::f  tcp dpt:587
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::f  fd4d:6169:6c63:6f77::f  tcp dpt:465
    0     0 MASQUERADE  tcp      *      *       fd4d:6169:6c63:6f77::f  fd4d:6169:6c63:6f77::f  tcp dpt:25

Chain DOCKER (2 references)
 pkts bytes target     prot opt in     out     source               destination         
   20  1600 RETURN     all      br-mailcow *       ::/0                 ::/0                
    0     0 RETURN     all      docker0 *       ::/0                 ::/0                
    0     0 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:4190 to:[fd4d:6169:6c63:6f77::b]:4190
    0     0 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:995 to:[fd4d:6169:6c63:6f77::b]:995
    5   420 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:993 to:[fd4d:6169:6c63:6f77::b]:993
    0     0 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:143 to:[fd4d:6169:6c63:6f77::b]:143
    0     0 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:110 to:[fd4d:6169:6c63:6f77::b]:110
    0     0 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:587 to:[fd4d:6169:6c63:6f77::f]:587
    0     0 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:465 to:[fd4d:6169:6c63:6f77::f]:465
    0     0 DNAT       tcp      !br-mailcow *       ::/0                 ::/0                 tcp dpt:25 to:[fd4d:6169:6c63:6f77::f]:25

DNS check:

104.18.32.7
172.64.155.249
@mkrecek234 mkrecek234 added the bug label Jan 17, 2024
@mkrecek234 mkrecek234 changed the title Authentication very slo (7 sec) Authentication very slow (7-11 sec) Jan 17, 2024
@beerlao
Copy link

beerlao commented Feb 14, 2024

Is this a permanent issue or does it occur after the mailcow stack is running for some time? I had a similar issue where logins were fast after a fresh start of the stack, but started to take several seconds after some time. In my case this was related to the innodb buffer pool of the mysql db. See details here:

https://dev.mysql.com/doc/refman/8.0/en/innodb-buffer-pool.html

After adjusting the values for innodb_buffer_pool_size, innodb_old_blocks_time, read_rnd_buffer_size and some other the issue went away.

@milkmaker
Copy link
Collaborator

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

@milkmaker milkmaker added the stale Please update the issue with current status, unclear if it's still open/needed. label Apr 15, 2024
@mkrecek234
Copy link
Author

Unfortunately, it also is so extremely slow after a fresh restart, so probably no buffering issue...

@milkmaker milkmaker removed the stale Please update the issue with current status, unclear if it's still open/needed. label Apr 15, 2024
@mrclschstr
Copy link
Contributor

mrclschstr commented Apr 23, 2024

I have recently noticed a similar problem, but mainly when logging in with FIDO2 (fido2_login). Logins can take a good 20 to 30 seconds.

My problem is that I cannot find any logs in connection with the login. In the mailcow UI logs, I can only see that the login was ultimately successful, but not how long the login took.

Any help would be appreciated...

EDIT: Issue is not limited to FIDO2 login and happens without 2FA as well...

EDIT 2: My impression is rather that only the first login takes so long and every further attempt after that works faster again in the short term. Exactly the other way around, so to speak, as described by @beerlao .

@beerlao
Copy link

beerlao commented Apr 25, 2024

I can confirm your observations, I'm still experiencing the problem even after fine tuning the database. The symptoms:

First login takes ages and sometimes runs into the timeout of the reverse proxy.
After the first login, every subsequent login into the same account is fast. At least for some time. If there is no login for some time for this particular account, logging in is slow again.
This problem seems to only be related to the web frontend, not to sogo and not to imap.
I suspect the retrieval of the last logins that are shown in the interface to be slow after some time.

My awful workaround is running the following cronjob every 5 minutes for the affected accounts:

curl -X GET http://localhost:8088/api/v1/get/last-login/$USER/7 -H 'Content-Type:application/json' -H 'X-API-Key:$API_KEY'

This one logs into the account and ask for the last 7 logins.

@mrclschstr
Copy link
Contributor

I can agree 100% with the symptoms described. What surprises me the most is that the problem only seems to exist for some users and not for everyone.

@14wkinnersley
Copy link

I also have this same issue, but only affects 1 user account. Deleting the user account and recreating does not fix it.

@PierrePlt
Copy link
Contributor

PierrePlt commented May 12, 2024

I have the same issue.
I did some tracing and it turns out that when getting /user, 150 requests are made to https://dfdata.bella.network/lookup with an average duration of 90ms each (13.5 seconds total).
This seems to be coming from this line:

curl_setopt($curl, CURLOPT_URL,"https://dfdata.bella.network/lookup/" . $sasl[$k]['real_rip']);

I am not familiar with the mailcow codebase, but I assume this is used to get the country of origin of each IP shown in the login history.
This would also explain why some users have this problem while others don't.

EDIT:
I tried del IP_SHORTCOUNTRY in Redis in an attempt to reproduce the issue with a recently logged-in account, it worked.
This further indicates that this is where the problem is coming from.
Deleting the login history fixes the issue (temporarily).
When deleting the history, connection time goes from 10-25s to 100-200ms.
What I don't understand for now is that a separate call to the json API on /api/v1/get/last-login is supposed to get the login history, this isn't part of what's returned by /user so this shouldn't slow the request down.

@PierrePlt
Copy link
Contributor

PierrePlt commented May 12, 2024

So,
On my side the issue comes from:

'last_login' => last_login('get', $_SESSION['mailcow_cc_username'], 7, 0)['ui']['time']

Which declares the last login as a global variable.
This in turn calls:
function last_login($action, $username, $sasl_limit_days = 7, $ui_offset = 1) {

Which, for each IP used to login in the last 7 days tries to get the cached location in Redis, and calls https://dfdata.bella.network/lookup if the value isn't cached.
At first glance, removing:
'last_login' => last_login('get', $_SESSION['mailcow_cc_username'], 7, 0)['ui']['time']

seems to solve the issue without having any obvious adverse effect.
The corresponding variable:
var last_login = '{{ last_login }}';

doesn't seem to be used anywhere.

A double-check would be welcome, I'd like to know if last_login can be deleted in header.inc.php (and in the twig template) or if I'm missing something.

@14wkinnersley
Copy link

While I dont know if I should remove last_login, I went ahead and removed it. The single user account I had issues with now will login instantly. I did notice when going to the 'App_Passwords' tab or the 'Temporary email aliases tab' it does have a loading screen for about 30 seconds now. But thank you @PierrePlt for the tip. Im leaving it removed for now unless I see any adverse side affects.

@PierrePlt
Copy link
Contributor

I guess the delay when clicking on another tab comes from the call to api/v1/get/last-login that still takes a while even though it's not blocking the loading of the main user page anymore
If you don't need to see the flag next to each IP address I guess you could remove lines 285-311 of functions.inc.php

if (!$sasl[$k]['location']) {
$curl = curl_init();
curl_setopt($curl, CURLOPT_URL,"https://dfdata.bella.network/lookup/" . $sasl[$k]['real_rip']);
curl_setopt($curl, CURLOPT_RETURNTRANSFER, true);
curl_setopt($curl, CURLOPT_USERAGENT, 'Moocow');
curl_setopt($curl, CURLOPT_TIMEOUT, 5);
$ip_data = curl_exec($curl);
if (!curl_errno($curl)) {
$ip_data_array = json_decode($ip_data, true);
if ($ip_data_array !== false and !empty($ip_data_array['location']['shortcountry'])) {
$sasl[$k]['location'] = $ip_data_array['location']['shortcountry'];
try {
$redis->hSet('IP_SHORTCOUNTRY', $sasl[$k]['real_rip'], $ip_data_array['location']['shortcountry']);
}
catch (RedisException $e) {
$_SESSION['return'][] = array(
'type' => 'danger',
'log' => array(__FUNCTION__, $_action, $_data_log),
'msg' => array('redis_error', $e)
);
curl_close($curl);
return false;
}
}
}
curl_close($curl);
}

That's not an acceptable long-term solution, but if the loading time is too big of an issue that should fix it for now

@benniju
Copy link

benniju commented Jun 21, 2024

I have the issue that I move though many different wifi networks throughout the day at university, and my device gets a different IPv6 Addresses every time.
The same also happens when moving though different APs in my home.
Because of this the login history is absolutely flooded with unique IPv6 Addresses and the login/ loading of the history and being able to actually use the page/ other tabs something takes multiple minutes which is really annoying.

Would it be possible that at least only the /64 IPv6 Network gets looked up and cached? Most likely all of the IPs in one /64 are always from one country or even one customer.
I also agree with #5888, not only because it would solve the loading issue, but also because of the privacy reasons.

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

No branches or pull requests

8 participants