fix: Workaround postconf write settling logic (#2998)

* fix: Workaround `postconf` write settle logic

After updating `main.cf`, to avoid an enforced delay from reading the config by postfix tools, we can ensure the modified time is at least 2 seconds in the past as a workaround. This should be ok with our usage AFAIK.

Shaves off 2+ seconds roughly off each container startup, reduces roughly 2+ minutes off tests.

* chore: Only modify `mtime` if less than 2 seconds ago

- Slight improvement by avoiding unnecessary writes with a conditional check on the util method.
- Can more comfortably call this during `postfix reload` in the change detection cycle now.
- Identified other tests that'd benefit from this, created a helper method to call instead of copy/paste.
- The `setup email restrict` command also did a modification and reload. Added util method here too.

* tests(fix): `mail_smtponly.bats` should wait for Postfix

- `postfix reload` fails if the service is not ready yet.
- `service postfix reload` and `/etc/init.d/postfix reload` presumably wait until it is ready? (as these work regardless)

* chore: Review feedback - Move reload method into utilities

target/bin/restrict-access

@@ -44,7 +44,7 @@ case "${MODE}" in
           sed -i 's|smtpd_sender_restrictions =|smtpd_sender_restrictions = check_sender_access texthash:/tmp/docker-mailserver/postfix-send-access.cf,|' /etc/postfix/main.cf \
         || sed -i 's|smtpd_recipient_restrictions =|smtpd_recipient_restrictions = check_recipient_access texthash:/tmp/docker-mailserver/postfix-receive-access.cf,|' /etc/postfix/main.cf
 
-      service postfix reload >/dev/null
+      _reload_postfix
     fi
 
     echo -e "${USER} \t\t REJECT" >>"${DATABASE}"

target/scripts/check-for-changes.sh

@@ -59,7 +59,7 @@ function _check_for_changes
     _log_with_date 'debug' 'Reloading services due to detected changes'
 
     [[ ${ENABLE_AMAVIS} -eq 1 ]] && _reload_amavis
-    postfix reload
+    _reload_postfix
     [[ ${SMTP_ONLY} -ne 1 ]] && dovecot reload
 
     _remove_lock

target/scripts/helpers/aliases.sh

@@ -54,6 +54,7 @@ function _handle_postfix_aliases_config
   local DATABASE_ALIASES='/tmp/docker-mailserver/postfix-aliases.cf'
   [[ -f ${DATABASE_ALIASES} ]] && cat "${DATABASE_ALIASES}" >>/etc/aliases
 
+  _adjust_mtime_for_postfix_maincf
   postalias /etc/aliases
 }
 

target/scripts/helpers/utils.sh

