You can make a difference in the Apple Support Community!

When you sign up with your Apple Account, you can provide valuable feedback to other community members by upvoting helpful replies and User Tips.

Looks like no one’s replied in a while. To start the conversation again, simply ask a new question.

postfix/lmtp errors....

Well it all started a day ago, when mail was being queued and not delivered.... In the log I can see

Nov 5 09:42:42 email postfix/lmtp[10922]: EFF393D184B: to=<ncudmore@newashgreen.net>, relay=none, delay=63724, delays=63719/5.1/0.16/0, dsn=4.4.1, status=deferred (connect to email.newashgreen.net[/var/imap/socket/lmtp]: No such file or directory)

having checked the postfix main.cf
mailbox_transport = lmtp:unix:/var/imap/socket/lmtp

and master.cf
lmtp unix - - n - - lmtp

cyrus.conf
lmtpunix cmd="lmtpd" listen="/var/imap/socket/lmtp" prefork=

everything points to /var/imap/socket/lmtp, and looks fine.

checking /var/imap/socket/ I can see the following...
drwxr-xr-x 4 _cyrus mail 136 5 Nov 01:03 .
drwxr-xr-x 16 _cyrus mail 544 5 Nov 01:03 ..
srwxrwxrwx 1 _cyrus mail 0 5 Nov 01:03 idle
-rw------- 1 _cyrus mail 0 4 Nov 23:01 lmtpunix-0.lock

which would imply there is indeed no socket for lmtp.

Checking the ownership on the directory I see
drwxr-xr-x 4 _cyrus mail 136 5 Nov 01:03 socket

So, cyrus has ownership, and group access for mail. Checking the group mail gave me

root# grep ^mail /etc/group
mail:*:6:

So, mail has no membership.... Thus, I reason on the fact that postfix has not access to here, checked to find the OS X use to replace the lack of adduser and the nearest find I could get was

sudo dscl . append /Groups/mail GroupMembership postfix

however, this seems to have no effect

# grep ^mail /etc/group
mail:*:6:

So, can anyone tell me how to add postfix to the mail group? Or, am I going down the wrong road and this isn't the problem?

Various iMac, Powerbook, MacBook, 2*mini, Mac OS X (10.5.8)

Posted on Nov 5, 2009 2:13 AM

Reply
22 replies

Nov 5, 2009 6:05 AM in response to Neil Cudmore

You are going down the wrong road and risk messing permissions and the mail system up.

The socket gets created by Cyrus when it starts. The socket not being there, implies that Cyrus is not able to start up (at least partially) properly.

Try and issue:
ps U _cyrus
(this should tell you if and which Cyrus processes are running).

Next make sure logging level for IMAP is set to "Information".
Stop and start mail services:
sudo serveradmin stop mail
sudo serveradmin start mail
and see if /var/log/mailaccess.log and /var/log/system.log show any Cyrus related errors.

HTH,
Alex

Nov 5, 2009 7:05 AM in response to pterobyte

Thanks Alex..
Just checked and got the following after the restart..

email:~ root# ps U _cyrus
PID TT STAT TIME COMMAND
13418 ?? Ss 0:00.02 master -l 256
13462 ?? S 0:00.01 idled
13464 ?? S 0:00.03 lmtpd

email:~ root# tail /var/log/mailaccess.log
Nov 5 14:46:11 email master[13464]: about to exec /usr/bin/cyrus/bin/lmtpd
Nov 5 14:46:11 email ctl_cyrusdb[13463]: checkpointing cyrus databases
Nov 5 14:46:11 email lmtpunix[13464]: executed
Nov 5 14:46:11 email ctl_cyrusdb[13463]: archiving database file: /var/imap/annotations.db
Nov 5 14:46:11 email ctl_cyrusdb[13463]: archiving log file: /var/imap/db/log.0000000001
Nov 5 14:46:11 email ctl_cyrusdb[13463]: archiving database file: /var/imap/mailboxes.db
Nov 5 14:46:11 email ctl_cyrusdb[13463]: archiving log file: /var/imap/db/log.0000000001
Nov 5 14:46:12: --- last message repeated 1 time ---
Nov 5 14:46:12 email ctl_cyrusdb[13463]: done checkpointing cyrus databases
Nov 5 14:46:12 email master[13418]: process 13463 exited, status 0

