puppet-postfix icon indicating copy to clipboard operation
puppet-postfix copied to clipboard

Postfix in broken state after initial setup

Open olifre opened this issue 5 years ago • 4 comments

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=<[email protected]>
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 "[email protected]"
postfix/cleanup[15112]: warning: B58CE25FE8: virtual_alias_maps map lookup problem for [email protected] -- 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=<[email protected]>
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 "[email protected]"
postfix/cleanup[15112]: warning: 3A8CE241D3: virtual_alias_maps map lookup problem for [email protected] -- message not accepted, try again later
postfix/pickup[21153]: 3B1C8241D3: uid=0 from=<root>
postfix/cleanup[15112]: 3B1C8241D3: message-id=<[email protected]>
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 "[email protected]"
postfix/cleanup[15112]: warning: 3B1C8241D3: virtual_alias_maps map lookup problem for [email protected] -- 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?

olifre avatar Mar 20 '20 12:03 olifre

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.

stale[bot] avatar Apr 19 '21 14:04 stale[bot]

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

olifre avatar Apr 19 '21 15:04 olifre

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.

stale[bot] avatar Jun 18 '21 16:06 stale[bot]

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

olifre avatar Jun 18 '21 16:06 olifre