# [solved] Postfix 2.7.3 - big problems after upgrade

## drrrl

Hi,

yesterday afternoon I upgraded my postfix from 2.7.2 to 2.7.3. It was just pure software upgrade, no changes in any configuration file (etc-update didn't even propose anything). Everything seemed OK in the evening,  until I noticed I couldn't log in to Horde (imap authentication) today in the morning. After a quick check I noticed that lmtp is consuming almost 100% of CPU, imap authentication does not work, mails are not coming. I checked logs and found the following in /var/log/messages:

```

Mar 15 01:47:40 myhost postfix/qmgr[16757]: 4C14593701: from=<plaxo@mx.plaxo.com>, size=36238, nrcpt=1 (queue active)

Mar 15 01:47:40 myhost spamd[16319]: prefork: child states: II

Mar 15 01:47:40 myhost lmtpunix[14342]: FATAL: couldn't exec() sendmail

Mar 15 01:47:40 myhost lmtpunix[14341]: sieve runtime error for kowal id <3ec84bbc7fac13cb27ee60c45d6f7534@xpertmailer.com>: Redirect: Sendmail process terminated normally, exit status 75

Mar 15 01:47:40 myhost lmtpunix[14341]: IOERROR: opening /var/spool/imap/stage./14341-1300150060-0: No such file or directory

Mar 15 01:47:40 myhost postfix/pipe[14339]: 4C14593701: to=<kowal@mydomain.com>, relay=cyrus, delay=0.57, delays=0.1/0.01/0/0.47, dsn=4.3.0, status=deferred (temporary failure)

Mar 15 01:47:40 myhost lmtpunix[14341]: IOERROR: error unlinking file /var/spool/imap/stage./14341-1300150060-0: No such file or directory

Mar 15 01:49:01 myhost master[3221]: process 14341 exited, signaled to death by 11

Mar 15 01:49:01 myhost master[3221]: service lmtpunix pid 14341 in READY state: terminated abnormally

Mar 15 01:55:37 myhost postfix/qmgr[16757]: 4C14593701: from=<plaxo@mx.plaxo.com>, size=36238, nrcpt=1 (queue active)

Mar 15 02:12:17 myhost postfix/pipe[14374]: warning: pipe_command_read: read time limit exceeded

Mar 15 02:12:17 myhost postfix/pipe[14374]: 4C14593701: to=<kowal@mydomain.com>, relay=cyrus, delay=1477, delays=477/0.01/0/1000, dsn=5.3.0, status=bounced (Command time limit exceeded: "/usr/lib/cyrus/deliver")

Mar 15 02:12:17 myhost postfix/cleanup[14409]: 60701936F2: message-id=<20110315011217.60701936F2@myhost.mydomain.com>

Mar 15 02:12:17 myhost postfix/bounce[14408]: 4C14593701: sender non-delivery notification: 60701936F2

```

I thought that maybe there were some dependencies unsolved after postfix update, so I run "revdep-rebuild -p" (no result) and manually reemerged all cyrus staff: cyrus-imap-dev-2.3.14, cyrus-sasl-2.1.23-r1, cyrus-imap-admin-2.3.14 and cyrus-imapd-2.3.14-r3. I restarted cyrus and postfix, and again, for some time it was running, until this moment:

```

Mar 15 08:34:02 myhost lmtpunix[10927]: FATAL: couldn't exec() sendmail

Mar 15 08:34:02 myhost lmtpunix[10913]: sieve runtime error for kowal id <20110315060333.D237C93705@myhost.mydomain.com>: Redirect: Sendmail process terminated normally, exit status 75

Mar 15 08:34:02 myhost lmtpunix[10913]: IOERROR: opening /var/spool/imap/stage./10913-1300174442-0: No such file or directory

Mar 15 08:34:02 myhost postfix/pipe[10909]: D237C93705: to=<kowal@myhost.mydomain.com>, orig_to=<root@myhost.mydomain.com>, relay=cyrus, delay=5429, delays=5428/0.13/0/0.73, dsn=4.3.0, status=deferred (temporary failure)

Mar 15 08:34:02 myhost lmtpunix[10913]: IOERROR: error unlinking file /var/spool/imap/stage./10913-1300174442-0: No such file or directory

Mar 15 08:35:54 myhost master[10756]: process 10913 exited, signaled to death by 11

Mar 15 08:35:54 myhost master[10756]: service lmtpunix pid 10913 in READY state: terminated abnormally

Mar 15 08:37:40 myhost HORDE[14698]: [imp] FAILED LOGIN for grzes [89.76.61.2] to {localhost:143 [imap/notls]} [pid 14698 on line 139 of "/var/www/localhost/htdocs/horde/imp/lib/Auth/imp.php"]

```

and again, lmtp at 99% CPU.

I've done several checks and finally came into conclusion, that everything is fine until a mail comes to a user (kowal in this case) who has set forwarding to external account (gmail in this particular case). As I restarted postfix several times, I noticed the same behaviour with another user forwarding his emails by appropriate sieve filter.

Since I didn't find a solution, I decided to downgrade postfix to 2.7.2 and... now everything works.

So, to summarize - be careful with upgrading postfix to 2.7.3, at least if you have it integrated with cyrus. I believie there is some bug in postfix 2.7.3, or at least some incompatibility introduced.Last edited by drrrl on Thu Mar 17, 2011 11:19 pm; edited 1 time in total

----------

## Princess Nell

Have you checked the release notes before upgrading?

----------

## drrrl

I read Release Notes on one of official postfix mirror (http://postfix.ezarticleinformation.com/official/postfix-2.7.3.RELEASE_NOTES), but found nothing that would cause incompatibilities in my current configuration.

----------

## Princess Nell

You haven't posted any config, but I specifically meant the section "Incompatibility with Postfix 2.7.2".

----------

## cach0rr0

shouldn't affect lmtp

having said that, my google-fu is epic

found this

http://www.mail-archive.com/info-cyrus@lists.andrew.cmu.edu/msg31140.html

http://lists.andrew.cmu.edu/pipermail/info-cyrus/2007-September/027067.html

seems it's one of the sieve rules. Nuke the sieve rules for now, see how you go, then see about recreating them (maybe the spec has changed? maybe a rogue regex is in an infinite loop?)

----------

## drrrl

 *Princess Nell wrote:*   

> You haven't posted any config, but I specifically meant the section "Incompatibility with Postfix 2.7.2".

 

You're right, I'm sorry. What I wanted to say is that incompatibility with 2.7.2 is about certification verification, while no TLS is used for internal communication, which seems to be a problem here. I'm using TLS only for client authentication, which doesn't seem to be related to current problem with lmtp - correct me if I'm wrong. My TLS related config is as follows:

```
# SASL

smtpd_sasl_auth_enable = yes

smtpd_sasl2_auto_enable = yes

smtpd_sasl_security_options = noanonymous

broken_sasl_auth_clients = yes

smtpd_sasl_authenticated_header = yes

# TLS

# OBSOLETE smtpd_use_tls = yes

smtpd_tls_security_level = may

smtpd_tls_key_file = /etc/ssl/myhost/server.key

smtpd_tls_cert_file = /etc/ssl/myhost/server.crt

smtpd_tls_CAfile = /etc/ssl/myhost/cacert.pem

#smtpd_tls_loglevel = 3

smtpd_tls_received_header = yes

smtpd_tls_session_cache_timeout = 3600s

tls_random_source = dev:/dev/urandom

# SASL over TLS

smtpd_sasl_tls_security_options = $smtpd_sasl_security_options

smtpd_tls_auth_only = yes

```

 *cach0rr0 wrote:*   

> shouldn't affect lmtp
> 
> having said that, my google-fu is epic
> 
> found this
> ...

 

Yes, that's weird, but as in your example, similar things happened, obviously with some much older version of software.

 *cach0rr0 wrote:*   

> seems it's one of the sieve rules. Nuke the sieve rules for now, see how you go, then see about recreating them (maybe the spec has changed? maybe a rogue regex is in an infinite loop?)

 

The strange thing here is that a) I've spoken with the user and he didn't change any of his sieve rules since a long time; b) immediately after downgrading from 2.7.3 to 2.7.2 the problem disappeared. This means that it is not a problem with some new badly defined rule, but rather something has changed in postfix behaviour.

