postal 3.1.1/3.2.2 drastically dropped email sending rate

[gitbnitin]

My database is as good as it was working with 70 emails/minutes. I just did the postal upgrade to version 3.1.1 and the sending rate went down to 6-8/minutes. I tried upgrading it to 3.2.2 but no luck.

No matter how many workers I add, it doesn't increase. On 2.3.3, it was sending 70/minutes with 4 workers, as soon as I upgraded to 3.1.1/3.2.2 it doesn't even go above 8/minute with 16 workers.

Could someone please help me with this?

[adamcooke]

You'd need to look at your logs and look at load on your system to see which components might be under load.

Just adding workers to a machine that doesn't have the necessary memory and CPU to support it might also be counterproductive.

[gitbnitin]

@adamcooke I am concerned because the same behaviour is seen on 2 different server with drastic decrease in sent rate.

[gitbnitin]

root@mx:~# vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0      0 2525588  27240 649596    0    0     8     4  130  115  2  1 97  0  0
 0  0      0 2525076  27240 649596    0    0     0     0  327  644  1  1 99  0  1
 0  0      0 2524824  27240 649596    0    0     0     0  213  480  1  0 99  0  0
 0  0      0 2524572  27240 649596    0    0     0     0  325  627  2  0 98  0  0
 0  0      0 2524320  27240 649596    0    0     0    14  828 1681  3  1 97  0  0
 0  0      0 2518180  27248 649636    0    0     0    79 1975 3601 13  3 84  0  0
 2  0      0 2517108  27248 649640    0    0     0    22  601 1114  2  1 96  0  0
 0  0      0 2516960  27248 649640    0    0     0     0  375  686  1  1 99  0  0
 0  0      0 2516928  27248 649640    0    0     0     2  338  619  1  0 98  0  0
 0  0      0 2516424  27248 649640    0    0     0     0  533 1006  1  1 98  0  0
 0  0      0 2516180  27248 649640    0    0     0     0  583 1220  2  1 97  0  0
 1  0      0 2514164  27256 649640    0    0     0    60 1435 3602 12  7 81  0  1
 0  0      0 2514164  27256 649640    0    0     0   128  333  548  1  1 98  0  1
 0  0      0 2514196  27256 649640    0    0     0     0  299  596  1  0 99  0  0
 0  0      0 2514024  27256 649640    0    0     0     0  556 1043  1  1 98  0  0
 0  0      0 2513572  27256 649640    0    0     0     0  626 1337  3  1 96  0  0
 0  0      0 2513572  27256 649640    0    0     0     0  195  390  0  1 99  0  0
 0  0      0 2513572  27256 649640    0    0     0    44  367  690  1  0 99  0  0
 0  0      0 2513352  27264 649640    0    0     0    60  356  636  1  1 99  0  0
 1  0      0 2513352  27264 649640    0    0     0     0  489  979  2  1 98  0  0
 2  0      0 2503772  27280 649836    0    0   140     0 1112 2212 13  2 86  0  0
 1  0      0 2503488  27284 649856    0    0    16     1  511 1037  3  0 97  0  0
 0  0      0 2503268  27284 649864    0    0     0    19  662 1330  1  1 98  0  0
 0  0      0 2503016  27284 649864    0    0     0    19  616 1065  5  1 94  0  0
 2  0      0 2502732  27284 649864    0    0     0    12  831 1569  3  1 96  0  0
 0  0      0 2500464  27296 649852    0    0    36    62 1998 3704  8  2 90  0  0
 0  0      0 2499896  27296 649916    0    0     0     0  396  748  1  0 99  0  0
 0  0      0 2499644  27296 649916    0    0     0    25  479  906  2  0 98  0  0
 0  0      0 2499644  27296 649916    0    0     0     0  294  525  1  0 99  0  0
 1  0      0 2498112  27296 649940    0    0     0    21 1370 2562 11  2 88  0  0
 0  0      0 2497096  27304 649944    0    0     0    57 1115 2088  3  2 95  0  0
 0  0      0 2496308  27304 649948    0    0     4     1  733 1429  3  0 96  0  0
 0  0      0 2496056  27304 649948    0    0     0    36  438  854  2  0 98  0  0
 0  0      0 2495868  27304 649916    0    0     0     1  319  600  0  1 98  0  1
 0  0      0 2495868  27304 649916    0    0     0     0  442  881  2  1 95  0  2
 0  0      0 2494324  27312 649916    0    0     0    53 1168 2393  5  1 92  0  1
 0  0      0 2494292  27312 649916    0    0     0     0  297  571  1  0 99  0  0
 1  0      0 2494300  27312 649916    0    0     0     0  366  683  1  1 98  0  0
 0  0      0 2494080  27312 649916    0    0     0     2  723 1488  4  1 95  0  1
 0  0      0 2493952  27312 649928    0    0     0    29 1120 2011  7  1 92  0  1
 0  0      0 2492424  27312 649928    0    0     0     0  866 1594  3  2 96  0  0
 0  0      0 2492172  27320 649932    0    0     0    32  437  782  1  1 98  0  0