@@ -44,3 +44,22 @@ function _require_n_parameters_or_print_usage
   [[ ${1:-} == 'help' ]]  && { __usage ; exit 0 ; }
   [[ ${#} -lt ${COUNT} ]] && { __usage ; exit 1 ; }
 }
+
+# NOTE: Postfix commands that read `main.cf` will stall execution,
+# until the config file has not be written to for at least 2 seconds.
+# After we modify the config explicitly, we can safely assume (reasonably)
+# that the write stream has completed, and it is safe to read the config.
+# https://github.com/docker-mailserver/docker-mailserver/issues/2985
+function _adjust_mtime_for_postfix_maincf
+{
+  if [[ $(( $(date '+%s') - $(stat -c '%Y' '/etc/postfix/main.cf') )) -lt 2 ]]
+  then
+    touch -d '2 seconds ago' /etc/postfix/main.cf
+  fi
+}
+
+function _reload_postfix
+{
+  _adjust_mtime_for_postfix_maincf
+  postfix reload
+}

target/scripts/startup/daemons-stack.sh

@@ -32,7 +32,6 @@ function _start_daemon_cron           { _default_start_daemon 'cron'           ;
 function _start_daemon_opendkim       { _default_start_daemon 'opendkim'       ; }
 function _start_daemon_opendmarc      { _default_start_daemon 'opendmarc'      ; }
 function _start_daemon_postsrsd       { _default_start_daemon 'postsrsd'       ; }
-function _start_daemon_postfix        { _default_start_daemon 'postfix'        ; }
 function _start_daemon_rsyslog        { _default_start_daemon 'rsyslog'        ; }
 function _start_daemon_update_check   { _default_start_daemon 'update-check'   ; }
 function _start_daemon_rspamd         { _default_start_daemon 'rspamd'         ; }
@@ -43,6 +42,12 @@ function _start_daemon_saslauthd
   _default_start_daemon "saslauthd_${SASLAUTHD_MECHANISMS}"
 }
 
+function _start_daemon_postfix
+{
+  _adjust_mtime_for_postfix_maincf
+  _default_start_daemon 'postfix'
+}
+
 function _start_daemon_postgrey
 {
   rm -f /var/run/postgrey/postgrey.pid

target/scripts/startup/setup-stack.sh

@@ -686,48 +686,52 @@ function _setup_docker_permit
     CONTAINER_NETWORKS+=("${IP}")
   done < <(ip -o -4 addr show type veth | grep -E -o '[0-9\.]+/[0-9]+')
 
-  case "${PERMIT_DOCKER}" in
-    ( 'none' )
+  function __clear_postfix_mynetworks
+  {
     _log 'trace' "Clearing Postfix's 'mynetworks'"
     postconf "mynetworks ="
-      ;;
+  }
 
-    ( 'connected-networks' )
-      for NETWORK in "${CONTAINER_NETWORKS[@]}"
-      do
-        NETWORK=$(_sanitize_ipv4_to_subnet_cidr "${NETWORK}")
-        _log 'trace' "Adding Docker network '${NETWORK}' to Postfix's 'mynetworks'"
+  function __add_to_postfix_mynetworks
+  {
+    local NETWORK_TYPE=$1
+    local NETWORK=$2
+
+    _log 'trace' "Adding ${NETWORK_TYPE} (${NETWORK}) to Postfix 'main.cf:mynetworks'"
+    _adjust_mtime_for_postfix_maincf
     postconf "$(postconf | grep '^mynetworks =') ${NETWORK}"
     echo "${NETWORK}" >> /etc/opendmarc/ignore.hosts
     echo "${NETWORK}" >> /etc/opendkim/TrustedHosts
+  }
+
+  case "${PERMIT_DOCKER}" in
+    ( 'none' )
+      __clear_postfix_mynetworks
+      ;;
+
+    ( 'connected-networks' )
+      for CONTAINER_NETWORK in "${CONTAINER_NETWORKS[@]}"
+      do
+        CONTAINER_NETWORK=$(_sanitize_ipv4_to_subnet_cidr "${CONTAINER_NETWORK}")
+        __add_to_postfix_mynetworks 'Docker Network' "${CONTAINER_NETWORK}"
       done
       ;;
 
     ( 'container' )
-      _log 'trace' "Adding container IP address to Postfix's 'mynetworks'"
-      postconf "$(postconf | grep '^mynetworks =') ${CONTAINER_IP}/32"
-      echo "${CONTAINER_IP}/32" >> /etc/opendmarc/ignore.hosts
-      echo "${CONTAINER_IP}/32" >> /etc/opendkim/TrustedHosts
+      __add_to_postfix_mynetworks 'Container IP address' "${CONTAINER_IP}/32"
       ;;
 
     ( 'host' )
-      _log 'trace' "Adding '${CONTAINER_NETWORK}/16' to Postfix's 'mynetworks'"
-      postconf "$(postconf | grep '^mynetworks =') ${CONTAINER_NETWORK}/16"
-      echo "${CONTAINER_NETWORK}/16" >> /etc/opendmarc/ignore.hosts
-      echo "${CONTAINER_NETWORK}/16" >> /etc/opendkim/TrustedHosts
+      __add_to_postfix_mynetworks 'Host Network' "${CONTAINER_NETWORK}/16"
       ;;
 
     ( 'network' )
-      _log 'trace' "Adding Docker network to Postfix's 'mynetworks'"
-      postconf "$(postconf | grep '^mynetworks =') 172.16.0.0/12"
-      echo 172.16.0.0/12 >> /etc/opendmarc/ignore.hosts
-      echo 172.16.0.0/12 >> /etc/opendkim/TrustedHosts
+      __add_to_postfix_mynetworks 'Docker IPv4 Subnet' '172.16.0.0/12'
       ;;
 
     ( * )
       _log 'warn' "Invalid value for PERMIT_DOCKER: '${PERMIT_DOCKER}'"
-      _log 'warn' "Clearing Postfix's 'mynetworks'"
-      postconf "mynetworks ="
+      __clear_postfix_mynetworks
       ;;
 
   esac
@@ -754,9 +758,13 @@ function _setup_postfix_override_configuration
   if [[ -f /tmp/docker-mailserver/postfix-main.cf ]]
   then
     cat /tmp/docker-mailserver/postfix-main.cf >>/etc/postfix/main.cf
+    _adjust_mtime_for_postfix_maincf
+
     # do not directly output to 'main.cf' as this causes a read-write-conflict
     postconf -n >/tmp/postfix-main-new.cf 2>/dev/null
+
     mv /tmp/postfix-main-new.cf /etc/postfix/main.cf
+    _adjust_mtime_for_postfix_maincf
     _log 'trace' "Adjusted '/etc/postfix/main.cf' according to '/tmp/docker-mailserver/postfix-main.cf'"
   else
     _log 'trace' "No extra Postfix settings loaded because optional '/tmp/docker-mailserver/postfix-main.cf' was not provided"

test/helper/common.bash

@@ -28,6 +28,14 @@ function _default_teardown() {
   docker rm -f "${CONTAINER_NAME}"
 }
 
+function _reload_postfix() {
+  local CONTAINER_NAME=${1:-${CONTAINER_NAME}}
+
+  # Reloading Postfix config after modifying it in <2 sec will cause Postfix to delay, workaround that:
+  docker exec "${CONTAINER_NAME}" touch -d '2 seconds ago' /etc/postfix/main.cf
+  docker exec "${CONTAINER_NAME}" postfix reload
+}
+
 # -------------------------------------------------------------------
 
 # @param ${1} program name [REQUIRED]

test/test_helper/common.bash

@@ -9,6 +9,14 @@ NAME=${NAME:-mailserver-testing:ci}
 TEST_TIMEOUT_IN_SECONDS=${TEST_TIMEOUT_IN_SECONDS:-120}
 NUMBER_OF_LOG_LINES=${NUMBER_OF_LOG_LINES:-10}
 
+function _reload_postfix() {
+  local CONTAINER_NAME=$1
+
+  # Reloading Postfix config after modifying it in <2 sec will cause Postfix to delay, workaround that:
+  docker exec "${CONTAINER_NAME}" touch -d '2 seconds ago' /etc/postfix/main.cf
+  docker exec "${CONTAINER_NAME}" postfix reload
+}
+
 # @param ${1} timeout
 # @param --fatal-test <command eval string> additional test whose failure aborts immediately
 # @param ... test to run

test/tests/parallel/set1/spam_virus/postgrey_enabled.bats

@@ -48,11 +48,13 @@ function teardown_file() { _default_teardown ; }
 @test "should initially reject (greylist) mail from 'user@external.tld'" {
   # Modify the postfix config in order to ensure that postgrey handles the test e-mail.
   # The other spam checks in `main.cf:smtpd_recipient_restrictions` would interfere with testing postgrey.
-  _run_in_container bash -c "sed -ie 's/permit_sasl_authenticated.*policyd-spf,$//g' /etc/postfix/main.cf"
-  _run_in_container bash -c "sed -ie 's/reject_unauth_pipelining.*reject_unknown_recipient_domain,$//g' /etc/postfix/main.cf"
-  _run_in_container bash -c "sed -ie 's/reject_rbl_client.*inet:127\.0\.0\.1:10023$//g' /etc/postfix/main.cf"
-  _run_in_container bash -c "sed -ie 's/smtpd_recipient_restrictions =/smtpd_recipient_restrictions = check_policy_service inet:127.0.0.1:10023/g' /etc/postfix/main.cf"
-  _run_in_container postfix reload
+  _run_in_container sed -i \
+    -e 's/permit_sasl_authenticated.*policyd-spf,$//g' \
+    -e 's/reject_unauth_pipelining.*reject_unknown_recipient_domain,$//g' \
+    -e 's/reject_rbl_client.*inet:127\.0\.0\.1:10023$//g' \
+    -e 's/smtpd_recipient_restrictions =/smtpd_recipient_restrictions = check_policy_service inet:127.0.0.1:10023/g' \
+    /etc/postfix/main.cf
+  _reload_postfix
 
   # Send test mail (it should fail to deliver):
   _send_test_mail '/tmp/docker-mailserver-test/email-templates/postgrey.txt' '25'

test/tests/serial/mail_smtponly.bats

@@ -9,6 +9,7 @@ function setup_file() {
     -t "${NAME}"
 
   wait_for_finished_setup_in_container mail_smtponly
+  wait_for_smtp_port_in_container mail_smtponly
 }
 
 function teardown_file() {
@@ -45,8 +46,8 @@ function teardown_file() {
 @test "checking smtp_only: mail send should work" {
   run docker exec mail_smtponly /bin/sh -c "postconf smtp_host_lookup=no"
   assert_success
-  run docker exec mail_smtponly /bin/sh -c "/etc/init.d/postfix reload"
-  assert_success
+
+  _reload_postfix mail_smtponly
 
   wait_for_smtp_port_in_container mail_smtponly
   run docker exec mail_smtponly /bin/sh -c "nc 0.0.0.0 25 < /tmp/docker-mailserver-test/email-templates/smtp-only.txt"

test/tests/serial/permit_docker.bats

@@ -65,8 +65,7 @@ teardown_file() {
   run docker exec mail_smtponly_second_network /bin/sh -c "postconf smtp_host_lookup=no"
   assert_success
 
-  run docker exec mail_smtponly_second_network /bin/sh -c "/etc/init.d/postfix reload"
-  assert_success
+  _reload_postfix mail_smtponly_second_network
 
   # we should be able to send from the other container on the second network!
   run docker exec mail_smtponly_second_network_sender /bin/sh -c "nc mail_smtponly_second_network 25 < /tmp/docker-mailserver-test/email-templates/smtp-only.txt"
@@ -78,8 +77,7 @@ teardown_file() {
   run docker exec mail_smtponly_force_authentication /bin/sh -c "postconf smtp_host_lookup=no"
   assert_success
 
-  run docker exec mail_smtponly_force_authentication /bin/sh -c "/etc/init.d/postfix reload"
-  assert_success
+  _reload_postfix mail_smtponly_force_authentication
 
   # the mailserver should require authentication and a protocol error should occur when using TLS
   run docker exec mail_smtponly_force_authentication /bin/sh -c "nc localhost 25 < /tmp/docker-mailserver-test/email-templates/smtp-only.txt"