Cyrus stopped sending mails until after reboot - why?

[Patrick Boutilier]

On 03/28/2012 08:24 AM, steffen-winkler at gmx.de wrote:
> Hi there,
>
> so last week our Cyrus stopped sending emails, we looked into several log files but as it seemed, nothing was logged so we stopped/started several services and after that didn't helped we rebooted the server which made Cyrus work again *yay*.
>
> Today I finally had the time to again take a look at the log files and found a warn.log which was last changed on the day Cyrus had problems, the size is ~100 megabytes.
>
> I hope that someone can help me figuring out what went wrong and why. (interesting side note: just shortly before the first entry in the log file appears, a backup of the mail databases was created by cyrus, I've no clue why. There is no such cron job and Cyrus never did that before and has not done it since that day)
>
> [code]
> Mar 21 16:00:16 mail pop3[22340]: dracauth: localhost: RPC: Program not registered
> Mar 21 16:00:16 mail pop3[22340]: DRAC notifications disabled
> Mar 21 16:00:16 mail pop3[18765]: dracauth: localhost: RPC: Program not registered
> [/code]
>
> that fills the first 176 lines over a time of 1 minute and 27 seconds and for 22 seconds, nothing happens. Then something new appears:
>
> [code]
> Mar 21 16:01:55 mail lmtp[20480]: unable to sendto() notify socket: No such file or directory
> [/code]
> then, after 8 seconds of nothing, the DRAC stuff continues for about 1 minute and 40 seconds, including two of those sendto() lines, then this appears
>
> [code]
> Mar 21 16:03:33 mail pop3[22380]: DRAC notifications disabled
> Mar 21 16:03:33 mail lmtp[20480]: unable to sendto() notify socket: No such file or directory
> Mar 21 16:03:42 mail imaps[20637]: dracconn: localhost: RPC: Program not registered
> Mar 21 16:03:42 mail imaps[20637]: DRAC notifications disabled
> Mar 21 16:03:43 mail imap[21658]: IOERROR: servername.net!user.support zero index/expunge record 960/960
> Mar 21 16:03:43 mail imap[20638]: dracconn: localhost: RPC: Program not registered
> Mar 21 16:03:43 mail imap[20638]: DRAC notifications disabled
> Mar 21 16:03:48 mail imap[20639]: dracconn: localhost: RPC: Program not registered
> [/code]
> after that it's again the usual dracauth stuff with some of those sendto() lines mixed in. Later this line combination joins the party
>
> [code]
> Mar 21 16:04:49 mail lmtp[20480]: unable to sendto() notify socket: No such file
>   or directory
> Mar 21 16:05:02 mail syslog-ng[3283]: last message repeated 2 times
> Mar 21 16:05:02 mail lmtp[20480]: unable to sendto() notify socket: No such file or directory
> [/code]
>
> and after some more lines
> [code]
> Mar 21 16:05:49 mail imaps[22390]: idle for too long, closing connection
> [/code]
> imap seems to lose it's patience.
> (we are now at 497 lines of text, just so you know)
>
> after two more minutes (and 100 lines of text) the imap deamon decided to jump the cliff aswell
>
> [code]
> Mar 21 16:07:09 mail imap[20690]: DBERROR db4: Logging region out of memory; you may need to increase its size
> Mar 21 16:07:09 mail imap[20690]: DBERROR: opening /mnt/Data/mail/lib/imap/annotations.db: Cannot allocate memory
> Mar 21 16:07:09 mail imap[20690]: DBERROR: opening /mnt/Data/mail/lib/imap/annotations.db: cyrusdb error
> Mar 21 16:07:09 mail imap[20690]: Fatal error: can't read annotations file
> Mar 21 16:07:09 mail master[15362]: service imap pid 20690 in READY state: terminated abnormally
> Mar 21 16:07:09 mail imap[20691]: dracconn: localhost: RPC: Program not registered
> [/code]
>
> (aside from the lines mentioned above, now the imap deamon is starterd over and over again...PER SECOND(which results in several thousand lines of text), always terminating with the above DBERRORs and every few seconds a DRACATUH message is in there again.)
>
> after just a few seconds (and 8thousand lines of log messages) this line combination appears:
> [code]
> Mar 21 16:07:17 mail imap[21851]: DBERROR db4: Logging region out of memory; you may need to increase its size
> Mar 21 16:07:17 mail imap[21851]: DBERROR: opening /mnt/Data/mail/lib/imap/mailboxes.db: Cannot allocate memory
> Mar 21 16:07:17 mail imap[21851]: DBERROR: opening /mnt/Data/mail/lib/imap/mailboxes.db: cyrusdb error
> [/code]
>
> after half an hour, the whole thing seems to calm down
> [code]
> Mar 21 16:38:15 mail postfix/smtpd[26855]: warning: network_biopair_interop: err
> or reading 5 bytes from the network: Connection reset by peer
> Mar 21 16:46:55 mail postfix/smtpd[26934]: warning: network_biopair_interop: err
> or reading 5 bytes from the network: Connection reset by peer
> Mar 21 16:52:46 mail postfix/pipe[26813]: warning: pipe_command_read: read time
> limit exceeded
> [/code]
>
> the pipe log message repeats for a few more entries, after that it was first detected that the mail server wasn't sending emails (received them without a problem) and we stopped it.
>
> Hope someone can make sense out of this.
>
> - Steffen
>


Looks to me like your machine may have run out of memory.

Also, Cyrus doesn't send mail. That is what postfix does.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: boutilpj.vcf
Type: text/x-vcard
Size: 286 bytes
Desc: not available
Url : http://lists.andrew.cmu.edu/pipermail/info-cyrus/attachments/20120328/70da4c2b/attachment.vcf