postal should not ignore routing table when using smtp relays ?

[fredleger]

Describe the bug

We have setup postal version 3.3.4 in a kubernetes cluster, following the documentation. This cluster is hosted on a managed infrastructure operated by our cloud provide (scaleway, france).
As the mail providers are becoming more and more sensitive about who is sending e-mails to them we noticed that for delivery we are more or less obliged to send our emails trough a whitelisted relay server offered by our cloud provider (smtp.tem.scaleway.com).

The idea is to match the following pattern :

graph LR;
TO(contact-at-example.com) --> MX(MX postal-smtp) --> PW(postal process) --> smtp.tem.scaleway.com --> U(end-user other-at-acme.net)

Loading

So we created on a bare new postal installation :

• an organization example.com
• a mail server dedicated to this usage
• a domain example.com inside this mail server (and setup DNS is all green)
• an address endpoint for [email protected]
• a routing rule for [email protected] using the above address endpoint as main endpoint

What we were expecting was that postal will use the relay server in order to send the e-mail
What we are experiencing is that postal is relaying the email without considering the routing defined

We confirmed it by using mailhog project as a relay, so we could see all the e-mails headers and none of them was mentionning [email protected]

Below is the env vars we used (not using any config file, just vars) :

CLAMAV_ENABLED: 'false'
CLAMAV_HOST: ''
CLAMAV_PORT: '2000'
DNS_MX_RECORDS: postal.example.com
DNS_RETURN_PATH_DOMAIN: postal.example.com
DNS_ROUTE_DOMAIN: ''
DNS_SPF_INCLUDE: _spf.tem.scaleway.com
DNS_TRACK_DOMAIN: postal.example.com
LOGGING_ENABLED: 'true'
LOGGING_HIGHLIGHTING_ENABLED: 'false'
LOGGING_RAILS_LOG_ENABLED: 'false'
LOGGING_SENTRY_DSN: ''
MAIN_DB_DATABASE: postal
MAIN_DB_ENCODING: utf8mb4
MAIN_DB_HOST: postal-mariadb
MAIN_DB_POOL_SIZE: '5'
MAIN_DB_PORT: '3306'
MAIN_DB_USERNAME: postal
MESSAGE_DB_HOST: postal-mariadb
MESSAGE_DB_PORT: '3306'
MESSAGE_DB_USERNAME: postal
POSTAL_DEFAULT_MAXIMUM_DELIVERY_ATTEMPTS: '18'
POSTAL_DEFAULT_MAXIMUM_HOLD_EXPIRY_DAYS: '7'
POSTAL_DEFAULT_SPAM_FAILURE_THRESHOLD: '20'
POSTAL_DEFAULT_SPAM_THRESHOLD: '5'
POSTAL_DEFAULT_SUPPRESSION_LIST_AUTOMATIC_REMOVAL_DAYS: '30'
POSTAL_SMTP_HOSTNAME: postal.example.com
POSTAL_TRUSTED_PROXIES: ''
POSTAL_USE_IP_POOLS: 'false'
POSTAL_USE_LOCAL_NS_FOR_DOMAIN_VERIFICATION: 'false'
POSTAL_USE_RESENT_SENDER_HEADER: 'true'
POSTAL_WEB_HOSTNAME: postal.example.com
POSTAL_WEB_PROTOCOL: https
POSTAL_SMTP_RELAYS: smtp://mailhog:25
SMTP_SERVER_DEFAULT_HEALTH_SERVER_BIND_ADDRESS: 0.0.0.0
SMTP_SERVER_DEFAULT_HEALTH_SERVER_PORT: '9090'
SMTP_SERVER_DEFAULT_PORT: '25'
SMTP_SERVER_LOG_CONNECTIONS: 'false'
SMTP_SERVER_LOG_IP_ADDRESS_EXCLUSION_MATCHER: ''
SMTP_SERVER_MAX_MESSAGE_SIZE: '14'
SMTP_SERVER_PROXY_PROTOCOL: 'false'
SMTP_SERVER_TLS_CERTIFICATE_PATH: /config/certs/tls.crt
SMTP_SERVER_TLS_ENABLED: 'true'
SMTP_SERVER_TLS_PRIVATE_KEY_PATH: /config/certs/tls.key
SPAMD_ENABLED: 'false'
SPAMD_HOST: ''
SPAMD_PORT: '783'
WEB_SERVER_DEFAULT_BIND_ADDRESS: 0.0.0.0
WEB_SERVER_DEFAULT_PORT: '5000'
WEB_SERVER_MAX_THREADS: '5'
WORKER_DEFAULT_HEALTH_SERVER_BIND_ADDRESS: 0.0.0.0
WORKER_DEFAULT_HEALTH_SERVER_PORT: '9090'