The sieve script for this user is very simple:

```
# sieve filter generated by Ingo (March 13, 2006, 12:51 pm)

require ["imapflags", "fileinto"];

# Whitelisted Addresses

if address :all :comparator "i;ascii-casemap" :is ["From", "Sender", "Resent-From"] "username_hidden@gmail.com"  {

    keep;

}

# Spam

if header :comparator "i;octet" :contains "X-Spam-Status" "Yes"  {

    addflag ["\\Deleted", "\\Seen"];

    fileinto "INBOX.Junk";

    removeflag ["\\Deleted", "\\Seen"];

    stop;

}

# admin-junk

if address :all :comparator "i;ascii-casemap" :contains "From" "root"  {

    addflag "\\Deleted";

    fileinto "INBOX.admin-junk";

    removeflag "\\Deleted";

    stop;

}

# admin-other

if anyof ( header :comparator "i;ascii-casemap" :contains "Sender" "imp", address :all :comparator "i;ascii-casemap" :contains "From" "itrc", address :all :comparator "i;ascii-casemap" :contains "From" "webmin" ) {

    addflag "\\Deleted";

    fileinto "INBOX.admin-other";

    removeflag "\\Deleted";

    stop;

}

# Forward

if true {

    redirect "username_hidden@gmail.com";

    keep;

}

```

