Emails delayed

Submitted by admin@curatebee.com on Sun, 11/09/2014 - 22:37

Emails are getting stuck in a queue somewhere. Don't receive any emails, but once I restart the milter-greylist process then a whole heap come through. Works for a day or 2 and then stops again and I have to restart the process again and then get a whole heap of emails through again. Not sure what is causing the blockage?

Status: 
Active

Comments

Submitted by andreychek on Sun, 11/09/2014 - 22:54

Howdy -- when you start having those problems, do you see any errors in /var/log/mail.log?

Submitted by admin@curatebee.com on Sun, 11/09/2014 - 23:07

this is what is currently in the log

Nov 10 15:58:01 ns1 postfix/pickup[1464]: EA22FA80E5: uid=0 from= Nov 10 15:58:01 ns1 postfix/cleanup[31650]: warning: connect to Milter service local:/var/run/milter-greylist/milter-greylist.sock: No such file or directory Nov 10 15:58:01 ns1 postfix/cleanup[31650]: EA22FA80E5: message-id=20141110045801.EA22FA80E5@ns1.hernet.com.au Nov 10 15:58:01 ns1 postfix/qmgr[1465]: EA22FA80E5: from=root@hernet.com.au, size=625, nrcpt=1 (queue active) Nov 10 15:58:02 ns1 postfix/local[32753]: EA22FA80E5: to=root@hernet.com.au, orig_to=, relay=local, delay=0.16, delays=0.09/0/0/0.07, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME) Nov 10 15:58:02 ns1 postfix/qmgr[1465]: EA22FA80E5: removed Nov 10 15:58:54 ns1 postfix/pickup[1464]: 73607A80E5: uid=0 from= Nov 10 15:58:54 ns1 postfix/cleanup[31650]: warning: connect to Milter service local:/var/run/milter-greylist/milter-greylist.sock: No such file or directory Nov 10 15:58:54 ns1 postfix/cleanup[31650]: 73607A80E5: message-id=20141110045854.73607A80E5@ns1.hernet.com.au Nov 10 15:58:54 ns1 postfix/qmgr[1465]: 73607A80E5: from=root@hernet.com.au, size=514, nrcpt=1 (queue active) Nov 10 15:58:54 ns1 postfix/local[32753]: 73607A80E5: to=root@hernet.com.au, orig_to=, relay=local, delay=0.14, delays=0.01/0/0/0.13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME) Nov 10 15:58:54 ns1 postfix/qmgr[1465]: 73607A80E5: removed Nov 10 15:59:01 ns1 postfix/pickup[1464]: DF776A80E5: uid=0 from= Nov 10 15:59:01 ns1 postfix/cleanup[31650]: warning: connect to Milter service local:/var/run/milter-greylist/milter-greylist.sock: No such file or directory Nov 10 15:59:01 ns1 postfix/cleanup[31650]: DF776A80E5: message-id=20141110045901.DF776A80E5@ns1.hernet.com.au Nov 10 15:59:01 ns1 postfix/qmgr[1465]: DF776A80E5: from=root@hernet.com.au, size=625, nrcpt=1 (queue active) Nov 10 15:59:01 ns1 postfix/local[32753]: DF776A80E5: to=root@hernet.com.au, orig_to=, relay=local, delay=0.05, delays=0.01/0/0/0.05, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME) Nov 10 15:59:01 ns1 postfix/qmgr[1465]: DF776A80E5: removed Nov 10 16:00:02 ns1 postfix/pickup[1464]: 4C293A80E5: uid=0 from= Nov 10 16:00:02 ns1 postfix/cleanup[31650]: warning: connect to Milter service local:/var/run/milter-greylist/milter-greylist.sock: No such file or directory Nov 10 16:00:02 ns1 postfix/cleanup[31650]: 4C293A80E5: message-id=20141110050002.4C293A80E5@ns1.hernet.com.au Nov 10 16:00:02 ns1 postfix/qmgr[1465]: 4C293A80E5: from=root@hernet.com.au, size=625, nrcpt=1 (queue active) Nov 10 16:00:02 ns1 postfix/local[32753]: 4C293A80E5: to=root@hernet.com.au, orig_to=, relay=local, delay=0.49, delays=0.03/0/0/0.47, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME) Nov 10 16:00:02 ns1 postfix/qmgr[1465]: 4C293A80E5: removed Nov 10 16:00:02 ns1 postfix/pickup[1464]: E260BA8119: uid=33 from= Nov 10 16:00:02 ns1 postfix/cleanup[31650]: warning: connect to Milter service local:/var/run/milter-greylist/milter-greylist.sock: No such file or directory Nov 10 16:00:02 ns1 postfix/cleanup[31650]: E260BA8119: message-id=20141110050002.E260BA8119@ns1.hernet.com.au Nov 10 16:00:02 ns1 postfix/qmgr[1465]: E260BA8119: from=www-data@hernet.com.au, size=915, nrcpt=1 (queue active) Nov 10 16:00:03 ns1 postfix/local[32753]: E260BA8119: to=root@hernet.com.au, orig_to=, relay=local, delay=0.13, delays=0.03/0/0/0.1, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME) Nov 10 16:00:03 ns1 postfix/qmgr[1465]: E260BA8119: removed Nov 10 16:01:01 ns1 postfix/pickup[1464]: DB8C7A80E7: uid=0 from= Nov 10 16:01:01 ns1 postfix/cleanup[31650]: warning: connect to Milter service local:/var/run/milter-greylist/milter-greylist.sock: No such file or directory Nov 10 16:01:01 ns1 postfix/cleanup[31650]: DB8C7A80E7: message-id=20141110050101.DB8C7A80E7@ns1.hernet.com.au Nov 10 16:01:01 ns1 postfix/qmgr[1465]: DB8C7A80E7: from=root@hernet.com.au, size=625, nrcpt=1 (queue active) Nov 10 16:01:02 ns1 postfix/local[32753]: DB8C7A80E7: to=root@hernet.com.au, orig_to=, relay=local, delay=0.29, delays=0.17/0/0/0.11, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME) Nov 10 16:01:02 ns1 postfix/qmgr[1465]: DB8C7A80E7: removed

