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
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
final thought of the night .... OD sort of knows what's going on still as thanks to my iphone still attempting to connect I can see
Nov 10 01:30:07 email bootpd[5103]: ACK sent Neils-iPhone 192.168.1.3 pktsize 310
Nov 10 01:30:11 email imaps[4537]: starttls: TLSv1 with cipher AES128-SHA (128/128 bits new) no authentication
Nov 10 01:30:11 email imaps[4537]: badlogin from: [192.168.1.3]. CRAM-MD5 user: ncudmore. auto-forwarding is enabled for this user
......
All I need to do now it get the darn thing to deliver to the right place.... and not forward email now.... no wait that's where this whole thing started....
Well, I wiped the OD (changed the server into stand alone server, then created a new OD) on Friday, and it worked.....
for 3 days, now it's back to square one.. email being bounced
Nov 17 12:24:40 email postfix/lmtp[15476]: 1FA6A40065A: to=<ncudmore@newashgreen.net>, relay=email.newashgreen.net[/var/imap/socket/lmtp], delay=783, delays=782/0.09/0.87/0.19, 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))
I can however see in the logs the additional error
Nov 17 12:24:40 email lmtpunix[15477]: AOD: user opts: get attributes for user: ncudmore@newashgreen.net failed with error: -14479
Nov 17 12:24:40 email lmtpunix[15477]: warning: unable to post message for user: ncudmore@newashgreen.net, mail is not enabled for this user
in the system log.
Tried a LDAP browser, on the OD, but it seems the macmail is a binary value (never looked at that before!)
I ran:-
email:bin root# ./chk_cyrus
Examining partition: ALL PARTITIONS
-snip-
checking: user.ncudmore (/var/spool/imap/user/ncudmore)
-> 7856 records
checking: user.ncudmore.Apple Mail To Do (/var/spool/imap/user/ncudmore/Apple Mail To Do)
-> 1 records
checking: user.ncudmore.Deleted Items (/var/spool/imap/user/ncudmore/Deleted Items)
-> 2 records
checking: user.ncudmore.Deleted Messages (/var/spool/imap/user/ncudmore/Deleted Messages)
-> 14 records
checking: user.ncudmore.Drafts (/var/spool/imap/user/ncudmore/Drafts)
-> 7 records
checking: user.ncudmore.Junk (/var/spool/imap/user/ncudmore/Junk)
-> 0 records
checking: user.ncudmore.Junk E-mail (/var/spool/imap/user/ncudmore/Junk E-mail)
-> 0 records
checking: user.ncudmore.Sent Items (/var/spool/imap/user/ncudmore/Sent Items)
-> 1 records
checking: user.ncudmore.Sent Messages (/var/spool/imap/user/ncudmore/Sent Messages)
-> 561 records
checking: user.ncudmore.Trash (/var/spool/imap/user/ncudmore/Trash)
-> 0 records
-snip-
and this looked ok. But in the system log it showed the following:-
Nov 18 09:27:57 email ctl_cyrusdb[16623]: checkpointing cyrus databases
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: DB
ENV->logflush: LSN of 1/26904 past current end-of-log of 1/3256
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: Database environment corrupt; the wrong log files may have been removed or incompatible database files imported from another environment
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: /var/imap/tls_sessions.db: unable to flush page: 0
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: txn_checkpoint: failed to flush the buffer cache Invalid argument
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR: couldn't checkpoint: Invalid argument
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR: sync /var/imap/db: cyrusdb error
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: DB
ENV->logflush: LSN of 1/26904 past current end-of-log of 1/3256
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: Database environment corrupt; the wrong log files may have been removed or incompatible database files imported from another environment
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: /var/imap/tls_sessions.db: unable to flush page: 0
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: txn_checkpoint: failed to flush the buffer cache Invalid argument
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR: couldn't checkpoint: Invalid argument
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR: sync /var/imap/db: cyrusdb error
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: DB
ENV->logflush: LSN of 1/26904 past current end-of-log of 1/3256
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: Database environment corrupt; the wrong log files may have been removed or incompatible database files imported from another environment
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: /var/imap/tls_sessions.db: unable to flush page: 0
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR db4: txn_checkpoint: failed to flush the buffer cache Invalid argument
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR: couldn't checkpoint: Invalid argument
Nov 18 09:27:57 email ctl_cyrusdb[16623]: DBERROR: sync /var/imap/db: cyrusdb error
Nov 18 09:27:57 email ctl_cyrusdb[16623]: done checkpointing cyrus databases
I can connect via IMAP and read, email, send external e-mail. I tried the following:-
email:bin root# sudo serveradmin stop mail
email:bin root# /usr/bin/cyrus/bin/reconstruct -i
which solved the problems shown by
./chk_cyrus
but to no avail....
One thing to note here is in my postfix/main.cf I have the following set:-
unknown
local_recipient_rejectcode = 450
So, getting all email being bounced with 550 errors would imply it could be a permissions issue. So, I checked the /private/var/spool/imap/user directory:-
drwx------ 10 _cyrus mail 340 Nov 10 22:26 user
and then my directory below that:-
drwx------ 7870 _cyrus mail 267580 Nov 18 09:45 ncudmore
and that look's OK.
In the GUI server manager, it shows all 8 accounts fine but all show with 0mb quota and Used 0mb, and the data store mail size and database location both show as 0mb.
After running a reconstruct on the accounts in the GUI they still show as 0mb, but at least in the Data Store, the mail store location now shows as 1.15GB and the database size as 313.39 mb.
No errors shown, until I change the mail settings back to receive email in place of forwarding it toto my google account....
I changed my mail settings in workgroup manager to the server in place of forward, then rebooted the whole server...
The following logs are all after the reboot...
system.log:-
Nov 20 12:10:01 email lmtpunix[551]: AOD: user opts: get attributes for user: ncudmore@newashgreen.net failed with error: -14479
Nov 20 12:10:01 email lmtpunix[551]: warning: unable to post message for user: ncudmore@newashgreen.net, mail is not enabled for this user
Nov 20 12:11:07 email authorizationhost[179]: MechanismInvoke 0x12e590 retainCount 2
Nov 20 12:11:08 email SecurityAgent[184]: MechanismInvoke 0x101650 retainCount 1
Nov 20 12:11:09 email SecurityAgent[184]: NSSecureTextFieldCell detected a field editor ((null)) that is not a NSTextView subclass designed to work with the cell. Ignoring...
Nov 20 12:11:09 email SecurityAgent[184]: NSExceptionHandler has recorded the following exception:\nNSRangeException --
* -[NSCFArray objectAtIndex:]: index (0) beyond bounds (0)\nStack trace: 0x39dbc 0x93c474ec 0x95b30c00 0x95b30c38 0x94a62180 0x709c8 0x5bee4 0x6edd8 0x637b4 0x68368 0x774a4 0xe068 0x14200 0x13f64 0xdb58 0x94a998f0 0x95aa126c 0x95ac3634 0x924c7b18 0x924c793c 0x924c777c 0x95c0b248 0x95c0ac00 0x95c048a0 0x11e14 0x2db0
mailaccess.log shows:-
Nov 20 12:10:01 email lmtpunix[551]: AOD: user opts: get attributes for user: ncudmore@newashgreen.net failed with error: -14479
Nov 20 12:10:01 email lmtpunix[551]: warning: unable to post message for user: ncudmore@newashgreen.net, mail is not enabled for this user
and mail.log shows the following for the conversation between google and home:-
Nov 20 12:10:00 email postfix/smtpd[544]: 65FFC4084ED: client=localhost[127.0.0.1]
Nov 20 12:10:00 email postfix/cleanup[548]: 65FFC4084ED: message-id=<39DE6FA9-9E85-42DB-AA15-417BCE780CD2@gmail.com>
Nov 20 12:10:00 email postfix/qmgr[542]: 65FFC4084ED: from=<ncudmore@googlemail.com>, size=2502, nrcpt=1 (queue active)
Nov 20 12:10:00 email postfix/smtp[522]: D60494084DC: to=<ncudmore@newashgreen.net>, relay=127.0.0.1[127.0.0.1]:10024, delay=37, delays=31/0.15/0.03/6.1, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=00439-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 65FFC4084ED)
Nov 20 12:10:01 email postfix/lmtp[550]: 65FFC4084ED: to=<ncudmore@newashgreen.net>, relay=email.newashgreen.net[/var/imap/socket/lmtp], delay=0.92, delays=0.03/0.1/0.69/0.1, 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))
Nov 20 12:10:01 email postfix/cleanup[548]: 509FD4084F1: message-id=<20091120121001.509FD4084F1@email.newashgreen.net>
Nov 20 12:10:01 email postfix/qmgr[542]: 509FD4084F1: from=, size=4777, nrcpt=1 (queue active)
Nov 20 12:10:01 email postfix/bounce[554]: 65FFC4084ED: sender non-delivery notification: 509FD4084F1
Nov 20 12:10:01 email postfix/qmgr[542]: 65FFC4084ED: removed
Nov 20 12:10:01 email postfix/qmgr[542]: D60494084DC: from=<ncudmore@googlemail.com>, size=2038, nrcpt=1 (queue active)
Nov 20 12:10:01 email postfix/qmgr[542]: D60494084DC: removed
Nov 20 12:10:02 email postfix/smtp[555]: 509FD4084F1: to=<ncudmore@googlemail.com>, relay=gmail-smtp-in.l.google.com[209.85.219.57]:25, delay=1.4, delays=0.01/0.02/0.34/1, dsn=2.0.0, status=sent (250 2.0.0 OK 1258719002 25si4103344ewy.33)
Nov 20 12:10:02 email postfix/qmgr[542]: 509FD4084F1: removed
Nov 20 12:10:25 email postfix/smtpd[475]: disconnect from mail-fx0-f215.google.com[209.85.220.215]
So, postfix seems fine, it's still an issue with cyrus/OD from what I can tell.....