voxpupuli / puppet-postfix

Puppet postfix module
Apache License 2.0
70 stars 174 forks source link

Postfix in broken state after initial setup #279

Open olifre opened 4 years ago

olifre commented 4 years ago

In some cases, postfix is left in a broken state after a fresh machine installation. For that to happen, a mail needs to arrive for a target listed in /etc/virtual after the file is filled by augeas but before it is postmapped.

I observed the following timeline on CentOS 8 with the master branch of this module:

(/Stage[main]/Postfix::Mta/Postfix::Config[virtual_alias_maps]/Augeas[manage postfix 'virtual_alias_maps']/returns) executed successfully
(/Stage[main]/Postfix::Mta/Postfix::Config[transport_maps]/Augeas[manage postfix 'transport_maps']/returns) executed successfully
(/Stage[main]/Postfix::Satellite/Postfix::Virtual[@example.com]/Augeas[Postfix virtual - @example.com]/returns) executed successfully
...
systemd[1]: Starting Postfix Mail Transport Agent...
postfix/postfix-script[21083]: starting the Postfix mail system
postfix/master[21085]: daemon started -- version 3.3.1, configuration /etc/postfix
systemd[1]: Started Postfix Mail Transport Agent.
(/Stage[main]/Postfix::Service/Exec[restart postfix after packages install]) Triggered 'refresh' from 1 event
...
(/Stage[main]/Postfix::Service/Service[postfix]/enable) enable changed 'false' to 'true'
systemd[1]: Reloading Postfix Mail Transport Agent.
postfix/postfix-script[21145]: refreshing the Postfix mail system
postfix/master[21085]: reload -- version 3.3.1, configuration /etc/postfix
systemd[1]: Reloaded Postfix Mail Transport Agent.
puppet-agent[2999]: (/Stage[main]/Postfix::Service/Service[postfix]) Triggered 'refresh' from 3 events
...
<some process sends a mail via the local relay>
...
postfix/cleanup[15112]: error: open database /etc/postfix/virtual.db: No such file or directory
B58CE25FE8: uid=0 from=<root>
postfix/trivial-rewrite[15113]: error: open database /etc/postfix/virtual.db: No such file or directory
postfix/trivial-rewrite[15113]: error: open database /etc/postfix/transport.db: No such file or directory
postfix/trivial-rewrite[15113]: warning: hash:/etc/postfix/transport is unavailable. open database /etc/postfix/transport.db: No such file or directory
postfix/trivial-rewrite[15113]: warning: hash:/etc/postfix/transport lookup error for "*"
postfix/trivial-rewrite[15113]: warning: hash:/etc/postfix/transport is unavailable. open database /etc/postfix/transport.db: No such file or directory
postfix/trivial-rewrite[15113]: warning: hash:/etc/postfix/transport lookup error for "*"
postfix/cleanup[15112]: B58CE25FE8: message-id=<20200320095901.B58CE25FE8@example.com>
postfix/cleanup[15112]: warning: hash:/etc/postfix/virtual is unavailable. open database /etc/postfix/virtual.db: No such file or directory
postfix/cleanup[15112]: warning: hash:/etc/postfix/virtual lookup error for "root@example.com"
postfix/cleanup[15112]: warning: B58CE25FE8: virtual_alias_maps map lookup problem for root@example.com -- message not accepted, try again later
...
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/virtual]/Postfix::Map[/etc/postfix/virtual]/File[postfix map /etc/postfix/virtual]/group) group changed 'root' to 'po>
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/virtual]/Postfix::Map[/etc/postfix/virtual]/File[postfix map /etc/postfix/virtual]/mode) mode changed '0644' to '0640'
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/virtual]/Postfix::Map[/etc/postfix/virtual]/File[postfix map /etc/postfix/virtual.db]/ensure) created
postfix/postmap[15303]: warning: removing zero-length database file: /etc/postfix/virtual.db
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/virtual]/Postfix::Map[/etc/postfix/virtual]/Exec[generate /etc/postfix/virtual.db]) Triggered 'refresh' from 4 events
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/transport]/Postfix::Map[/etc/postfix/transport]/File[postfix map /etc/postfix/transport]/group) group changed 'root' >
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/transport]/Postfix::Map[/etc/postfix/transport]/File[postfix map /etc/postfix/transport]/mode) mode changed '0644' to>
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/transport]/Postfix::Map[/etc/postfix/transport]/File[postfix map /etc/postfix/transport.db]/ensure) created
postfix/postmap[15307]: warning: removing zero-length database file: /etc/postfix/transport.db
puppet-agent[2999]: (/Stage[main]/Postfix::Mta/Postfix::Hash[/etc/postfix/transport]/Postfix::Map[/etc/postfix/transport]/Exec[generate /etc/postfix/transport.db]) Triggered 'refresh' from 3 >
puppet-agent[2999]: (/Stage[main]/Postfix::Augeas/Augeas::Lens[postfix_canonical]/File[/opt/puppetlabs/puppet/share/augeas/lenses/postfix_canonical.aug]/ensure) defined content as '{md5}b3a35>
puppet-agent[2999]: (/Stage[main]/Postfix::Augeas/Augeas::Lens[postfix_canonical]/Exec[Typecheck lens postfix_canonical]) Triggered 'refresh' from 1 event
puppet-agent[2999]: (/Stage[main]/Postfix::Augeas/Augeas::Lens[postfix_canonical]/File[/opt/puppetlabs/puppet/share/augeas/lenses/tests/test_postfix_canonical.aug]/ensure) defined content as >
puppet-agent[2999]: (/Stage[main]/Postfix::Augeas/Augeas::Lens[postfix_canonical]/Exec[Test lens postfix_canonical]) Triggered 'refresh' from 3 events
...
postfix/pickup[21153]: 3A8CE241D3: uid=0 from=<root>
postfix/cleanup[15112]: 3A8CE241D3: message-id=<20200320100024.3A8CE241D3@example.com>
postfix/cleanup[15112]: warning: hash:/etc/postfix/virtual is unavailable. open database /etc/postfix/virtual.db: No such file or directory
postfix/cleanup[15112]: warning: hash:/etc/postfix/virtual lookup error for "root@example.com"
postfix/cleanup[15112]: warning: 3A8CE241D3: virtual_alias_maps map lookup problem for root@example.com -- message not accepted, try again later
postfix/pickup[21153]: 3B1C8241D3: uid=0 from=<root>
postfix/cleanup[15112]: 3B1C8241D3: message-id=<20200320100024.3B1C8241D3@example.com>
postfix/cleanup[15112]: warning: hash:/etc/postfix/virtual is unavailable. open database /etc/postfix/virtual.db: No such file or directory
postfix/cleanup[15112]: warning: hash:/etc/postfix/virtual lookup error for "root@example.com"
postfix/cleanup[15112]: warning: 3B1C8241D3: virtual_alias_maps map lookup problem for root@example.com -- message not accepted, try again late

The system never recovers until either a reboot or restarting postfix.

My interpretation is that /etc/virtual is created with wrong initial permissions by Augeas, and this is fixed later when virtual.db is created (and RHEL seems to ship an empty DB in the package by default). However, if postfix has already looked at those files before that happens, we end up in a broken state.

My current workaround is rather ugly:

        exec { 'restart postfix after postmap':
                command         => 'systemctl restart postfix',
                refreshonly     => true,
                subscribe       => Package['postfix'],
        }

        Postfix::Map<| |> ~> Exec['restart postfix after postmap']

(I use a separate exec to prevent a dependency cycle)

Any ideas on how to fix this better?

stale[bot] commented 3 years ago

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

olifre commented 3 years ago

If there are no better ideas (as wontfix suggests?) should we document the hackish workaround? I can certainly do a PR on this.

stale[bot] commented 3 years ago

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

olifre commented 3 years ago

Bumping this with a useless comment and spamming all subscribed watches since the issue persists.