email:~ root# tail /var/log/system.log
Nov 5 14:58:35 email com.apple.launchd[1] (edu.cmu.andrew.cyrus.master[14549]): Stray process with PGID equal to this dead job: PID 14550 PPID 1 ctl_cyrusdb
Nov 5 14:58:35 email com.apple.launchd[1] (edu.cmu.andrew.cyrus.master[14549]): Exited abnormally: User defined signal 1
Nov 5 14:58:35 email master[14584]: process started
Nov 5 14:58:50 email ctl_cyrusdb[14585]: verifying cyrus databases
Nov 5 14:58:50 email ctl_cyrusdb[14585]: skiplist: recovered /var/imap/mailboxes.db (35 records, 6880 bytes) in 0 seconds
Nov 5 14:58:51 email ctl_cyrusdb[14585]: skiplist: recovered /var/imap/annotations.db (0 records, 144 bytes) in 1 second
Nov 5 14:59:19 email ctl_cyrusdb[14585]: done verifying cyrus databases
Nov 5 14:59:19 email master[14584]: Cyrus POP/IMAP Server v2.3.8 ready for work
Nov 5 14:59:19 email ctl_cyrusdb[14640]: checkpointing cyrus databases
Nov 5 14:59:20 email ctl_cyrusdb[14640]: done checkpointing cyrus databases

email:~ root# tail /var/log/mailaccess.log
Nov 5 14:59:19 email master[14641]: about to exec /usr/bin/cyrus/bin/lmtpd
Nov 5 14:59:19 email ctl_cyrusdb[14640]: checkpointing cyrus databases
Nov 5 14:59:19 email ctl_cyrusdb[14640]: archiving database file: /var/imap/annotations.db
Nov 5 14:59:19 email lmtpunix[14641]: executed
Nov 5 14:59:20 email ctl_cyrusdb[14640]: archiving log file: /var/imap/db/log.0000000001
Nov 5 14:59:20 email ctl_cyrusdb[14640]: archiving database file: /var/imap/mailboxes.db
Nov 5 14:59:20 email ctl_cyrusdb[14640]: archiving log file: /var/imap/db/log.0000000001
Nov 5 14:59:20: --- last message repeated 1 time ---
Nov 5 14:59:20 email ctl_cyrusdb[14640]: done checkpointing cyrus databases
Nov 5 14:59:20 email master[14584]: process 14640 exited, status 0

So all looks OK to me at this point

Nov 5, 2009 7:54 AM in response to pterobyte

Still no joy 😟

But, the error in mail.log has changed??? to

/var/spool/postfix/cyrus-socket/lmtp]: Socket operation on non-socket



email:~ root# tail /var/log/mailaccess.log
Nov 5 15:43:25 email imaps[36260]: starttls: TLSv1 with cipher AES128-SHA (128/128 bits reused) no authentication
Nov 5 15:43:25 email imaps[36260]: AOD: mbr check_servicemembership with access allservices
Nov 5 15:43:25 email imaps[36260]: AOD: mail service ACL NOT enabled
Nov 5 15:43:25 email imaps[36260]: login: Neils-intel-iMac.newashgreen.net [192.168.1.14] ncudmore CRAM-MD5+TLS User logged in
Nov 5 15:43:25 email imaps[36260]: quota set to "unlimited" for mailbox user.ncudmore
Nov 5 15:43:25 email imaps[36258]: seen_db: user ncudmore opened /var/imap/user/n/ncudmore.seen
Nov 5 15:43:25 email imaps[36258]: open: user ncudmore opened Deleted Messages
Nov 5 15:43:25 email imaps[36258]: SQUAT failed to open index file
Nov 5 15:43:25 email imaps[36258]: SQUAT failed
Nov 5 15:43:25 email imaps[36258]: Expunged 17 messages from user.ncudmore.Deleted Messages

email:~ root# tail /var/log/system.log
Nov 5 15:45:21 email postfix/tlsmgr[36435]: warning: encryption keys etc. may be predictable
Nov 5 15:45:35 email org.amavis.amavisd_cleanup[36463]: find:
Nov 5 15:45:35 email org.amavis.amavisd_cleanup[36463]: /var/amavis/tmp/amavis-20091103T235142-04569/parts: Permission denied
Nov 5 15:45:35 email org.amavis.amavisd_cleanup[36463]: find:
Nov 5 15:45:35 email org.amavis.amavisd_cleanup[36463]: /var/amavis/tmp/amavis-20091103T235142-04569/parts: Permission denied
Nov 5 15:45:49 email postfix/tlsmgr[36487]: warning: no entropy source specified with parameter tls randomsource
Nov 5 15:45:49 email postfix/tlsmgr[36487]: warning: encryption keys etc. may be predictable
Nov 5 15:46:00 email postfix/smtpd[36485]: warning: 192.211.85.209.multi.uribl.com: RBL lookup error: Host or domain name not found. Name service error for name=192.211.85.209.multi.uribl.com type=A: Host not found, try again
Nov 5 15:46:50 email postfix/tlsmgr[36575]: warning: no entropy source specified with parameter tls randomsource
Nov 5 15:46:50 email postfix/tlsmgr[36575]: warning: encryption keys etc. may be predictable


