OSX Server.App Mail Server Not Starting

Question

I'm having an issue that I've had before, but I've never come up with a solution. I have a Mac Mail server set up using Server.App, and occasionally the server will just stop working, and when I try to restart it, it will freeze on the "starting" screen.

If I try to run sudo serveradmin fullstatus mail, I get this:

mail:startedTime = "2014-05-08 01:34:36 +0000"
mail:setStateVersion = 1
mail:state = "STARTING"
mail:protocolsArray:_array_index:0:status = "ON"
mail:protocolsArray:_array_index:0:kind = "INCOMING"
mail:protocolsArray:_array_index:0:protocol = "IMAP"
mail:protocolsArray:_array_index:0:state = "RUNNING"
mail:protocolsArray:_array_index:0:service = "MailAccess"
mail:protocolsArray:_array_index:0:error = ""
mail:protocolsArray:_array_index:1:status = "ON"
mail:protocolsArray:_array_index:1:kind = "INCOMING"
mail:protocolsArray:_array_index:1:protocol = "POP3"
mail:protocolsArray:_array_index:1:state = "RUNNING"
mail:protocolsArray:_array_index:1:service = "MailAccess"
mail:protocolsArray:_array_index:1:error = ""
mail:protocolsArray:_array_index:2:status = "OFF"
mail:protocolsArray:_array_index:2:kind = "INCOMING"
mail:protocolsArray:_array_index:2:protocol = "SMTP"
mail:protocolsArray:_array_index:2:state = "STOPPED"
mail:protocolsArray:_array_index:2:service = "MailTransferAgent"
mail:protocolsArray:_array_index:2:error = ""
mail:protocolsArray:_array_index:3:status = "OFF"
mail:protocolsArray:_array_index:3:kind = "OUTGOING"
mail:protocolsArray:_array_index:3:protocol = "SMTP"
mail:protocolsArray:_array_index:3:state = "STOPPED"
mail:protocolsArray:_array_index:3:service = "MailTransferAgent"
mail:protocolsArray:_array_index:3:error = ""
mail:protocolsArray:_array_index:4:status = "OFF"
mail:protocolsArray:_array_index:4:kind = "INCOMING"
mail:protocolsArray:_array_index:4:protocol = ""
mail:protocolsArray:_array_index:4:state = "STOPPED"
mail:protocolsArray:_array_index:4:service = "ListServer"
mail:protocolsArray:_array_index:4:error = ""
mail:protocolsArray:_array_index:5:status = "ON"
mail:protocolsArray:_array_index:5:kind = "INCOMING"
mail:protocolsArray:_array_index:5:protocol = ""
mail:protocolsArray:_array_index:5:state = "STOPPED"
mail:protocolsArray:_array_index:5:service = "JunkMailFilter"
mail:protocolsArray:_array_index:5:error = "Warning: Mail filtering service is enabled but not running"
mail:protocolsArray:_array_index:6:status = "ON"
mail:protocolsArray:_array_index:6:kind = "INCOMING"
mail:protocolsArray:_array_index:6:protocol = ""
mail:protocolsArray:_array_index:6:state = "STOPPED"
mail:protocolsArray:_array_index:6:service = "VirusScanner"
mail:protocolsArray:_array_index:6:error = "Warning: Virus scanning service is enabled but not running"
mail:protocolsArray:_array_index:7:status = "ON"
mail:protocolsArray:_array_index:7:kind = "INCOMING"
mail:protocolsArray:_array_index:7:protocol = ""
mail:protocolsArray:_array_index:7:state = "STOPPED"
mail:protocolsArray:_array_index:7:service = "VirusDatabaseUpdater"
mail:protocolsArray:_array_index:7:error = "Warning: Virus scanning service is enabled but the virus database updater is not running"
mail:logPaths:Server Error Log = "/Library/Logs/Mail/mail-err.log"
mail:logPaths:IMAP Log = "/Library/Logs/Mail/mail-info.log"
mail:logPaths:Server Log = "/Library/Logs/Mail/mail-info.log"
mail:logPaths:POP Log = "/Library/Logs/Mail/mail-info.log"
mail:logPaths:SMTP Log = "/var/log/mail.log"
mail:logPaths:List Server Log = "/Library/Logs/Mail/listserver.log"
mail:logPaths:Migration Log = "/Library/Logs/MailMigration.log"
mail:logPaths:Virus Log = "/Library/Logs/Mail/clamav.log"
mail:logPaths:Amavisd Log = "/Library/Logs/Mail/amavis.log"
mail:logPaths:Virus DB Log = "/Library/Logs/Mail/freshclam.log"
mail:imapStartedTime = "2014-05-08 01:34:36 +0000"
mail:postfixStartedTime = ""
mail:servicePortsRestrictionInfo = _empty_array
mail:servicePortsAreRestricted = "NO"
mail:connectionCount = 25
mail:readWriteSettingsVersion = 1
mail:serviceStatus = "ENABLED"