Submitted by andreychek on Sun, 11/09/2014 - 23:15

Hmm, it looks like milter-greylist is stopped for some reason... perhaps it's crashing?

What is the output of these two commands:

free -m
dmesg | tail -30

Submitted by admin@curatebee.com on Sun, 11/09/2014 - 23:18

There is no directory /var/run on the system so not sure where it is supposed to be pointed too?

Submitted by admin@curatebee.com on Sun, 11/09/2014 - 23:20

free -m total used free shared buffers cached Mem: 1994 1832 162 0 4 46 -/+ buffers/cache: 1781 213 Swap: 2046 1310 736

MYSQL is using 1.5GB

dmesg | tail -30 [230797.500700] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=23845 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230798.933102] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:45:41:64:08:00 SRC=103.15.178.111 DST=255.255.255.255 LEN=132 TOS=0x00 PREC=0x00 TTL=64 ID=0 DF PROTO=UDP SPT=17500 DPT=17500 LEN=112 [230798.933903] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:45:41:64:08:00 SRC=103.15.178.111 DST=103.15.178.255 LEN=132 TOS=0x00 PREC=0x00 TTL=64 ID=0 DF PROTO=UDP SPT=17500 DPT=17500 LEN=112 [230799.493327] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=3965 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230802.504882] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=23873 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230804.500381] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=3968 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230807.510092] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=23895 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230808.775641] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=104 TOS=0x00 PREC=0x00 TTL=128 ID=4157 PROTO=UDP SPT=57623 DPT=61117 LEN=84 [230809.508147] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=4362 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230812.514398] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=23945 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230814.515164] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=4689 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230817.518469] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=23979 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230818.789199] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5081 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230819.523269] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5083 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230822.521972] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=24005 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230824.531158] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5347 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230827.526284] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=24039 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230828.983861] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:45:41:64:08:00 SRC=103.15.178.111 DST=255.255.255.255 LEN=132 TOS=0x00 PREC=0x00 TTL=64 ID=0 DF PROTO=UDP SPT=17500 DPT=17500 LEN=112 [230829.539127] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5457 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230832.530967] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=24067 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230834.547322] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5462 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230837.534233] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=24136 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230839.553828] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5483 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230840.628959] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:30:c8:8e:08:00 SRC=103.15.178.15 DST=255.255.255.255 LEN=131 TOS=0x00 PREC=0x00 TTL=128 ID=28149 PROTO=UDP SPT=17500 DPT=17500 LEN=111 [230842.538846] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=24179 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230844.562731] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5528 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230847.543178] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=24183 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230849.569453] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5543 PROTO=UDP SPT=57623 DPT=61117 LEN=52 [230852.547123] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:37:c6:e3:08:00 SRC=103.15.178.138 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=24188 PROTO=UDP SPT=60419 DPT=61117 LEN=52 [230854.577924] Firewall: UDP_IN Blocked IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:16:3e:56:66:14:08:00 SRC=103.15.178.132 DST=103.15.178.255 LEN=72 TOS=0x00 PREC=0x00 TTL=128 ID=5646 PROTO=UDP SPT=57623 DPT=61117 LEN=52

