5

Our postfix system stops sending mails at night. Every night at 2am it stops picking up mails. The server is a monitoring server, which sends a lot of mails per day. /bin/mail drops the mails in the postdrop queue where postfix pickup picks up the mails and postfix processes the mail. It works the whole day, but on 2am it stops and nothing appears in the logs (even with enabled verbose logging for pickup and cleanup). When I manually restart the postfix service, it begins to deliver the mails from the postdrop queue. What can happen at 2am, that forces postfix to stop working? The cronjobs do not impact postfix

All cronjobs:

mi    h   d  m  w  user                command
01    *   *  *  *  root                /etc/cron.hourly/mcelog.cron
*/10  *   *  *  *  apache              /usr/share/nagiosbp/bin/nagios_bp_session_timeout 2>&1 | logger -t nagios_bp_session_timeout
*/5   *   *  *  *  apache              /usr/bin/php -q /usr/share/centreon/cron/downtimeManager.php >> /var/log/centreon/downtimeManager.log 2>&1
*/5   *   *  *  *  nagios              /usr/share/centreon/bin/nagiosPerfTrace >> /var/log/centreon/nagiosPerfTrace.log 2>&1
*     *   *  *  *  apache              cd /usr/share/thruk && /bin/bash -l -c '/usr/bin/thruk -a bpd' >/dev/null 2>>/var/lib/thruk/cron.log
*     *   *  *  *  apache              /usr/bin/php -q /usr/share/centreon/cron/centAcl.php >> /var/log/centreon/centAcl.log 2>&1
*     *   *  *  *  nagios              /usr/share/centreon/bin/logAnalyser >> /var/log/centreon/logAnalyser.log 2>&1
3     1   *  *  *  $CRONTAB_EXEC_USER  /opt/fan_backup.pl -s
0     2   *  *  *  nagios              /usr/share/centreon/cron/centreonPurge.sh >> /var/log/centreon/centreon-purge.log 2>&1
0     3   *  *  *  nagios              /usr/share/centreon/cron/eventReportBuilder.pl -l >> /var/log/centreon/eventReportBuilder.log 2>&1
30    3   *  *  *  root                /tmp/postfix_restart.sh
02    4   *  *  *  root                /etc/cron.daily/0anacron
02    4   *  *  *  root                /etc/cron.daily/logrotate
02    4   *  *  *  root                /etc/cron.daily/makewhatis.cron
02    4   *  *  *  root                /etc/cron.daily/mlocate.cron
02    4   *  *  *  root                /etc/cron.daily/prelink
02    4   *  *  *  root                /etc/cron.daily/rpm
02    4   *  *  *  root                /etc/cron.daily/tmpwatch
22    4   *  *  0  root                /etc/cron.weekly/0anacron
22    4   *  *  0  root                /etc/cron.weekly/99-raid-check
22    4   *  *  0  root                /etc/cron.weekly/makewhatis.cron
42    4   1  *  *  root                /etc/cron.monthly/0anacron
0     6   *  *  *  nagios              /usr/share/centreon/cron/dashboardBuilder.pl -l >> /var/log/centreon/dashboardBuilder.log 2>&1
33    8   *  *  *  root                /usr/bin/ocsinventory-agent --lazy > /dev/null 2>&1
0     21  *  *  0  root                /opt/fan_backup.pl -s

As workaround we have got a script to restart postfix every night at 3:30

postfix_restart.sh:

mailcount=`/usr/bin/find /var/spool/postfix/maildrop/ -type f | /usr/bin/wc -l`
if [ "$mailcount" -gt "3" ]; then
/bin/date > /tmp/mailTEMP.txt
/usr/sbin/postqueue -p >> /tmp/mailTEMP.txt
echo "Queue maildrop: " >> /tmp/mailTEMP.txt
find /var/spool/postfix/maildrop/ -maxdepth 1 -type f | wc -l >> /tmp/mailTEMP.txt
/sbin/service postfix restart >> /tmp/mailTEMP.txt
/bin/cat /tmp/mailTEMP.txt | /bin/mail -s "Postfix restarted" my@email.com
fi

mail from tonight:

Fri Feb 20 03:30:01 CET 2015
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
DBB4DBF126E      498 Fri Feb 20 02:13:49  nagios
                                         email@address.de
E58C1BF19A6      535 Fri Feb 20 02:12:30  nagios
                                         email@address.de
50D83BF1300      498 Fri Feb 20 02:24:26  nagios
                                         email@address.de
E4AA3BF1A3F      527 Fri Feb 20 02:12:59  nagios
                                         email@address.de
9EEF2BF12D6      498 Fri Feb 20 03:04:01  nagios
                                         email@address.de
76E5BBF13A3      520 Fri Feb 20 03:19:10  nagios
                                         email@address.de
7666FBF139B      528 Fri Feb 20 03:11:36  nagios
                                         email@address.de
C7446BF1122      515 Fri Feb 20 02:11:39  nagios
                                         email@address.de
39715BF12BA      434 Fri Feb 20 02:46:47  nagios
                                         email@address.de
3A62FBF1357      479 Fri Feb 20 03:05:01  nagios
                                         email@address.de
0EF03BF1351      486 Fri Feb 20 03:05:01  nagios
                                         email@address.de
5DC17BF1397      528 Fri Feb 20 02:09:07  nagios
                                         email@address.de
959DFBF1519      441 Fri Feb 20 03:25:06  nagios
                                         email@address.de
9AA25BF1344      478 Fri Feb 20 03:14:01  nagios
                                         email@address.de
55C16BF138D      495 Fri Feb 20 03:05:01  nagios
                                         email@address.de
8E481BF12D0      513 Fri Feb 20 03:01:36  nagios
                                         email@address.de
F2BD7BF13B3      498 Fri Feb 20 03:14:01  nagios
                                         email@address.de
AF2D0BF13A2      548 Fri Feb 20 03:11:36  nagios
                                         email@address.de
44490BF1342      478 Fri Feb 20 03:04:01  nagios
                                         email@address.de
73EEABF1391      487 Fri Feb 20 03:05:01  nagios
                                         email@address.de
422EBBF134D      478 Fri Feb 20 02:34:03  nagios
                                         email@address.de
-- 15 Kbytes in 21 Requests.
Queue maildrop: 21
Shutting down postfix: [  OK  ]
Starting postfix: [  OK  ]

maillog (last successful mail to first successful mail after postfix restart)