To Reproduce

1. setup all as indicated above
2. send e-mail to postal-smtp service using swaks
3. go to mailhog
4. check the email received headers

Expected behaviour

We would expect that relaying is actually using routing table or thta there is an env var that allow to control this behavior (like RELAY_UNMODIFIED=false or something meaningful)

Screenshots

Environment details

• OS: linux
• kubernetes using env var in a configmap (deployed using this chart https://github.com/hoverkraft-tech/helm-chart-postal)

Additional information/context

If this is not an issue but rather a feature, can you point us to the right direction in order to achieve what we are trying to do ?
Feel free to ask any missing details

[willpower232]

the relay configuration is always the last step in the process

POSTAL_SMTP_RELAYS: smtp://mailhog:25

Surely you're just sending mail straight to mailhog and this should be set to the scaleway one?

[fredleger]

This was only for debugging and show you the capture.
The behavior is the same using scaleway relay or mailhog. The TO is not showing the routed address

[cvillabrille]

I'm happy to see I'm not the only one ;-)

We have noticed this behavior in two internal domains (not accessible from internet). Depending on the order list of the email addresses in To: the delivery is attempted or delegated to the relay host. After any address not in the routing table, no delivery is attempted and it's forwarded directly to the relay host.

Example:

1. In this example:
   echo "Test" | mutt -s "Test to deliver" "[email protected]" "[email protected]" "[email protected]"
   Postal relies the delivery of all addresses to the relay host without attempting to deliver to domain1 and domain2, despite of the routing tables for domain1 and domain2 configured.

2. In this other case.
   echo "Test" | mutt -s "Test to deliver" "[email protected]; [email protected] ; [email protected]"
   Postal attempts the delivery to domain1, but gmail and domain2 are directly sent to the relay host.

3. In this last test case.
   echo "Test" | mutt -s "Test to deliver" "[email protected]; [email protected]; [email protected]"
   We can see in the logs of domain1 and domain2 the delivery attempt from Postal, and gmail is forwarded to the relay host, as it should be.

[cvillabrille]

To add a bit of more information.

Logs of the worker when we send an email with the following To: list. (example 1 of the above list)

mutt -s "Test email" "[email protected]; [email protected]; [email protected]"

starting message unqueue component=worker thread=work1 original_queued_message=354
queue latency is 3.131274461746216s component=worker thread=work1 original_queued_message=354
parsing message content as it hasn't been parsed before component=worker thread=work1 original_queued_message=354 queued_message=354
Connected to 50.51.52.53:25 (smart_host.forwarder.com) log_id=CWIYT3C8 component=worker thread=work1 original_queued_message=354 queued_message=354
Sending message 1::333 to [email protected] log_id=CWIYT3C8 component=worker thread=work1 original_queued_message=354 queued_message=354

starting message unqueue component=worker thread=work0 original_queued_message=355
queue latency is 3.9189493656158447s component=worker thread=work0 original_queued_message=355
parsing message content as it hasn't been parsed before component=worker thread=work0 original_queued_message=355 queued_message=355

Accepted by 50.51.52.53:25 (smart_host.forwarder.com) for [email protected] log_id=CWIYT3C8 component=worker thread=work1 original_queued_message=354 queued_message=354
message processing complete component=worker thread=work1 original_queued_message=354 queued_message=354
finished message unqueue component=worker thread=work1 original_queued_message=354