Submitted by admin@curatebee.com on Sun, 11/09/2014 - 23:24

restarted the milter-greylist process

from mail log now

Nov 10 16:20:01 ns1 postfix/pickup[2584]: D3431A8119: uid=33 from=<www-data>
Nov 10 16:20:01 ns1 postfix/cleanup[31650]: warning: connect to Milter service local:/var/run/milter-greylist/milter-greylist.sock: No such file or directory
Nov 10 16:20:01 ns1 postfix/cleanup[31650]: D3431A8119: message-id=<20141110052001.D3431A8119@ns1.hernet.com.au>
Nov 10 16:20:01 ns1 postfix/qmgr[1465]: D3431A8119: from=<www-data@hernet.com.au>, size=915, nrcpt=1 (queue active)
Nov 10 16:20:01 ns1 postfix/local[32753]: D3431A8119: to=<root@hernet.com.au>, orig_to=<root>, relay=local, delay=0.09, delays=0.02/0/0/0.07, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Nov 10 16:20:01 ns1 postfix/qmgr[1465]: D3431A8119: removed
Nov 10 16:20:45 ns1 milter-greylist: cannot read dumpfile "/var/lib/milter-greylist/greylist.db"
Nov 10 16:20:45 ns1 milter-greylist: starting with an empty greylist
Nov 10 16:21:02 ns1 postfix/pickup[2584]: 0E5F4A80E7: uid=0 from=<root>
Nov 10 16:21:02 ns1 milter-greylist: 0E5F4A80E7: skipping greylist because this is the default action, (from=root@hernet.com.au, rcpt=root@hernet.com.au, addr=localhost[127.0.0.1]) ACL 75
Nov 10 16:21:02 ns1 postfix/cleanup[31650]: 0E5F4A80E7: message-id=<20141110052102.0E5F4A80E7@ns1.hernet.com.au>
Nov 10 16:21:02 ns1 milter-greylist: smfi_getsymval failed for {if_addr}
Nov 10 16:21:02 ns1 postfix/qmgr[1465]: 0E5F4A80E7: from=<root@hernet.com.au>, size=625, nrcpt=1 (queue active)
Nov 10 16:21:02 ns1 postfix/local[32753]: 0E5F4A80E7: to=<root@hernet.com.au>, orig_to=<root>, relay=local, delay=0.27, delays=0.14/0/0/0.13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Nov 10 16:21:02 ns1 postfix/qmgr[1465]: 0E5F4A80E7: removed

Submitted by andreychek on Mon, 11/10/2014 - 14:00

First off, just to verify -- do you want to use the milter-greylist daemon? If not, you can always disable that.

However, I re-read what you mentioned above, and you said there was no /var/run directory on your server?

If not, that sounds like a problem... not just for milter-greylist, but potentially for other things too.

If that doesn't exist, you can create it by running these two commands as root:

mkdir /var/run
chmod 755 /var/run

After doing that, try restarting milter-greylist, and see if those errors go away at that point.

Submitted by admin@curatebee.com on Mon, 11/10/2014 - 19:47

Do I need it, well reading through the forums I thought you used it for rate limiting so I just left it in place as part of the virtualmin/webmin install.

Had a look at /var/run - it's actually a symbolic link pointed to /run which exists and has a whole lot of files and directories under it.

Where I am confused is /var/run/milter-greylist/milter-greylist.sock: No such file or directory - this doesn't exist even when the milter-greylist process is running. If I look at the process milter-greylist in webmin it shows

PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin DAEMON=/usr/sbin/milter-greylist NAME=greylist SNAME=greylist DESC="Greylist Mail Filter Daemon" PIDFILE="/var/run/$NAME.pid" PNAME="milter-greylist" USER="greylist" SOCKET=/var/spool/postfix/var/run/milter-greylist/milter-greylist.sock

Now the socket referred to here does exist, but then further down the process command is:

if [ ! -d /var/run/$PNAME ]; then mkdir /var/run/$PNAME chown greylist:greylist /var/run/$PNAME chmod 755 /var/run/$PNAME fi

so it doesn't appear to be pointing it to the correct socket, is this an error in the way webmin has been configured?

Submitted by andreychek on Mon, 11/10/2014 - 19:53

Well, that software isn't installed by default. However, if someone wishes to use email rate limiting, Virtualmin would offer to install that software in order to handle the rate limiting.

If you don't need the rate limiting, it's no problem to disable milter-greylist.

Note that it doesn't handle any greylisting -- which is actually handled by another service, Postgrey.