Feb 20 01:49:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:49:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:49:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:50:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:50:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:50:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:51:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:51:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:51:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:52:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:52:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:52:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: before input_transp_cleanup: cleanup flags = enable_bad_mail_bounce enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: after input_transp_cleanup: cleanup flags = enable_bad_mail_bounce enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: connect to subsystem public/cleanup
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: public/cleanup socket: wanted attribute: queue_id
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: input attribute name: queue_id
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: input attribute value: B5C60BF10E6
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: public/cleanup socket: wanted attribute: (list terminator)
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: input attribute name: (end)
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: send attr flags = 115
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read T 1424220771 381957
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read A rewrite_context=local
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read F Nagios company name
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read S nagios
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read R email@address.de
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read M
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: uid=100 from=<nagios>
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N To: email@address.de
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N Subject: ** PROBLEM alert - generic-host/Servername is CRITICAL **
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N ***** Autoalert company name Notification *****
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N Notification Type: PROBLEM
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N Service: Servicename
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N Host: generic-host
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N Address: 172.16.20.24
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N State: CRITICAL
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read N Date/Time: Wed Feb 20 01:52:51 CET 2015 Additional Info : CRITICAL: Query expected 1 but got 2.
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read X
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: B5C60BF10E6: read E
Feb 20 01:52:51 lxcentreon postfix/pickup[23795]: public/cleanup socket: wanted attribute: status
Feb 20 01:52:51 lxcentreon postfix/cleanup[26648]: B5C60BF10E6: message-id=<20150218005251.B5C60BF10E6@hostname.int>
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: input attribute name: status
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: input attribute value: 0
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: public/cleanup socket: wanted attribute: reason
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: input attribute name: reason
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: input attribute value: (end)
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: public/cleanup socket: wanted attribute: (list terminator)
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: input attribute name: (end)
Feb 20 01:52:53 lxcentreon postfix/qmgr[24601]: B5C60BF10E6: from=<nagios@email.de>, size=691, nrcpt=1 (queue active)
Feb 20 01:52:53 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:52:53 lxcentreon postfix/smtp[26786]: B5C60BF10E6: to=<email@address.dee>, relay=mx.company.int[172.16.111.222]:25, delay=2.4, delays=2.4/0.01/0/0, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B4FC0418DB5)
Feb 20 01:52:53 lxcentreon postfix/qmgr[24601]: B5C60BF10E6: removed
Feb 20 01:53:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:53:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:53:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:54:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:54:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:54:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:55:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:55:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:55:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:56:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:56:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:56:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:57:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:57:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:57:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:58:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:58:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:58:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 01:59:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 01:59:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 01:59:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 02:00:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 02:00:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 02:00:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 02:01:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 02:01:23 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 02:01:23 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 02:02:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 02:02:59 lxcentreon postfix/pickup[23795]: master_notify: status 0
Feb 20 02:02:59 lxcentreon postfix/pickup[23795]: master_notify: status 1
Feb 20 02:03:23 lxcentreon postfix/pickup[23795]: trigger_server_accept_fifo: trigger arrived
Feb 20 03:30:01 lxcentreon postfix/postfix-script: stopping the Postfix mail system
Feb 20 03:30:01 lxcentreon postfix/master[24598]: terminating on signal 15
Feb 20 03:30:01 lxcentreon postfix/postfix-script: starting the Postfix mail system
Feb 20 03:30:01 lxcentreon postfix/master[18117]: daemon started -- version 2.3.3, configuration /etc/postfix
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  mail
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  ipv4
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: name_mask: ipv4
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  hostname
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  company.int
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  Postfix
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  postfix
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  postfix
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  postdrop
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  hostname, hostname.companyname.int localhost.companyname.int localhost
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: expand $myhostname -> hostname.companyname.int
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  mx.companyname.int
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  /usr/libexec/postfix
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  /var/lib/postfix
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  /usr/sbin
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  /var/spool/postfix
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  pid
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  localhost
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  double-bounce
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  nobody
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  hash:/etc/aliases
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  200600825
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  2.3.3
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  hash
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  deferred, defer
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: expand $mydestination -> hostname, hostname.companyname.int localhost.companyname.int localhost
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: expand $relay_domains -> hostname, hostname.companyname.int localhost.companyname.int localhost
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  TZ MAIL_CONFIG LANG
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  MAIL_CONFIG MAIL_DEBUG MAIL_LOGTAG TZ XAUTHORITY DISPLAY LANG=C
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  subnet
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  +=
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  -=+
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  debug_peer_list,fast_flush_domains,mynetworks,permit_mx_backup_networks,qmqpd_authorized_clients,relay_domains,smtpd_access_maps
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  bounce
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  cleanup
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  defer
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  pickup
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  qmgr
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  rewrite
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  showq
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  error
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  flush
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  verify
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  trace
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  2
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  100s
Feb 20 03:30:01 lxcentreon last message repeated 3 times
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  3600s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  3600s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  100s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  100s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  1000s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  1000s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  10s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  10s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  1s
Feb 20 03:30:01 lxcentreon last message repeated 3 times
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  500s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  500s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  18000s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  18000s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  1s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  1s
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: name_mask: subnet
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: inet_addr_local: configured 2 IPv4 addresses
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: mynetworks: 127.0.0.0/8
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const  127.0.0.0/8
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: dict_eval: const
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: process generation: 1 (1)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: trigger_server_accept_fifo: trigger arrived
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: master_notify: status 0
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: before input_transp_cleanup: cleanup flags = enable_bad_mail_bounce enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: after input_transp_cleanup: cleanup flags = enable_bad_mail_bounce enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: connect to subsystem public/cleanup
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: queue_id
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute name: queue_id
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute value: 77A5FBF1537
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: (list terminator)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute name: (end)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: send attr flags = 115
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read T 1424225521 198348
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read A rewrite_context=local
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read F Nagios companyname
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read S nagios
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read R email@address.de
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read M
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: uid=100 from=<nagios>
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N To: email@address.de
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N Subject: ** PROBLEM alert - generic-host/Windows Uptime is CRITICAL **
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N ***** Autoalert companyname Notification *****
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N Notification Type: PROBLEM
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N Service: Windows Uptime
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N Host: generic-host
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N Address: 172.19.12.102
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N State: CRITICAL
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read N Date/Time: Wed Feb 20 03:12:01 CET 2015 Additional Info : CRITICAL - Socket timeout after 10 seconds
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read X
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 77A5FBF1537: read E
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: status
Feb 20 03:30:01 lxcentreon postfix/cleanup[18125]: 77A5FBF1537: message-id=<20150218023001.77A5FBF1537@hostname.companyname.int>
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute name: status
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute value: 0
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: reason
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute name: reason
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute value: (end)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: (list terminator)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute name: (end)
Feb 20 03:30:01 lxcentreon postfix/qmgr[18124]: 77A5FBF1537: from=<nagios@companyname.de>, size=637, nrcpt=1 (queue active)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: before input_transp_cleanup: cleanup flags = enable_bad_mail_bounce enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: after input_transp_cleanup: cleanup flags = enable_bad_mail_bounce enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: connect to subsystem public/cleanup
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: queue_id
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute name: queue_id
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute value: 8A5D0BF11B4
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: (list terminator)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: input attribute name: (end)
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: send attr flags = 115
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read T 1424226153 324435
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read A rewrite_context=local
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read F Nagios companyname
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read S nagios
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read R email@address.de
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read M
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: uid=100 from=<nagios>
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N To: email@address.de
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N Subject: ** PROBLEM alert - generic-host/hostname is CRITICAL **
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N ***** Autoalert companyname Notification *****
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N Notification Type: PROBLEM
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N Service: servicename
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N Host: generic-host
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N Address: 172.16.20.24
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N State: CRITICAL
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read N Date/Time: Wed Feb 20 03:22:33 CET 2015 Additional Info : CRITICAL: Query expected OK but got Warnung.
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read X
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: 8A5D0BF11B4: read E
Feb 20 03:30:01 lxcentreon postfix/pickup[18123]: public/cleanup socket: wanted attribute: status
Feb 20 03:30:01 lxcentreon postfix/cleanup[18125]: 8A5D0BF11B4: message-id=<20150218023001.8A5D0BF11B4@hostname.companyname.int>
Feb 20 03:30:01 lxcentreon postfix/smtp[18127]: 77A5FBF1537: to=<email@address.de>, relay=mx.companyname.int[172.16.111.222]:25, delay=1080, delays=1080/0.01/0.01/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 94551418DC0)
Feb 20 03:30:01 lxcentreon postfix/qmgr[18124]: 77A5FBF1537: removed
GotAQuestion
  • 51
  • 2
  • So the logs stopped at 02:03 and it's freeze until you restart it, right? – masegaloeh Feb 20 '15 at 11:37
  • Any logrotate-like stuff, anything that could impact postfix at the time it stops? – Dan Feb 20 '15 at 12:04
  • masegaloeh: Yes, you are right. Dan: Just the cronjobs I posted in the question, the backup is done at 1:18am. Logrotation at 4:20am. I disabled the logwatch cronjob (it produced very big mails) but no improvement... – GotAQuestion Feb 20 '15 at 12:08
  • According to [this thread](http://archives.neohapsis.com/archives/postfix/2005-06/1236.html), looks like you can get more verbose logging by adding more `-v` parameter. – masegaloeh Feb 20 '15 at 15:36
  • Also, if the verbose switch `-v` doesn't help, you can add [strace/truss command](http://www.postfix.org/DEBUG_README.html#man_trace) in a cron around 2 AM. It will produce how system behave in backgroud. – masegaloeh Feb 20 '15 at 15:38
  • Do you/Does postfix have enough disk space left? Can you verify that the /usr/share/centreon/cron/centreonPurge.sh script does nothing to postfix, its configuration or its logs? Are your configurations only stored in text files or are there other sources like LDAP, DBs, ...? – sebokopter Feb 21 '15 at 11:02
  • There is a nagios job starting at 2AM and you have unsent nagios mails. I would suspect nagios - could you uninstall it and see if it helps? – Thorbjørn Ravn Andersen Feb 21 '15 at 22:45
  • Try logging `ps auxf` in your postfix_restart.sh. Maybe `cleanup` has segfaulted or been terminated by centreon. BTW you keep your sysadmin scripts in /tmp? Also your master.cf might be relevant. – Cedric Knight Feb 22 '15 at 11:45
  • @masegaloeh: I'll try it with -vvv on pickup and strace/truss in another night sebokopter: 27GB avaible, all /usr/share/centreon/cron/centreonPurge.sh does is stopping centstorage, purging centreon logs and starting censtorage, nothing to do with postfix. Config ist stored in textfiles (and maybe canonical.db) Thorbjørn Ravn Andersen: It's a monitoring server, without nagios it would be useless. Nagios sent mails via mailx, the mails are in the postdrop queue, now it's postfix turn to pickup the mails and deliver them Cedric Knight: I'll try logging this. And yes, somteimes i do ;) – GotAQuestion Feb 23 '15 at 10:21
  • Tonight something changed, emails got picked up and cleaned up, but not queued. "Feb 23 02:16:40 lxcentreon postfix/pickup[4949]: fatal: watchdog timeout;Feb 23 02:31:02 servername postfix/master[22724]: warning: process /usr/libexec/postfix/pickup pid 4949 exit status 1"; Til 8:00 am there were two log entries per mail (over 100 mails): Feb 23 02:45:56 servername postfix/pickup[6950]: 49A6D4109B5: uid=100 from= Feb 23 02:45:57 servername postfix/cleanup[6952]: 49A6D4109B5: message-id=<20150223014556.49A6D4109B5@servername.companyname.int>"; but no qmgr log entry til restart of postfix – GotAQuestion Feb 23 '15 at 10:45
  • Can you edit the question and post the output of `postconf -n` and content of `master.cf`? Also please post the updated maillog entry. – masegaloeh Feb 25 '15 at 06:02
  • @masegaloeh: No characters left in the question to do so...Where could I post the config else? – GotAQuestion Feb 26 '15 at 11:18
  • You can post it in pastebin on others – masegaloeh Feb 26 '15 at 11:20
  • @masegaloeh: http://pastebin.com/WjiyDhqM postconfg, master.cf, canonical. Thanks for your help – GotAQuestion Feb 26 '15 at 14:16
  • 1
    Wait... You still use postfix 2.3? Consider to upgrade it because perhaps the bug was fixed in newer version. Also please post the [newest maillog](http://serverfault.com/questions/670123/postfix-stops-picking-up-mails-at-night?noredirect=1#comment820089_67012) when this event happened – masegaloeh Feb 26 '15 at 14:21
  • @masegaloeh: It is a CentOS 5.11 server, there is no newer postfix version available in our repos (CentOS standard repos, epel, FAN, graphviz and remi) – GotAQuestion Feb 27 '15 at 09:31

1 Answers1

2

Snippet from comment

It is a CentOS 5.11 server, there is no newer postfix version available in our repos (CentOS standard repos, epel, FAN, graphviz and remi).

So you are stuck in unsupported version of postfix 2.3.3. Well, I understand your case, it's very sad tough :(.

Postfix version 2.3.3 was released in August 2006. Although the CentOS team was backported several features for this version but still, they may miss one-two bugfixes.

My suggestion is please try to upgrading it. Perhaps via other unofficial repo or building from source. Another option is post this bug on the CentOS mailing lists.

And I think that even Wietse Venema (the postfix author) will also suggest you to upgrading it. The mere fact that watchdog timeouts aren't a frequent item on postfix mailing list is indicative that the problem is likely to be outside Postfix

Community
  • 1
masegaloeh
  • 18,236
  • 10
  • 57
  • 106
  • Well, this is what I suggest. There might be anything, that forces postfix to stop, outside of postfix. Postfix ran on this server for a couple of years and now there are those problems. Do you have any idea, to find out what forces postfix to stop working? I'll talk to my colleagues regarding the postfix update – GotAQuestion Feb 27 '15 at 10:56
  • Please post the strace output. Maybe we can draw some idea from there :) – masegaloeh Feb 27 '15 at 11:05