[gitbnitin]

root@mx:~# cat /opt/postal/config/postal.yml
version: 2

postal:
  # The hostname that the Postal web interface runs on
  web_hostname: mx.example.com
  # The HTTP protocol to use for the Postal web interface
  web_protocol: https
  # The hostname that the Postal SMTP server runs on
  smtp_hostname: mx.example.com
  # Should IP pools be enabled for this installation?
  use_ip_pools: false
  # The maximum number of delivery attempts
  default_maximum_delivery_attempts: 18
  # The number of days to hold a message before they will be expired
  default_maximum_hold_expiry_days: 7
  # The number of days an address will remain in a suppression list before being removed
  default_suppression_list_automatic_removal_days: 30
  # The default threshold at which a message should be treated as spam
  default_spam_threshold: 5
  # The default threshold at which a message should be treated as spam failure
  default_spam_failure_threshold: 20
  # Domain verification and checking usually checks with a domain's nameserver. Enable this to check with the server's local nameservers.
  use_local_ns_for_domain_verification: false
  # Append a Resend-Sender header to all outgoing e-mails
  use_resent_sender_header: false
  # Path to the private key used for signing
  #signing_key_path: config/postal/signing.key
  signing_key_path: /config/signing.key
  # An array of SMTP relays in the format of smtp://host:port
  smtp_relays: []
  # An array of IP addresses to trust for proxying requests to Postal (in addition to localhost addresses)
  trusted_proxies: []

web_server:
  # Specify configuration for the Postal web server
  default_bind_address: 0.0.0.0
  default_port: 5000
  # The maximum number of threads which can be used by the web server
  max_threads: 5

smtp_server:
  # Specify configuration to the Postal SMTP server
  default_port: 587
  default_bind_address: 0.0.0.0
  tls_enabled: true
  tls_certificate_path: /config/mx.example.com.crt
  tls_private_key_path: /config/mx.example.com.key
  # The default port for the SMTP server health server to listen on
  default_health_server_port: 9091
  # The default bind address for the SMTP server health server to listen on
  default_health_server_bind_address: 127.0.0.1

logging:
  # Specify options for the logging
  stdout: true

clamav:
  # Enable ClamAV for message inspection
  enabled: false
  # The host of the ClamAV server
  host: 127.0.0.1
  # The port of the ClamAV server
  port: 2000

worker:
  # The default port for the worker health server to listen on
  default_health_server_port: 9090
  # The default bind address for the worker health server to listen on
  default_health_server_bind_address: 127.0.0.1

rspamd:
  # Enable rspamd for message inspection
  enabled: false
  # The hostname of the rspamd server
  host: 192.168.1.150
  # The port of the rspamd server
  port: 11334
  # Enable SSL for the rspamd connection
  ssl: false
  # The password for the rspamd server
  password: admin
  # Any flags for the rspamd server
  flags:

spamd:
  enabled: true
  host: 127.0.0.1
  port: 783

smtp_client:
  open_timeout: 120
  read_timeout: 120


main_db:
  # Specify the connection details for your MySQL database
  host: 127.0.0.1
  username: root
  password: postal
  database: postal
  pool_size: 50
  encoding: utf8mb4

message_db:
  # Specify the connection details for your MySQL server that will be house the
  # message databases for mail servers.
  host: 127.0.0.1
  username: root
  password: postal
  pool_size: 50
  database_name_prefix: postal