email:~ root# tail /var/log/mail.log
Nov 5 15:46:50 email postfix/smtpd[36574]: connect from localhost[127.0.0.1]
Nov 5 15:46:50 email postfix/smtpd[36574]: 992AE3E25AF: client=localhost[127.0.0.1]
Nov 5 15:46:50 email postfix/cleanup[36579]: 992AE3E25AF: message-id=<686368ca0911050745o51fe360aia9f6e0f3170a8ba9@mail.gmail.com>
Nov 5 15:46:50 email postfix/qmgr[36545]: 992AE3E25AF: from=<ncudmore@googlemail.com>, size=2305, nrcpt=1 (queue active)
Nov 5 15:46:50 email postfix/smtp[36504]: 495CC3E2594: to=<ncudmore@newashgreen.net>, relay=127.0.0.1[127.0.0.1]:10024, delay=61, delays=11/0.05/0.1/50, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=35674-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 992AE3E25AF)
Nov 5 15:46:51 email postfix/lmtp[36581]: 992AE3E25AF: to=<ncudmore@newashgreen.net>, relay=none, delay=0.42, delays=0.12/0.11/0.19/0, dsn=4.4.1, status=deferred (connect to mserver.newashgreen.net[/var/spool/postfix/cyrus-socket/lmtp]: Socket operation on non-socket)
Nov 5 15:47:27 email postfix/postfix-script[36632]: refreshing the Postfix mail system
Nov 5 15:47:27 email postfix/master[35600]: reload configuration /etc/postfix
Nov 5 15:47:27 email postfix/qmgr[36636]: 495CC3E2594: from=<ncudmore@googlemail.com>, size=1837, nrcpt=1 (queue active)
Nov 5 15:47:27 email postfix/qmgr[36636]: 495CC3E2594: removed

email:~ root# ps U _cyrus
PID TT STAT TIME COMMAND
35711 ?? Ss 0:00.06 master -l 256
35764 ?? S 0:00.77 idled
35766 ?? S 0:00.06 lmtpd
36251 ?? S 0:00.32 imapd: Neils-intel-iMac.newashgreen.net [192.168.1.14] ncudmore user.ncu
36257 ?? R 1:09.67 imapd: Neils-intel-iMac.newashgreen.net [192.168.1.14] ncudmore user.ncu
36258 ?? S 0:00.09 imapd: Neils-intel-iMac.newashgreen.net [192.168.1.14] ncudmore user.ncu
36259 ?? S 0:00.07 imapd: Neils-intel-iMac.newashgreen.net [192.168.1.14] ncudmore
36260 ?? S 0:00.07 imapd: Neils-intel-iMac.newashgreen.net [192.168.1.14] ncudmore


email:~ root# ls -la /var/imap/socket
total 0
drwxr-xr-x 5 _cyrus mail 170 Nov 5 15:43 .
drwxr-xr-x 17 _cyrus mail 578 Nov 5 15:43 ..
srwxrwxrwx 1 _cyrus mail 0 Nov 5 15:37 idle
-rw------- 1 _cyrus mail 0 Nov 5 15:43 imaps-1.lock
-rw------- 1 _cyrus mail 0 Nov 5 15:37 lmtpunix-0.lock

Nov 5, 2009 8:44 AM in response to pterobyte

opps...

You're right I restored an earlier postfix main.cf which was incorrect.....

Back to the error saying :-

Nov 5 16:41:28 email postfix/lmtp[41433]: EFF393E2778: to=<ncudmore@newashgreen.net>, relay=none, delay=88851, delays=88850/0.34/0.02/0, dsn=4.4.1, status=deferred (connect to mserver.newashgreen.net[/var/imap/socket/lmtp]: No such file or directory)

Back to square one 😟

Nov 6, 2009 6:33 AM in response to pterobyte

I think so.... Dates look fine on the restored versions. But you know what it's like, just because it's from a period when the server was working, it will not mean that was the active configuration running at the time.

The server was up for 52 days, and only after a reboot following 10.5.8 being applied did I get any problems.

Doubt, the 10.5.8 from 10.5.7 had anything to do with this but....

Nov 6, 2009 8:32 AM in response to pterobyte

Some progress....

I can now see