so, I believe it is a problem of forwarding to external server (like in one of the links you sent).

Anyway, I will try to upgrade postfix again and do some more debugging somewhere in the night, when mail system failure will not be that annoying  :Wink: 

----------

## cach0rr0

right, that's the same behavior some of the users in those discussions had 

the sieve rule would seemingly arbitrarily start misbehaving, after a long time of behaving correctly

and it could well be a change in postfix, who knows. But either way, if you temporarily remove the sieve rules, and the issue goes away, we can confirm the problem is there (even if it *is* catalysted by a postfix updgrade)

rather, I'm not proposing that as a fix, just a troubleshooting step to confirm the issue one way or another.

----------

## drrrl

I guess I've found the solution.

The issue is that postfix-2.7.3 installer removes this link:

```
# ls -l /usr/lib/sendmail

lrwxrwxrwx 1 root root 18 Mar 15 09:06 /usr/lib/sendmail -> /usr/sbin/sendmail
```

Unfortunately there is no warning in release notes or warning messages during emerge about it. /usr/lib/sendmail is the old default path for sendmail binary, which was also used by postfix, and there are still programs that assume this in their default configurations. One of the programs is... cyrus! 

So, when my mentioned above user received an email, the sieve script was executed, and tried to send email to external server. Sieve is part of cyrus, to it looked for sendmail binary in default location, namely /usr/lib/sendmail, and since it didn't exist, hence the "lmtpunix[12818]: FATAL: couldn't exec() sendmail" error. Apparently there is some flow in cyrus design and checks, causing series of problems, starting with these errors:

```
lmtpunix[12805]: IOERROR: opening /var/spool/imap/stage./12805-1300402194-0: No such file or directory

IOERROR: error unlinking file /var/spool/imap/stage./12805-1300402194-0: No such file or directory
```

but then things are going even worse:

lmtp hangs with 99.9% CPU

postfix receives mails, but cannot deliver them to local mailboxes, they stuck in the queue

finally things start to timeout ("postfix/pipe[14616]: warning: pipe_command_read: read time limit exceeded", "pyza deliver[16202]: connect(/var/imap/socket/lmtp) failed: Connection timed out"), and...

imap authentication stops working

After upgrading to postfix 2.7.3 again I added the following line to /etc/imapd.conf and everything runs smoothly now:

```
sendmail: /usr/sbin/sendmail
```

Conclusion:

postfix installer should warn about removing /usr/lib/sendmail

cyrus code should be reviewed why when sieve is used to forward emails and the sendmail variable points to non-existing binaries, things are going so wrong instead of just dropping an error and discarding the mail forward. This time it was removal of /usr/lib/sendmail, but the same situation would happed if someone makes a typo defining path to sendmail in imapd.conf

----------

## Guybrush

Thanks a lot!!!

Fixed just the same issue for me.    :Very Happy: 

----------

## cach0rr0

 *drrrl wrote:*   

> 
> 
> Conclusion:
> 
> postfix installer should warn about removing /usr/lib/sendmail
> ...

 

it might be worth logging a bug with regards to this behavior. I don't know if it's the postfix code, or the gentoo ebuild code, but it should at the very least have a build message saying "hey, this shit has changed, if you use cyrus or anything else that calls sendmail, blah blah blah incompatibility blah"

That, or, the ebuild *can* actually create a symlink. I don't know what's the portage-friendly syntactically correct solution, but one way or another methinks == logging-bug-worthy

Good work on this, btw, I'd have never figured it out, and I'm sure in the not-too-distant future my old 2.6 install is headed for an upgrade

----------

## drrrl

You're right, I logged two bugs:

- one about postfix upgrade removing /usr/lib/sendmail

- the second about cyrus going crazy when sendmail path is wrong

Thanks.

----------