rabbitmq:
  # Specify connection details for your RabbitMQ server
  host: 127.0.0.1
  username: postal
  password: postal
  vhost: postal

dns:
  # Specify the DNS records that you have configured. Refer to the documentation at
  # https://github.com/atech/postal/wiki/Domains-&-DNS-Configuration for further
  # information about these.
  mx_records:
    - mx.example.com
  smtp_server_hostname: mx.example.com
  spf_include: spf.example.com
  return_path_domain: rp.example.com
  route_domain: routes.example.com
  track_domain: track.example.com
  dkim_identifier: postal
  domain_verify_prefix: postal-verification
  custom_return_path_prefix: psrp
  timeout: 20
  resolv_conf_path: /etc/resolv.conf

smtp:
  # Specify an SMTP server that can be used to send messages from the Postal management
  # system to users. You can configure this to use a Postal mail server once the
  # your installation has been set up.
  host: 127.0.0.1
  port: 2525
  username: [email protected] # Complete when Postal is running and you can
  password: oexamplekf # generate the credentials within the interface.
  # The type of authentication to use
  authentication_type: login
  # Use STARTTLS when connecting to the SMTP server and fail if unsupported
  enable_starttls: false
  # Detects if STARTTLS is enabled in the SMTP server and starts to use it
  enable_starttls_auto: true
  # When using TLS, you can set how OpenSSL checks the certificate. Use 'none' for no certificate checking
  openssl_verify_mode: peer
  from_name: Cole
  from_address: [email protected]

rails:
  # This is generated automatically by the config initialization. It should be a random
  # string unique to your installation.
  secret_key: 1341b8285a0d9c14a1dd21bddc9794da57bc8c2ad2037fa952e244c4d17a5ccf424eaa5d4ff3c4b00072cdbb3fee23e6049ed96a578c2fee6823e4f940cc748e40896bf056804a844a1dd21bddc9794da57bc8c2ad2037fa952e244c4d17a5ccfced2ad37

[adamcooke]

I'm just guessing but do you have any IO limitations on that sever?

You really need to find a message that you feel was processed slowly and see which stage is actually slow by comparing with the logs.

[gitbnitin]

here is the iostat results

root@mx:~# iostat 1
Linux 5.4.0-105-generic (mx.emailstructures.com) 03/18/2024 x86_64 (4 CPU)

avg-cpu: %user %nice %system %iowait %steal %idle
2.05 0.00 0.67 0.02 0.17 97.09

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 6.27 21.59 14.36 2385.30 3689984 2455218 407768576

avg-cpu: %user %nice %system %iowait %steal %idle
3.73 0.00 1.00 0.00 1.74 93.53

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 2.00 0.00 36.00 0.00 0 36 0

avg-cpu: %user %nice %system %iowait %steal %idle
0.50 0.00 0.25 0.00 0.00 99.25

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
1.26 0.00 0.25 0.00 0.25 98.24

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
0.00 0.00 0.00 0.00 0.00 100.00

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
1.76 0.00 1.01 0.00 0.00 97.24

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
3.02 0.00 0.25 0.00 0.00 96.73

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
0.75 0.00 0.25 0.00 0.00 99.00

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 2.00 0.00 16.00 0.00 0 16 0

avg-cpu: %user %nice %system %iowait %steal %idle
1.00 0.00 0.25 0.00 0.25 98.50

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
0.50 0.00 0.25 0.00 0.00 99.25

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
1.51 0.00 1.01 0.00 0.00 97.48

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
2.99 0.00 0.75 0.00 0.25 96.01

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
3.80 0.00 0.25 0.25 0.00 95.70

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 34.00 716.00 28.50 0.00 716 28 0

avg-cpu: %user %nice %system %iowait %steal %idle
2.01 0.00 0.75 0.00 0.25 96.99

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 9.00 28.00 0.50 0.00 28 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
0.00 0.00 0.25 0.00 0.00 99.75

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
5.54 0.00 1.26 0.00 0.00 93.20

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 8.00 16.00 72.50 0.00 16 72 0