email:~ root# ls -la /var/imap/socket
total 0
drwxr-xr-x 6 _cyrus mail 204 Nov 6 16:24 .
drwxr-xr-x 18 _cyrus mail 612 Nov 6 16:24 ..
srwxrwxrwx 1 _cyrus mail 0 Nov 6 16:24 idle
-rw------- 1 _cyrus mail 0 Nov 5 15:43 imaps-1.lock
srwxrwxrwx 1 root mail 0 Nov 6 16:24 lmtp
-rw------- 1 _cyrus mail 0 Nov 5 15:37 lmtpunix-0.lock


so I can now see the lmtp socket, but it's a root process... but now also getting

Nov 6 16:30:24 email postfix/lmtp[82355]: 7DB073E4A83: to=<ncudmore@newashgreen.net>, relay=email.newashgreen.net[/var/imap/socket/lmtp], delay=7179, delays=7179/0.04/0.31/0.07, dsn=5.1.1, status=bounced (host email.newashgreen.net[/var/imap/socket/lmtp] said: 550-Mailbox unknown. Either there is no mailbox associated with this 550-name or you do not have authorization to see it. 550 5.1.1 User unknown (in reply to RCPT TO command))

going to chown the socket to _cyrus and see where that leaves me....

Nov 7, 2009 1:35 AM in response to Neil Cudmore

Well I chowned the socket to _cyrus:mail, but that's not the problem, as when I restarted the mail

sudo serveradmin start mail

It's ownership went back to root:mail.

So, it look's like now Cyrus can't see the Open directory for delivery. I confirmed this by creating a new account for testing (Fred Flintstone), and whilst I can connect to the server via imap and send email out bound from Fred's account; inbound it's being rejected, then sending back a NDR:-

Nov 7 00:53:28 email postfix/smtp[23100]: C8C9B3E67FD: to=<fflintstone@newashgreen.net>, relay=127.0.0.1[127.0.0.1]:10024, delay=31, delays=0.59/0/0.03/31, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=22936-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as D0E9A3E6818)
Nov 7 00:53:28 email postfix/qmgr[22948]: C8C9B3E67FD: removed
Nov 7 00:53:29 email postfix/smtp[23295]: 18FF63E681C: to=<ncudmore@googlemail.com>, relay=gmail-smtp-in.l.google.com[209.85.219.13]:25, delay=1.1, delays=0.01/0.04/0.26/0.83, dsn=2.0.0, status=sent (250 2.0.0 OK 1257555209 17si1200957ewy.47)
Nov 7 00:53:29 email postfix/qmgr[22948]: 18FF63E681C: removed



in googlemail:-

Final-Recipient: rfc822; fflintstone@newashgreen.net
Original-Recipient: rfc822;fflintstone@newashgreen.net
Action: failed
Status: 5.1.1
Remote-MTA: dns; email.newashgreen.net
Diagnostic-Code: smtp; 550-Mailbox unknown. Either there is no mailbox
associated with this 550-name or you do not have authorization to see it.
550 5.1.1 User unknown

Nov 9, 2009 4:22 PM in response to pterobyte

Ahh eureka !

Look's like it's all down to the OD not working correctly.....

Set up a local user and rebooted the whole darn server, and got the following error showing in the system log...

Nov 9 23:33:33 email lmtpunix[69896]: AOD: user opts: get attributes for user: ncudmore@newashgreen.net failed with error: -14479
Nov 9 23:33:33 email lmtpunix[69896]: warning: unable to post message for user: ncudmore@newashgreen.net, mail is not enabled for this user

Checked in Workgroup Manager and yes, I did have mail enabled for myself... changed the setting from POP and IMAP to just IMAP and re-saved and still nothing..

Checked the LDAP Log and can see

Nov 9 23:29:14 email slapd[46]: <= bdb substringcandidates: (authAuthority) index_param failed (18)
Nov 9 23:38:25 email slapd[46]: @(#) $OpenLDAP: slapd 2.3.27 (Jun 17 2009 19:09:12) $
Nov 9 23:38:29 email slapd[46]: overlay_config(): warning, overlay "dynid" already in list
Nov 9 23:38:45: --- last message repeated 4 times ---

Changed my email setting to forward email to my google account and this works fine..... Change it back and:-

Nov 10 00:19:31 email lmtpunix[3568]: AOD: user opts: get attributes for user: ncudmore@newashgreen.net failed with error: -14479
Nov 10 00:19:31 email lmtpunix[3568]: warning: unable to post message for user: ncudmore@newashgreen.net, mail is not enabled for this user

postfix/lmtp errors....

Welcome to Apple Support Community
A forum where Apple customers help each other with their products. Get started with your Apple Account.