It appears that SMTP isn't starting and is blocking the rest. I can't find any useful information in my logs. The last time this happened, I had to start fresh with a new server, but the server has grown to the point that this is no longer feasible. Any ideas?

UPDATE:

Per the answer below:

When I try to telnet, I get connection refused errors. Also, running ps ax didn't show the master line.

My /var/log/mail.log looks like this when cycling the server:

May  7 23:07:23 mail.thoughtspacedesigns.com servermgrd[113]: servermgr_swupdate[INF]: Verifying Software Update catalog configuration.
May  7 23:07:23 mail.thoughtspacedesigns.com servermgrd[113]: --Module servermgr_swupdate's response has retain count of 4.

That's the only thing that popped this time. Other times I haven't been getting any response.

Also, in server.app is a "mail server log" in the logs section. When I cycle the switch, the only thing that appears is this:

May 07 23:07:21 master: Info: Dovecot v2.2.5 starting up (core dumps disabled)

Answer 1

The first thing I'd try is seeing if you can talk to the SMTP server.

Telnet to port 25 on the server, on the command line of the server it would be telnet locahost 25 and the server should reply

Trying ::1...
Connected to localhost.
Escape character is '^]'.
220 <servername> ESMTP Postfix

(If you do connect then just type "quit" followed by return to exit.)

If not then check to see if master is running with ps ax | grep master which should give a line like

29   ??  Ss     0:05.48 master -c /Library/Server/Mail/Config/postfix

Then have a close look at /var/log/mail.log and try sending yourself some mail at your server address and see what happens.

If the telnet doesn't work and there is no 'master' process working then postfix is borked. You need to figure out why. If you run:

master -d -v -v -c /Library/Server/Mail/Config/postfix

you will be able to watch the postfix 'master' process start up and then in anther terminal window try the telnet trick again. This should give you some more useful information.

Answer 2

This fixed it for me...for macOS Server 5

Follow this article: Setting Logging Levels for Mail Services on OS X Server 5

And set each below.

sudo serveradmin settings mail:postfix:log_level = "info"
sudo serveradmin settings mail:postfix:spam_log_level = “info”
sudo serveradmin settings mail:imap:log_level = "info"
sudo serveradmin settings mail:postfix:log_rolling_days_enabled = yes
sudo serveradmin settings mail:postfix:log_rolling_days = 3

Answer 3

I figured out the issue. It turns out that this is actually a common issue that afflicts OSX Server. Postfix will sometimes corrupt itself when modifying mail server settings. In order to get the server to come back online, I had to replace the /Library/Server/Mail/Config folder with the latest working version. I have Crashplan installed on that computer, so I was able to easily restore the folder back to a previous date with a few clicks, and voila, the server works again.

For those of you not as lucky as me (no backup solution), you can try deleting server.app and reinstalling. The network engineers over at CyberLynk told me this would also repair that folder without destroying any pertinent data (such as email accounts).