• SolvedFixed
  • [SOLVED] Mail delivery issues for POP/IMAP in latest Grommunio releases

ozy How many connections you see, when you run this command: mysqladmin processlist ?
If you habe only the core components installed, all threads belong to the gromox MySQL database.
And how many mailboxes you have on thy system?

@WalterH I have a 4 users community setup and another 5 user community setup. Both have chat, archive and jitsi installed. Both servers had the same POP/IMAP behavior, and both are up-to-date.

mysqladmin processlist result (on boths machines, above mysql tuning file is setup):

+--------+-----------+-----------------+-----------+---------+-------+----------+------------------+----------+
| Id     | User      | Host            | db        | Command | Time  | State    | Info             | Progress |
+--------+-----------+-----------------+-----------+---------+-------+----------+------------------+----------+
| 16     | grochat   | localhost:48122 | grochat   | Sleep   | 800   |          |                  | 0.000    |
| 20     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 21     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 26     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 39     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 40     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 87     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 88     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 89     | grommunio | localhost       | grommunio | Sleep   | 5     |          |                  | 0.000    |
| 394    | grommunio | localhost       | grommunio | Sleep   | 1009  |          |                  | 0.000    |
| 395    | grommunio | localhost       | grommunio | Sleep   | 1009  |          |                  | 0.000    |
| 1557   | grommunio | localhost       | grommunio | Sleep   | 39201 |          |                  | 0.000    |
| 1612   | grommunio | localhost       | grommunio | Sleep   | 47814 |          |                  | 0.000    |
| 1665   | grommunio | localhost       | grommunio | Sleep   | 40269 |          |                  | 0.000    |
| 4712   | grommunio | localhost       | grommunio | Sleep   | 61201 |          |                  | 0.000    |
| 5912   | grommunio | localhost       | grommunio | Sleep   | 60573 |          |                  | 0.000    |
| 11964  | grommunio | localhost       | grommunio | Sleep   | 57601 |          |                  | 0.000    |
| 19222  | grommunio | localhost       | grommunio | Sleep   | 54001 |          |                  | 0.000    |
| 26473  | grommunio | localhost       | grommunio | Sleep   | 50401 |          |                  | 0.000    |
| 33724  | grommunio | localhost       | grommunio | Sleep   | 46801 |          |                  | 0.000    |
| 40972  | grommunio | localhost       | grommunio | Sleep   | 43201 |          |                  | 0.000    |
| 48217  | grommunio | localhost       | grommunio | Sleep   | 39601 |          |                  | 0.000    |
| 55462  | grommunio | localhost       | grommunio | Sleep   | 36001 |          |                  | 0.000    |
| 62705  | grommunio | localhost       | grommunio | Sleep   | 32401 |          |                  | 0.000    |
| 69963  | grommunio | localhost       | grommunio | Sleep   | 28801 |          |                  | 0.000    |
| 77214  | grommunio | localhost       | grommunio | Sleep   | 25201 |          |                  | 0.000    |
| 84460  | grommunio | localhost       | grommunio | Sleep   | 21601 |          |                  | 0.000    |
| 91696  | grommunio | localhost       | grommunio | Sleep   | 18001 |          |                  | 0.000    |
| 98929  | grommunio | localhost       | grommunio | Sleep   | 14401 |          |                  | 0.000    |
| 106171 | grommunio | localhost       | grommunio | Sleep   | 10801 |          |                  | 0.000    |
| 113405 | grommunio | localhost       | grommunio | Sleep   | 7201  |          |                  | 0.000    |
| 120651 | grommunio | localhost       | grommunio | Sleep   | 3601  |          |                  | 0.000    |
| 121965 | grochat   | localhost:55942 | grochat   | Sleep   | 247   |          |                  | 0.000    |
| 125583 | grochat   | localhost:34004 | grochat   | Sleep   | 10    |          |                  | 0.000    |
| 127892 | grommunio | localhost       | grommunio | Sleep   | 1     |          |                  | 0.000    |
| 127897 | root      | localhost       |           | Query   | 0     | starting | show processlist | 0.000    |
+--------+-----------+-----------------+-----------+---------+-------+----------+------------------+----------+

My best guess about the problem:
gromox keeps the mysql connections open, ie in TIME_WAIT state, and mysql drops the connection after net_read_timeout and net_write_timeout is reached, which is 5 sec by default.
Since mysql doesn't store anything else than configuration, I guess the "notify" process from midb for POP/IMAP is not launched since the code path is not reached when mysql errors occur.