starting message unqueue component=worker thread=work1 original_queued_message=356
queue latency is 3.9644083976745605s component=worker thread=work1 original_queued_message=356
parsing message content as it hasn't been parsed before component=worker thread=work1 original_queued_message=356 queued_message=356
Connected to 50.51.52.53:25 (smart_host.forwarder.com) log_id=FJYW5ZNT component=worker thread=work0 original_queued_message=355 queued_message=355
Sending message 1::334 to [email protected] log_id=FJYW5ZNT component=worker thread=work0 original_queued_message=355 queued_message=355
Connected to 50.51.52.53:25 (smart_host.forwarder.com) log_id=AKE9T9KD component=worker thread=work1 original_queued_message=356 queued_message=356
Sending message 1::335 to [email protected] log_id=AKE9T9KD component=worker thread=work1 original_queued_message=356 queued_message=356
Accepted by 50.51.52.53:25 (smart_host.forwarder.com) for [email protected] log_id=AKE9T9KD component=worker thread=work1 original_queued_message=356 queued_message=356
message processing complete component=worker thread=work1 original_queued_message=356 queued_message=356
finished message unqueue component=worker thread=work1 original_queued_message=356
Accepted by 50.51.52.53:25 (smart_host.forwarder.com) for [email protected] log_id=FJYW5ZNT component=worker thread=work0 original_queued_message=355 queued_message=355
message processing complete component=worker thread=work0 original_queued_message=355 queued_message=355

Logs of the worker when we send an email with the following To: list. (example 3 of the above list)

mutt -s "Test email" "[email protected]; [email protected]; [email protected]"

starting message unqueue component=worker thread=work1 original_queued_message=357
queue latency is 2.6448798179626465s component=worker thread=work1 original_queued_message=357
message is incoming component=worker thread=work1 original_queued_message=357 queued_message=357
inspecting message component=worker thread=work1 original_queued_message=357 queued_message=357
message inspected, headers added spam_score=0 component=worker thread=work1 original_queued_message=357 queued_message=357
Connected to 10.11.12.1:25 (smtp.domain1.com) log_id=JFZOJQAA component=worker thread=work1 original_queued_message=357 queued_message=357
Sending message 1::336 to [email protected] t log_id=JFZOJQAA component=worker thread=work1 original_queued_message=357 queued_message=357
Accepted by 10.11.12.1:25 (smtp.domain1.com) for [email protected] log_id=JFZOJQAA component=worker thread=work1 original_queued_message=357 queued_message=357
message processing completed component=worker thread=work1 original_queued_message=357 queued_message=357
finished message unqueue component=worker thread=work1 original_queued_message=357

starting message unqueue component=worker thread=work1 original_queued_message=358
queue latency is 2.803494453430176s component=worker thread=work1 original_queued_message=358
message is incoming component=worker thread=work1 original_queued_message=358 queued_message=358
inspecting message component=worker thread=work1 original_queued_message=358 queued_message=358
message inspected, headers added spam_score=0 component=worker thread=work1 original_queued_message=358 queued_message=358
Connected to 20.21.22.23:25 (smtp.domain2.com) log_id=5OQKBKCZ component=worker thread=work1 original_queued_message=358 queued_message=358
Sending message 1::337 to [email protected] log_id=5OQKBKCZ component=worker thread=work1 original_queued_message=358 queued_message=358
Accepted by 20.21.22.23:25 (smtp.domain2.com) for [email protected] log_id=5OQKBKCZ component=worker thread=work1 original_queued_message=358 queued_message=358
message processing completed component=worker thread=work1 original_queued_message=358 queued_message=358
finished message unqueue component=worker thread=work1 original_queued_message=358

starting message unqueue component=worker thread=work1 original_queued_message=359
queue latency is 2.9426372051239014s component=worker thread=work1 original_queued_message=359
parsing message content as it hasn't been parsed before component=worker thread=work1 original_queued_message=359 queued_message=359
Connected to 50.51.52.53:25 (smart_host.forwarder.com) log_id=3VXLPSFS component=worker thread=work1 original_queued_message=359 queued_message=359
Sending message 1::338 to [email protected] log_id=3VXLPSFS component=worker thread=work1 original_queued_message=359 queued_message=359
Accepted by 50.51.52.53:25 (smart_host.forwarder.com) for [email protected] log_id=3VXLPSFS component=worker thread=work1 original_queued_message=359 queued_message=359
message processing complete component=worker thread=work1 original_queued_message=359 queued_message=359
finished message unqueue component=worker thread=work1 original_queued_message=359

We have tested with :
batch_queued_messages: false

and also with :
batch_queued_messages: true

[fredleger]

@cvillabrille can you confirm that you are also using relay configuration ?

[cvillabrille]

I do.
In postal.yml:

postal section:

smtp_relays: smtp://smart_host.forwarder.com:25?ssl_mode=Auto

[fredleger]

@willpower232 can you bring your lights here ?
It seems that we are at least 2 people to not understand if when setting mailrelay, shunt of routing table is awaited or not ?
Is it a feature or an issue ?