avg-cpu: %user %nice %system %iowait %steal %idle
2.27 0.00 1.01 0.00 0.00 96.72

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
0.25 0.00 0.50 0.25 0.00 99.00

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 263.00 0.00 2584.50 0.00 0 2584 0

avg-cpu: %user %nice %system %iowait %steal %idle
1.50 0.00 1.50 0.00 0.00 97.00

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

avg-cpu: %user %nice %system %iowait %steal %idle
8.48 0.00 3.99 0.00 0.25 87.28

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 0.00 0.00 0.00 0.00 0 0 0

^C
root@mx:~#

[adamcooke]

One thing might be useful is to run the following query on the database of your mail server. It'll show the average latency for dequeueing for all messages over the last hour. You can look over longer period of time by changing 3600. The "message rate" metric shown in the web UI isn't all that useful for determining system performance.

I will adding this information to the web UI soon.

SELECT 
    AVG(latency) AS average_latency
FROM 
    (
        SELECT 
            messages.id,
            COALESCE(MIN(deliveries.timestamp), UNIX_TIMESTAMP(NOW())) - messages.timestamp AS latency
        FROM 
            messages
        LEFT JOIN 
            deliveries ON messages.id = deliveries.message_id
        WHERE 
            messages.timestamp >= UNIX_TIMESTAMP(NOW()) - 3600
        GROUP BY 
            messages.id
    ) AS subquery;

[gitbnitin]

June 11, 2024 20:24

SENT

Message for [email protected] accepted by 142.250.150.26:25 (aspmx3.googlemail.com)

June 11, 2024 19:40

Message received by Postal

Received using the [email protected] SMTP credential. Connection secured with SSL.

[gitbnitin]

root@mx01:~# iostat
Linux 5.4.0-105-generic (mx01.meetinginvite.io) 06/11/2024 x86_64 (4 CPU)

avg-cpu: %user %nice %system %iowait %steal %idle
0.78 0.00 0.31 0.03 0.39 98.49

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 4.92 13.42 13.14 115.46 65864382 64493110 566671048

[gitbnitin]

MariaDB [(none)]> SHOW VARIABLES LIKE 'max_allowed_packet';
+--------------------+----------+
| Variable_name | Value |
+--------------------+----------+
| max_allowed_packet | 16777216 |
+--------------------+----------+
1 row in set (0.001 sec)

MariaDB [(none)]> SHOW VARIABLES LIKE 'max_connections';
+-----------------+-------+
| Variable_name | Value |
+-----------------+-------+
| max_connections | 1000 |
+-----------------+-------+
1 row in set (0.001 sec)

MariaDB [(none)]> SHOW VARIABLES LIKE 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout | 28800 |
+---------------+-------+
1 row in set (0.001 sec)

MariaDB [(none)]> SHOW VARIABLES LIKE 'innodb_buffer_pool_size';
+-------------------------+-----------+
| Variable_name | Value |
+-------------------------+-----------+
| innodb_buffer_pool_size | 268435456 |
+-------------------------+-----------+
1 row in set (0.001 sec)

[gitbnitin]

root@mx01:# postal status
NAME IMAGE COMMAND SERVICE CREATED STATUS PORTS
postal-smtp-1 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" smtp 4 days ago Up 4 days
postal-web-1 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" web 4 days ago Up 4 days
postal-worker-1 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
postal-worker-2 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
postal-worker-3 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
postal-worker-4 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
postal-worker-5 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
postal-worker-6 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
postal-worker-7 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
postal-worker-8 ghcr.io/postalserver/postal:3.3.3 "/docker-entrypoint.…" worker 4 days ago Up 4 days
root@mx01:#

[gitbnitin]

2024-06-11 16:14:19 +0000 INFO queue latency is 515845.458432436s component=worker thread=work5 original_queued_message=265538

[hugoperes]

Hey guys! I also noticed the drastic reduction in the sending rate of Postal v3. In version 2.14, we are having a sending rate of 388 emails per minute. When upgrading to version 3, this rate dropped to 96 per minute. I would like to know if the team is already trying to solve this problem in a new release or if there is some configuration so that we can obtain a high sending rate in v3 as we have in v2.

[hugoperes]

Postal 2.1.4 now, hitting 432 emails per minute. We are only using 10 workers. If it continues like this, I won't want to migrate to version 3 anytime soon.