Indeed, the mysql tuning set, gromox will still have timeouts with mysql after the configured wait time, but at least it's a "hotfix".

    ozy

    It definitely went down.

    armitage:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:0
    mysqld.log-20240821.xz:33
    mysqld.log-20240822.xz:31
    mysqld.log-20240823.xz:28
    armitage:/var/log/mysql # 
    
    gromi:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:5
    mysqld.log-20240821.xz:26
    mysqld.log-20240822.xz:26
    mysqld.log-20240823.xz:25
    gromi:/var/log/mysql # 
    
    gromi:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:0
    mysqld.log-20240821.xz:25
    mysqld.log-20240822.xz:25
    mysqld.log-20240823.xz:24
    gromi:/var/log/mysql # 
    
    server-grommunio:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:15
    mysqld.log-20240821.xz:34
    mysqld.log-20240822.xz:37
    mysqld.log-20240823.xz:34
    server-grommunio:/var/log/mysql # 
    
    gromi:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:0
    mysqld.log-20240821.xz:25
    mysqld.log-20240822.xz:25
    mysqld.log-20240823.xz:25
    gromi:/var/log/mysql # 
    
    gromi:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:0
    mysqld.log-20240821.xz:26
    mysqld.log-20240822.xz:27
    mysqld.log-20240823.xz:28
    gromi:/var/log/mysql # 
    
    gromi:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:0
    mysqld.log-20240821.xz:25
    mysqld.log-20240822.xz:25
    mysqld.log-20240823.xz:25
    gromi:/var/log/mysql # 
    
    gromi:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:0
    mysqld.log-20240821.xz:30
    mysqld.log-20240822.xz:27
    mysqld.log-20240823.xz:30
    gromi:/var/log/mysql # 
    
    gromi:/var/log/mysql # xzgrep -c Warning *
    mysqld.log:0
    mysqld.log-20240820.xz:24
    mysqld.log-20240821.xz:24
    mysqld.log-20240822.xz:32
    mysqld.log-20240823.xz:26
    gromi:/var/log/mysql # 

    @jengelh Could you maybe tell us why this happens or if it's already in the works to be fixed?

    Also G-Web performs better when this modification is in place.

    My results: on two server, this modification works perfect and the connection errors are gone. On a third server, Postfix can't access the virtual lookup tables in DB. Currently I did not have time to debug this, so I removed the configuration file from this server. Will post the results within the next days.

    When you encounter postfix lookup errors, there are 2 options:

    1. remove this line skip_name_resolve=ON from /etc/my.cnf.d/grommunio.cnfand restart mariadb and postfix.

    2. verify this 4 Postfix lookup files:

      ls -1 /etc/postfix/grommunio-*.cf | sort
      /etc/postfix/grommunio-bcc-forwards.cf
      /etc/postfix/grommunio-virtual-mailbox-alias-maps.cf
      /etc/postfix/grommunio-virtual-mailbox-domains.cf
      /etc/postfix/grommunio-virtual-mailbox-maps.cf

      cat /etc/postfix/grommunio-*.cf | grep hosts
      The hosts string must be localhost like: hosts = localhost, if you see 127.0.0.1 change ist to localhost and restart mariadb and postfix.
      Reason: skip_name_resolve=ON disables name resolution for Maria DB, so 127.0.0.1 do not get resolved as localhost any longer.

    • crpb replied to this.

      WalterH Reason: skip_name_resolve=ON disables name resolution for Maria DB, so 127.0.0.1 do not get resolved as localhost any longer.

      even localhost? oh... should have read a bit further i guess 😛.

      Fixed my config above.....

      So I would like to cautiously throw my results into the round that the mysql tuning options on my server Rocky Linux 9.4 - aarch64) do not lead to the desired success. The mails still arrive every 10 minutes late (see midb.cfg)

      I have created the following entry:
      /etc/my.cnf.d/grommunio.cnf

      [mariadb]
      innodb_buffer_pool_size=1G
      max_allowed_packet=256M
      net_read_timeout=3600
      net_write_timeout=3600
      read_rnd_buffer_size=8M
      skip_name_resolve=ON
      sort_buffer_size=8M
      table_cache=1000
      thread_cache_size=512 #this value is not adopted from the configuration file in my case, I then set it myself in mariadb to be able to test it
      wait_timeout=288000

      The settings in /etc/gromox/midb.cfg

      midb_cache_interval=5minutes
      midb_reload_interval=10minutes

      are still in place.

      On a positive note, the mysql [Warning]s have actually disappeared.

      (sorry for writing in German in the first place ...)

      It isn't persistent for me aswell... laggs are happening again.. 🙁

        So my MySQL tuning above doesn't resolve entirely the problem, it just makes the POP/IMAP delays happen way more less, so there's definitly room for improvement.

        I still get a couple mysql errors:

        2024-08-26 10:07:45 7 [Warning] Aborted connection 7 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
        2024-08-26 10:07:45 9 [Warning] Aborted connection 9 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
        2024-08-26 11:07:45 54 [Warning] Aborted connection 54 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
        2024-08-26 12:07:45 89 [Warning] Aborted connection 89 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
        2024-08-26 13:07:45 105 [Warning] Aborted connection 105 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
        2024-08-26 14:07:45 132 [Warning] Aborted connection 132 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)

        I'll try a bit more tuning. Currently trying to raise connect_timeout.

        crpb
        What is not persistent for you?
        The "thread_cache_size" entry?

        @ozy for me it sadly does not change anything.
        The first mail after restart is instant, the others are delayed around 10 mins.

          GeneralProbe

          how the mails show up in imap. well, new mails seems to come in ok. read/unread status seems a bit fonky..

          today I see the "[Warning] Aborted connection" again for all three servers.

          @crpb Not persistent for me too. There must be some side effect somewhere which is triggered by restarting mysql.
          I've implemented the midb cache/reload settings too meanwhile.

          Still, server runs faster with the mysql settings.
          The final settings I use which don't show any other connections error since 2 hours:
          Note that I added connect_timeout which seems to handle the remaining errors.

          [mysqld]
          table_cache             = 1000
          innodb_buffer_pool_size = 1G
          read_rnd_buffer_size    = 8M
          sort_buffer_size        = 8M
          max_allowed_packet      = 256M
          innodb_log_file_size    = 256M
          wait_timeout            = 288000
          innodb-file-per-table   = 1
          net_read_timeout        = 3600
          net_write_timeout       = 3600
          connect_timeout         = 3600

            So the above mysql tuning with connect_timout set does not produce any errors since 6 hours.

            Strange part is, POP/IMAP has no delay with these setups for a while, and then fades back to delays defined by midb reload/cache settings.
            There's definitly some relation, but I can't understand which one.

            Sorry if I suggested this completely solves the delay issues, but I guess it will help diagnose them somehow.

            Right,

            2024-08-26 11:02:45 0 [Note] Starting MariaDB 10.5.22-MariaDB source revision 7e650253dc488debcb0898ebe6d385bf6dfa3656 as process 992
            2024-08-26 11:02:45 0 [Note] InnoDB: Uses event mutexes
            2024-08-26 11:02:45 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
            2024-08-26 11:02:45 0 [Note] InnoDB: Number of pools: 1
            2024-08-26 11:02:45 0 [Note] InnoDB: Using ARMv8 crc32 + pmull instructions
            2024-08-26 11:02:45 0 [Note] InnoDB: Using Linux native AIO
            2024-08-26 11:02:45 0 [Note] InnoDB: Initializing buffer pool, total size = 1073741824, chunk size = 134217728
            2024-08-26 11:02:45 0 [Note] InnoDB: Completed initialization of buffer pool
            2024-08-26 11:02:45 0 [Note] InnoDB: 128 rollback segments are active.
            2024-08-26 11:02:45 0 [Note] InnoDB: Creating shared tablespace for temporary tables
            2024-08-26 11:02:45 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
            2024-08-26 11:02:45 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
            2024-08-26 11:02:45 0 [Note] InnoDB: 10.5.22 started; log sequence number 658220; transaction id 1920
            2024-08-26 11:02:45 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
            2024-08-26 11:02:45 0 [Note] Plugin 'FEEDBACK' is disabled.
            2024-08-26 11:02:45 0 [Note] Server socket created on IP: '::1'.
            2024-08-26 11:02:45 0 [Note] InnoDB: Buffer pool(s) load completed at 240826 11:02:45
            2024-08-26 11:02:46 0 [Warning] 'proxies_priv' entry '@% root@mail.example.com' ignored in --skip-name-resolve mode.
            2024-08-26 11:02:46 0 [Note] Reading of all Master_info entries succeeded
            2024-08-26 11:02:46 0 [Note] Added new Master_info '' to hash table
            2024-08-26 11:02:46 0 [Note] /usr/libexec/mariadbd: ready for connections.
            Version: '10.5.22-MariaDB'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server

            that's my log.

            But I do get the delays just after receiving the first mail.

            © 2020-2024 grommunio GmbH. All rights reserved. | https://grommunio.com | Data Protection | Legal notice