From owner-freebsd-questions@FreeBSD.ORG Sat Sep 10 16:29:18 2005 Return-Path: X-Original-To: freebsd-questions@freebsd.org Delivered-To: freebsd-questions@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 13BF416A41F for ; Sat, 10 Sep 2005 16:29:18 +0000 (GMT) (envelope-from pauls@utdallas.edu) Received: from smtp1.utdallas.edu (smtp1.utdallas.edu [129.110.10.12]) by mx1.FreeBSD.org (Postfix) with ESMTP id C148543D45 for ; Sat, 10 Sep 2005 16:29:17 +0000 (GMT) (envelope-from pauls@utdallas.edu) Received: from [10.111.39.99] (pvdyna111039099.utdallas.edu [10.111.39.99]) by smtp1.utdallas.edu (Postfix) with ESMTP id 37744388E79 for ; Sat, 10 Sep 2005 11:29:17 -0500 (CDT) Date: Sat, 10 Sep 2005 11:29:16 -0500 From: Paul Schmehl To: freebsd-questions@freebsd.org Message-ID: <32860FDCC8EE0B0DDDC40288@[10.111.39.99]> X-Mailer: Mulberry/4.0.0 (Win32) MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit Content-Disposition: inline Subject: Postfix->Cyrus-imap connection problem X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 10 Sep 2005 16:29:18 -0000 Recently a server I maintain failed catastrophically and had to be rebuilt from scratch. The server *was* FreeBSD 4.9 SECURITY. I decided to update to FreeBSD 5.4 SECURITY since we were starting from scratch with brand new drives. Unfortunately, I was on vacation at the time, so we hired the techs at our ISP to install the new drives and the OS. For some reason they only allowed 250MB for the /var slice, so I had to create /var/log, /var/imap and /var/spool in /usr/local and make symlinks to /var to get the system working. (I considered more than once starting over from scratch, but the site was done for six days, and I didn't want to delay it any further.) After installing cvsup, updating all the ports, installing portupgrade and freebsd-update and updating everything, I began installing the apps again. I'm using Postfix 2.2.5.1, cyrus-sasl 2.1.21 and cyrus-imap 2.1.18. Even though I'm using the exact same config that was working fine on the old server, I can't get Postfix to deliver mail consistently to cyrus-imap. Mail sometimes sits in the queue and never gets delivered to legitimate accounts. Here's the error message in maillog: Sep 10 10:53:20 stovebolt postfix/lmtp[9742]: 410561143C0: to=, relay=/var/imap/socket/lmtp[/var/imap/socket/lmtp], delay=1457, status=deferred (conversation with /var/imap/socket/lmtp[/var/imap/socket/lmtp] timed out while sending end of data -- message may be sent more than once) Here's a test message I sent to my account: Sep 10 11:03:39 stovebolt postfix/smtpd[9947]: connect from smtp1.utdallas.edu[129.110.10.12] Sep 10 11:03:39 stovebolt postfix/smtpd[9947]: D96C411432C: client=smtp1.utdallas.edu[129.110.10.12] Sep 10 11:03:39 stovebolt postfix/cleanup[9950]: D96C411432C: message-id=<20050910160230.46C28388DF4@smtp1.utdallas.edu> Sep 10 11:03:39 stovebolt postfix/qmgr[9738]: D96C411432C: from=, size=1007, nrcpt=1 (queue active) Sep 10 11:03:39 stovebolt postfix/smtpd[9947]: disconnect from smtp1.utdallas.edu[129.110.10.12] Sep 10 11:03:44 stovebolt postfix/pickup[9737]: 455D111434A: uid=1002 from= Sep 10 11:03:44 stovebolt postfix/pipe[9951]: D96C411432C: to=, relay=filter, delay=5, status=sent ( dummyr) Sep 10 11:03:44 stovebolt postfix/qmgr[9738]: D96C411432C: removed Sep 10 11:03:44 stovebolt postfix/cleanup[9950]: 455D111434A: message-id=<20050910160230.46C28388DF4@smtp1.utdallas.edu> Sep 10 11:03:44 stovebolt postfix/qmgr[9738]: 455D111434A: from=, size=1317, nrcpt=1 (queue active) Sep 10 11:06:59 stovebolt postfix/anvil[9948]: statistics: max connection rate 1/60s for (smtp:129.110.10.12) at Sep 10 11:03:39 Sep 10 11:06:59 stovebolt postfix/anvil[9948]: statistics: max connection count 1 for (smtp:129.110.10.12) at Sep 10 11: 03:39 Sep 10 11:06:59 stovebolt postfix/anvil[9948]: statistics: max cache size 1 at Sep 10 11:03:39 Sep 10 11:08:20 stovebolt postfix/lmtp[9822]: A36CC11434E: to=, relay=/var/imap/socket/lmtp[/var/ima p/socket/lmtp], delay=600, status=deferred (conversation with /var/imap/socket/lmtp[/var/imap/socket/lmtp] timed out whi le sending end of data -- message may be sent more than once) Sep 10 11:13:44 stovebolt postfix/lmtp[9961]: 455D111434A: to=, relay=/var/imap/socket/lmtp[/var/ima p/socket/lmtp], delay=600, status=deferred (conversation with /var/imap/socket/lmtp[/var/imap/socket/lmtp] timed out whi le sending end of data -- message may be sent more than once) Here's the same message in the mailq: 455D111434A 1317 Sat Sep 10 11:03:44 pauls@utdallas.edu (conversation with /var/imap/socket/lmtp[/var/imap/socket/lmtp] timed out while sending end of data -- message may be sent more than once) geek@stovebolt.com I can login to the imap server, and I can view all the mail in every folder. (I used reconstruct to rebuild the mailboxes after installing the app.) I can su to user cyrus, login to localhost using cyradm and run any command that I want to. I'm using lmtp as the transport between Postfix and Cyrus-imap in main.cf: mailbox_transport = lmtp:unix:/var/imap/socket/lmtp I'm using a private, unix socket in master.cf: lmtp unix - - n - - lmtp The lmtpsocket is defined in imap.conf: lmtpsocket: /var/imap/socket/lmtp The listening socket is defined in cyrus.conf: lmtpunix cmd="lmtpd" listen="/var/imap/socket/lmtp" prefork=1 Sockstat shows the sockets connecting: sockstat -c | grep lmtp | less postfix lmtp 9822 7 dgram -> ?? postfix lmtp 9822 9 stream private/lmtp postfix lmtp 9822 11 stream -> /var/imap/socket/lmtp postfix local 9821 16 stream -> private/lmtp cyrus lmtpd 9761 0 stream /var/imap/socket/lmtp cyrus lmtpd 9761 1 stream /var/imap/socket/lmtp cyrus lmtpd 9761 2 stream /var/imap/socket/lmtp cyrus lmtpd 9761 11 dgram -> ?? postfix lmtp 9742 7 dgram -> ?? postfix lmtp 9742 9 stream private/lmtp postfix lmtp 9742 11 stream -> /var/imap/socket/lmtp postfix local 9740 15 stream -> private/lmtp cyrus lmtpd 9683 0 stream /var/imap/socket/lmtp cyrus lmtpd 9683 1 stream /var/imap/socket/lmtp cyrus lmtpd 9683 2 stream /var/imap/socket/lmtp cyrus lmtpd 9683 11 dgram -> ?? cyrus lmtpd 3380 11 dgram -> ?? cyrus lmtpd 2610 11 dgram -> ?? cyrus lmtpd 2609 11 dgram -> ?? cyrus lmtpd 2563 11 dgram -> ?? cyrus lmtpd 2480 11 dgram -> ?? cyrus lmtpd 2478 11 dgram -> ?? cyrus lmtpd 2423 11 dgram -> ?? cyrus lmtpd 2422 11 dgram -> ?? cyrus lmtpd 2284 11 dgram -> ?? cyrus lmtpd 2194 11 dgram -> ?? cyrus lmtpd 2178 11 dgram -> ?? cyrus lmtpd 2162 11 dgram -> ?? cyrus lmtpd 2112 11 dgram -> ?? cyrus lmtpd 2111 11 dgram -> ?? cyrus lmtpd 2005 11 dgram -> ?? cyrus lmtpd 1909 11 dgram -> ?? cyrus lmtpd 1878 11 dgram -> ?? cyrus lmtpd 1839 11 dgram -> ?? cyrus lmtpd 1798 11 dgram -> ?? cyrus lmtpd 1796 11 dgram -> ?? cyrus lmtpd 1615 11 dgram -> ?? cyrus lmtpd 1580 11 dgram -> ?? cyrus lmtpd 1432 11 dgram -> ?? cyrus lmtpd 1431 11 dgram -> ?? cyrus lmtpd 1342 11 dgram -> ?? cyrus lmtpd 1340 11 dgram -> ?? cyrus lmtpd 1244 11 dgram -> ?? cyrus lmtpd 1131 11 dgram -> ?? cyrus lmtpd 1061 11 dgram -> ?? cyrus lmtpd 923 11 dgram -> ?? cyrus lmtpd 900 11 dgram -> ?? cyrus lmtpd 870 11 dgram -> ?? cyrus lmtpd 818 11 dgram -> ?? cyrus lmtpd 733 11 dgram -> ?? cyrus lmtpd 566 11 dgram -> ?? cyrus lmtpd 565 11 dgram -> ?? cyrus lmtpd 451 11 dgram -> ?? If anyone has a clue where to go from here, I'm all ears. On a related note, is there a utility that would allow me to view the conversation between the lmtp sockets on postfix and imap? If I could see what's going on, maybe I could figure out why it's failing. Paul Schmehl (pauls@utdallas.edu) Adjunct Information Security Officer University of Texas at Dallas AVIEN Founding Member http://www.utdallas.edu/ir/security/