Procmail and spamassassin woes.

40 posts / 0 new
Last post
#1 Wed, 01/23/2008 - 11:46
SeanWolfe

Procmail and spamassassin woes.

I've been having problems with the spamassassin plugin for quite some time now. I've narrowed it down to a procmail problem, but I haven't been able to figure out what. I every couple days pick it up and try to manually trace where the mail might be going (procmail is a bit of a mystery to me). But I've been able to isolate the problem to the fact that the lookup-domain.pl script (any of 3) is not firing. I finally think the problem is /etc/procmailrc

Here is what /etc/procmailrc looks like

[code:1]# Use maildir-style mailbox in user's home directory LOGFILE=/var/log/procmail.log TRAP=//etc/webmin/virtual-server/procmail-logger.pl :0wi VIRTUALMIN=|//etc/webmin/virtual-server/lookup-domain.pl $LOGNAME :0 * ?/usr/bin/test "$VIRTUALMIN" != "" { INCLUDERC=//etc/webmin/virtual-server/procmail/$VIRTUALMIN } ORGMAIL=$HOME/Maildir/ DEFAULT=$HOME/Maildir/ DROPPRIVS=yes :0 $DEFAULT :0 * ^X-Spam-Status: Yes $DEFAULT[/code:1]

and the log output looks like

[code:1]procmail: Couldn't read "//etc/webmin/virtual-server/procmail/running /etc/webmin/virtual-server/lookup-domain.pl" From someone@somewhere.com Wed Jan 23 15:19:34 2008 Subject: Some crazy subject Folder: /home/domain/homes/tom/Maildir/new/1201123174.24746_0.salvo 2763 Time:1201123174 From:«»someone@somewhere.com To:tom@domain.com User:tom.domain Size:2813 Dest:/home/domain/homes/tom/Maildir/new/1201123174.24746_0.myserveraddrss.mydomain.com Mode:None[/code:1]

that line procmail: Couldn't read "//etc/webmin/virtual-server/procmail/running /etc/webmin/virtual-server/lookup-domain.pl" looks suspicious

and I've tried tracing it many times.

And I think it has to do with this line in procmailrc VIRTUALMIN=|//etc/webmin/virtual-server/lookup-domain.pl $LOGNAME

I tried changing that line to VIRTUALMIN=//etc/webmin/virtual-server/lookup-domain.pl $LOGNAME

But i think that was more disastrous because i think the mail would get lost

this is what the log output looked like

[code:1]procmail: Skipped "sam.domain" From acoolguy@anotherplace.com Wed Jan 23 15:27:39 2008 Subject: Re: Fwd: I like procmail Folder: VIRTUALMIN=//etc/webmin/virtual-server/lookup-domain.pl 0 Time:1201123659 From:acoolguy@anotherplace.com To:«»sam@domain.com User:«»sam.domain Size:5429 Dest:VIRTUALMIN=//etc/webmin/virtual-server/lookup-domain.pl Mode:None [/code:1] That Dest:VIRTUALMIN=//etc/webmin/virtual-server/lookup-domain.pl Mode:None is the sad part. Do messages that procmail fail to process go to some kind of purgatory somewhere?

I have also tried having Virtualmin reinstall the default procmail, but since virtualmin is a nice guy, it leaves it alone.

Any ideas? anyone?

Thu, 01/24/2008 - 12:41
SeanWolfe

Ok, I've gave myself a little crash course in Procmail. And I see the error of my ways. The error message that appeared in the previous log was caused by a debug message I stuck into one of the scripts, and procmail was trying to process it. Evidently, the other lookup-domain scripts are running, but for some reason Spamassassin doesn't process the mails. I've manually ran the scripts and everything on the processing side is working. I just don't see what is happening, unless a Procmail rule is dumping out of the script early.

guess I'm still going to have to look.

Fri, 02/01/2008 - 07:25 (Reply to #2)
Joe
Joe's picture

Hi Sean,

The first thing to check is if the lookup-domain.pl script is outputting a domain ID for the mailbox that is receiving spam. You can do this by running a command like :

/etc/webmin/virtual-server/lookup-domain.pl username.domain </dev/null

where username.domain is the full Unix login (as used for POP3 and IMAP) for the user in question. If this outputs a domain ID number, all should be well.

If not, there are a few possible causes :

1) The user's domain doesn't have the spam feature enabled, on the Edit Virtual Server page.

2) The user is close to his quota. Unless he has about 10MB free, Virtualmin will not run SpamAssassin, as it requires about that much disk space for temp files .. and hangs if it doesn't get them!

3) Spam filtering is disabled for the individual user, which can be done on the Edit User page.

--

Check out the forum guidelines!

Fri, 02/01/2008 - 07:37 (Reply to #3)
SeanWolfe

Hey Jamie,

<div class='quote'>
/etc/webmin/virtual-server/lookup-domain.pl username.domain &lt;/dev/null
</div>

Yes, I tried this a bunch of times. The domain ID does get returned.

<div class='quote'>1) The user's domain doesn't have the spam feature enabled, on the Edit Virtual Server page.</div>
I've check this, and I've enabled and disabled it several times. I've also disabled and enabled the spam and virus plugin in virtualmin.

<div class='quote'>
2) The user is close to his quota. Unless he has about 10MB free, Virtualmin will not run SpamAssassin, as it requires about that much disk space for temp files .. and hangs if it doesn't get them!
</div>
This might be the case for some users, but this happens to all users, even ones that don't have quotas.

<div class='quote'>
3) Spam filtering is disabled for the individual user, which can be done on the Edit User page.
</div>
I've checked several users, and they all had it enabled. Users that I have that go to me, I have checked this and tried to change it many times. Nothing has made this any different.

I clearly believe that procmail, when it gets to the part where it finds the domain ID (VIRTUALMIN=|/etc/webmin/virtual-server/lookup-domain.pl $LOGNAME), it doesn't seem to receive the response. Therefore it doesn't load up the domains custom procmail settings.

This clearly is shown with this output:
<div class='quote'>procmail: Executing &quot;/usr/bin/test,,!=,&quot;
procmail: Non-zero exitcode (1) from &quot;/usr/bin/test&quot;
procmail: No match on &quot;/usr/bin/test != &quot;
</div>

Anything else I can test?

Fri, 02/01/2008 - 08:33 (Reply to #4)
Joe
Joe's picture

Sean - can you post your current /etc/procmailrc file to this bug report? I suspect that it may differ from the current Virtualmin standard..

--

Check out the forum guidelines!

Sun, 06/07/2009 - 07:18 (Reply to #5)
SeanWolfe

Here is my current procmailrc:

[code:1]
# Use maildir-style mailbox in user's home directory
VERBOSE=yes
LOGFILE=/var/log/procmail.log
TRAP=//etc/webmin/virtual-server/procmail-logger.pl
:0wi
VIRTUALMIN=|/etc/webmin/virtual-server/lookup-domain.pl $LOGNAME
:0
* ?/usr/bin/test &quot;$VIRTUALMIN&quot; != &quot;&quot;
{
INCLUDERC=//etc/webmin/virtual-server/procmail/$VIRTUALMIN
}
ORGMAIL=$HOME/Maildir/
DEFAULT=$HOME/Maildir/
DROPPRIVS=yes

:0
* ^X-Spam-Status: Yes
$DEFAULT
:0
$DEFAULT

[/code:1]

Sun, 06/07/2009 - 07:18 (Reply to #6)
SeanWolfe

Here is my current procmailrc:

[code:1]
# Use maildir-style mailbox in user's home directory
VERBOSE=yes
LOGFILE=/var/log/procmail.log
TRAP=//etc/webmin/virtual-server/procmail-logger.pl
:0wi
VIRTUALMIN=|/etc/webmin/virtual-server/lookup-domain.pl $LOGNAME
:0
* ?/usr/bin/test &quot;$VIRTUALMIN&quot; != &quot;&quot;
{
INCLUDERC=//etc/webmin/virtual-server/procmail/$VIRTUALMIN
}
ORGMAIL=$HOME/Maildir/
DEFAULT=$HOME/Maildir/
DROPPRIVS=yes

:0
* ^X-Spam-Status: Yes
$DEFAULT
:0
$DEFAULT

[/code:1]

Fri, 02/01/2008 - 17:54 (Reply to #7)
SeanWolfe

You mean /var/log/webmin/lookup-domain-daemon.log, right?
This is strange because the log only has a few entries for this week.

Here is the last 100 lines of that log.
[code:1]
[Wed Jan 16 09:03:14 2008] user=root NOUSER
[Wed Jan 16 10:03:15 2008] user=root NOUSER
[Wed Jan 16 13:03:14 2008] user=root NOUSER
[Wed Jan 16 14:03:14 2008] user=root NOUSER
[Wed Jan 16 15:03:15 2008] user=root NOUSER
[Wed Jan 16 18:03:14 2008] user=root NOUSER
[Wed Jan 16 20:00:01 2008] user=root NOUSER
[Wed Jan 16 20:03:12 2008] user=root NOUSER
[Wed Jan 16 21:03:14 2008] user=root NOUSER
[Thu Jan 17 00:03:15 2008] user=root NOUSER
[Thu Jan 17 01:03:16 2008] user=root NOUSER
[Thu Jan 17 02:03:15 2008] user=root NOUSER
[Thu Jan 17 04:03:14 2008] user=root NOUSER
[Thu Jan 17 05:03:14 2008] user=root NOUSER
[Thu Jan 17 07:00:01 2008] user=root NOUSER
[Thu Jan 17 08:03:15 2008] user=root NOUSER
[Thu Jan 17 11:03:16 2008] user=root NOUSER
[Thu Jan 17 12:03:14 2008] user=root NOUSER
[Thu Jan 17 13:03:14 2008] user=root NOUSER
[Thu Jan 17 17:03:15 2008] user=root NOUSER
[Thu Jan 17 20:00:02 2008] user=root NOUSER
[Thu Jan 17 20:03:15 2008] user=root NOUSER
[Thu Jan 17 21:03:15 2008] user=root NOUSER
[Thu Jan 17 22:03:14 2008] user=root NOUSER
[Thu Jan 17 23:03:15 2008] user=root NOUSER
[Fri Jan 18 01:03:15 2008] user=root NOUSER
[Fri Jan 18 03:03:17 2008] user=root NOUSER
[Fri Jan 18 05:03:15 2008] user=root NOUSER
[Fri Jan 18 07:00:02 2008] user=root NOUSER
[Fri Jan 18 09:03:16 2008] user=root NOUSER
[Fri Jan 18 11:03:15 2008] user=root NOUSER
[Fri Jan 18 12:03:15 2008] user=root NOUSER
[Fri Jan 18 14:03:14 2008] user=root NOUSER
[Fri Jan 18 19:03:14 2008] user=root NOUSER
[Fri Jan 18 20:00:02 2008] user=root NOUSER
[Fri Jan 18 22:03:15 2008] user=root NOUSER
[Sat Jan 19 01:03:14 2008] user=root NOUSER
[Sat Jan 19 02:03:14 2008] user=root NOUSER
[Sat Jan 19 04:03:14 2008] user=root NOUSER
[Sat Jan 19 06:03:14 2008] user=root NOUSER
[Sat Jan 19 07:00:01 2008] user=root NOUSER
[Sat Jan 19 07:03:14 2008] user=root NOUSER
[Sat Jan 19 09:03:15 2008] user=root NOUSER
[Sat Jan 19 11:03:14 2008] user=root NOUSER
[Sat Jan 19 13:03:14 2008] user=root NOUSER
[Sat Jan 19 15:03:15 2008] user=root NOUSER
[Sat Jan 19 17:03:14 2008] user=root NOUSER
[Sat Jan 19 20:00:01 2008] user=root NOUSER
[Sat Jan 19 20:03:14 2008] user=root NOUSER
[Sat Jan 19 22:03:14 2008] user=root NOUSER
[Sun Jan 20 03:00:01 2008] user=root NOUSER
[Sun Jan 20 03:10:24 2008] user=root NOUSER
[Sun Jan 20 06:03:14 2008] user=root NOUSER
[Sun Jan 20 07:00:01 2008] user=root NOUSER
[Sun Jan 20 07:03:14 2008] user=root NOUSER
[Sun Jan 20 08:03:15 2008] user=root NOUSER
[Sun Jan 20 09:03:14 2008] user=root NOUSER
[Sun Jan 20 11:03:15 2008] user=root NOUSER
[Sun Jan 20 15:03:14 2008] user=root NOUSER
[Sun Jan 20 18:03:15 2008] user=root NOUSER
[Sun Jan 20 19:03:15 2008] user=root NOUSER
[Sun Jan 20 20:00:01 2008] user=root NOUSER
[Sun Jan 20 20:03:15 2008] user=root NOUSER
[Sun Jan 20 21:03:15 2008] user=root NOUSER
[Sun Jan 20 22:03:15 2008] user=root NOUSER
[Mon Jan 21 01:03:15 2008] user=root NOUSER
[Mon Jan 21 02:03:15 2008] user=root NOUSER
[Mon Jan 21 03:10:21 2008] user=root NOUSER
[Mon Jan 21 04:03:14 2008] user=root NOUSER
[Mon Jan 21 05:03:14 2008] user=root NOUSER
[Mon Jan 21 06:03:14 2008] user=root NOUSER
[Mon Jan 21 07:00:01 2008] user=root NOUSER
[Mon Jan 21 07:03:14 2008] user=root NOUSER
[Mon Jan 21 09:03:15 2008] user=root NOUSER
[Mon Jan 21 09:37:19 2008] user=sean.spindlex dom=spindlex.com spam=1 client=spamc quota= uquota=
[Mon Jan 21 09:39:05 2008] user=sean.spindlex dom=spindlex.com spam=1 client=spamc quota= uquota=
[Mon Jan 21 09:44:01 2008] user=sean.spindlex dom=spindlex.com spam=1 client=spamc quota= uquota=
[Mon Jan 21 10:03:14 2008] user=root NOUSER
[Mon Jan 21 11:03:14 2008] user=root NOUSER
[Mon Jan 21 12:03:15 2008] user=root NOUSER
[Mon Jan 21 17:03:14 2008] user=root NOUSER
[Mon Jan 21 19:03:15 2008] user=root NOUSER
[Mon Jan 21 20:00:01 2008] user=root NOUSER
[Mon Jan 21 20:03:15 2008] user=root NOUSER
[Mon Jan 21 21:03:12 2008] user=root NOUSER
[Mon Jan 21 23:03:15 2008] user=root NOUSER
[Tue Jan 22 01:03:15 2008] user=root NOUSER
[Tue Jan 22 02:03:14 2008] user=root NOUSER
[Tue Jan 22 04:03:15 2008] user=root NOUSER
[Tue Jan 22 06:03:15 2008] user=root NOUSER
[Tue Jan 22 07:00:02 2008] user=root NOUSER
[Tue Jan 22 10:03:14 2008] user=root NOUSER
[Tue Jan 22 11:03:14 2008] user=root NOUSER
[Tue Jan 22 12:03:14 2008] user=root NOUSER
[Tue Jan 22 13:03:15 2008] user=root NOUSER
[Tue Jan 22 14:03:15 2008] user=root NOUSER
[Tue Jan 22 17:03:14 2008] user=root NOUSER
[Tue Jan 22 20:00:02 2008] user=root NOUSER
[Tue Jan 22 20:03:15 2008] user=root NOUSER
[Tue Jan 22 21:03:15 2008] user=root NOUSER
[/code:1]

If this is suppose to get an entry for every email, something is wrong because this server gets a TON of email. At least 2 emails a minute.

Fri, 02/01/2008 - 18:01 (Reply to #8)
Joe
Joe's picture

When you run lookup-domain.pl as root from the command line, does an entry get logged to that file?

One thing to check is if Procmail is being run as the right user (root). In a standard Virtualmin install, your /etc/postfix/main.cf file should contain a line like :

[code:1]mailbox_command = /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME[/code:1]

and the /usr/bin/procmail-wrapper command should be setuid root :

[code:1]-rwsr-sr-x 1 root root 2916 2006-10-14 23:18 /usr/bin/procmail-wrapper[/code:1]

--

Check out the forum guidelines!

Sun, 06/07/2009 - 07:18 (Reply to #9)
SeanWolfe

Hey Jamie,

<div class='quote'>When you run lookup-domain.pl as root from the command line, does an entry get logged to that file?
</div>

No, it does not appear that anything gets logged when I run lookup-domain.pl as root. That is if you mean in the /var/log/webmin/lookup-domain-daemon.log.

My mailbox command for postfix has always been:
[code:1]mailbox_command = /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME[/code:1]
This is how I configured it from installation.

And this is how my procmail-wrapper looks:

[code:1]-rwsr-sr-x 1 root root 8266 Oct 22 00:37 /usr/bin/procmail-wrapper[/code:1]

I did have to make my procmail-wrapper on my own. This Virtualmin installation for the most part was performed manually. Here is the source I used for the wrapper (found on this forum):

[code:1]
# procmail-wrapper.c
#include &quot;stdio.h&quot;
int main(int argc, char **argv)
{
setuid(geteuid());
setgid(getegid());
execv(&quot;/usr/bin/procmail&quot;, argv);
}
[/code:1]

Do I need to have postfix run as another users? Currently it runs as postfix.

Here is a list of my usual postfix processes that are running.
[code:1]salvonexus seanwolfe # ps aux | grep postfix
postfix 14666 0.0 0.0 41036 2532 ? S Jan31 0:02 qmgr -l -t fifo -u
postfix 14678 0.0 0.0 40700 2224 ? S Jan31 0:01 anvil -l -t unix -u
postfix 14681 0.0 0.0 40704 2268 ? S Jan31 0:00 tlsmgr -l -t unix -u
postfix 16548 0.0 0.0 51912 4128 ? S 16:20 0:00 smtpd -n smtp -t inet -u -o smtpd_sasl_auth_enable yes
postfix 16554 0.0 0.0 51932 4176 ? S 16:20 0:00 smtpd -n smtp -t inet -u -o smtpd_sasl_auth_enable yes
postfix 16561 0.0 0.0 40952 2648 ? S 16:21 0:00 cleanup -z -t unix -u
postfix 16850 0.0 0.0 40708 2148 ? S 16:29 0:00 pickup -l -t fifo -u
postfix 17037 0.0 0.0 40864 2524 ? S 16:32 0:00 smtp -t unix -u
postfix 17171 0.0 0.0 40964 2740 ? S 16:35 0:00 local -t unix
[/code:1]

Sat, 02/02/2008 - 14:39 (Reply to #10)
Joe
Joe's picture

I wonder if Procmail is even being run by Postfix on your system?
If you send email to a non-root user, do you see log entries in /var/log/maillog or mail.log showing that Procmail is being called?

Just for testing purposes, I installed Virtualmin Pro 3.51 on a fresh CentOS 5 box, and verified that spam filtering was working OK. And that the expected entries appear in /var/webmin/lookup-domain-daemon.log .

--

Check out the forum guidelines!

Sat, 02/02/2008 - 16:10 (Reply to #11)
SeanWolfe

Hey Jamie,

I am certain that procmail is running. Every email that comes in, I see it get logged in /var/log/procmail.log.

Here is an example of postfix activity:
[code:1]Feb 2 20:07:39 salvonexus postfix/local[25201]: 9672625395D: to=&lt;billy.mydomain@salvonexus.someserver.com&gt;, orig_to=&lt;billy@mydomain.com&gt;, relay=local, delay=0.28, delays=0.26/0/0/0.02, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)[/code:1]

Just a note, I've had this issue since I installed Virtualmin on this machine in October.

Sat, 02/02/2008 - 16:19 (Reply to #12)
Joe
Joe's picture

The only other thing I can think of is to check if the lookup-domain-daemon.pl process is running (it gets started by the /etc/init.d/lookup-domain-daemon boot script).

If that doesn't help, to debug this further I'd need to login to the system myself.. contact me via email at jcameron@virtualmin.com if that is possible. I'll post any findings to this forum..

--

Check out the forum guidelines!

Sun, 06/07/2009 - 07:18 (Reply to #13)
SeanWolfe

Okay, I think we are getting somewhere. I don't seem to have an init script for lookup-domain-daemon.pl.

I do see <b>/etc/webmin/init/lookup-domain.sh</b> though.
[code:1]salvonexus seanwolfe # cat /etc/webmin/init/lookup-domain.sh
#!/bin/sh
# Daemon for quickly looking up Virtualmin servers from procmail

case &quot;$1&quot; in
'start')
/usr/local/webmin/virtual-server/lookup-domain-daemon.pl
RETVAL=$?
;;
'stop')
kill `cat //var/log/webmin/lookup-domain-daemon.pid`
RETVAL=$?
;;
'restart')
$0 stop ; $0 start
RETVAL=$?
;;
*)
echo &quot;Usage: $0 { start | stop }&quot;
RETVAL=1
;;
esac
exit $RETVAL[/code:1]

But, I do see the process running.
[code:1]salvonexus seanwolfe # ps aux | grep lookup-domain-daemon
root 13730 0.0 1.1 100264 69412 ? Ss Jan28 0:16 /usr/local/webmin/virtual-server/lookup-domain-daemon.pl
[/code:1]

Maybe the script isn't running with the correct params?

But then looking to see if it is listening to a port, i do a netstat:
[code:1]salvonexus seanwolfe # netstat -tap | grep 13730
tcp 0 0 localhost:11000 *:* LISTEN 13730/lookup-domain [/code:1]

To me, everything is where it should be. If you think I should, let you in to debug it, you can email me your public key file, and I'll create an account that can su in.

Sun, 06/07/2009 - 07:18 (Reply to #14)
SeanWolfe

Okay, I think we are getting somewhere. I don't seem to have an init script for lookup-domain-daemon.pl.

I do see <b>/etc/webmin/init/lookup-domain.sh</b> though.
[code:1]salvonexus seanwolfe # cat /etc/webmin/init/lookup-domain.sh
#!/bin/sh
# Daemon for quickly looking up Virtualmin servers from procmail

case &quot;$1&quot; in
'start')
/usr/local/webmin/virtual-server/lookup-domain-daemon.pl
RETVAL=$?
;;
'stop')
kill `cat //var/log/webmin/lookup-domain-daemon.pid`
RETVAL=$?
;;
'restart')
$0 stop ; $0 start
RETVAL=$?
;;
*)
echo &quot;Usage: $0 { start | stop }&quot;
RETVAL=1
;;
esac
exit $RETVAL[/code:1]

But, I do see the process running.
[code:1]salvonexus seanwolfe # ps aux | grep lookup-domain-daemon
root 13730 0.0 1.1 100264 69412 ? Ss Jan28 0:16 /usr/local/webmin/virtual-server/lookup-domain-daemon.pl
[/code:1]

Maybe the script isn't running with the correct params?

But then looking to see if it is listening to a port, i do a netstat:
[code:1]salvonexus seanwolfe # netstat -tap | grep 13730
tcp 0 0 localhost:11000 *:* LISTEN 13730/lookup-domain [/code:1]

To me, everything is where it should be. If you think I should, let you in to debug it, you can email me your public key file, and I'll create an account that can su in.

Sun, 02/03/2008 - 05:44 (Reply to #15)
nickiles

Ok I have fixed the permissions on procmail.log which has allowed procmail to progress further - the error is now with lookup-domain - see below:

[code:1]procmail: Assigning &quot;TRAP=//etc/webmin/virtual-server/procmail-logger.pl&quot;
procmail: Executing &quot;/etc/webmin/virtual-server/lookup-domain.pl,caroline.fundays.org.uk&quot;
Failed to run /virtual-server/lookup-domain.pl : No such file or directory at /etc/webmin/virtual-server/lookup-domain.pl line 10.
procmail: Program failure (2) of &quot;/etc/webmin/virtual-server/lookup-domain.pl&quot;
[/code:1]

Any thoughts?

Nick

Sun, 02/03/2008 - 08:32 (Reply to #16)
SeanWolfe

Nick,

What does your /etc/procmailrc file look like?

Is your virtualmin config installed in /etc/webmin/virtual-server directory? Is it elsewhere?

What does /etc/webmin/virtual-server/lookup-domain.pl look like?

What is <b>root=</b> set to in /etc/webmin/miniserv.conf?

Likely your procmailrc is pointing to the wrong location, or your permissions are not set correctly on your virtualmin config.

This is what mine looks like for lookup-domain.pl
[code:1]salvonexus seanwolfe # ls -la /etc/webmin/virtual-server/lookup-domain.pl
-rwxr-xr-x 1 root root 278 Jan 28 16:21 /etc/webmin/virtual-server/lookup-domain.pl
[/code:1]

Sun, 06/07/2009 - 07:18 (Reply to #17)
nickiles

Hi Sean

Procmailrc is:
[code:1]# Use maildir-style mailbox in user's home directory
VERBOSE=yes
LOGFILE=/var/log/procmail.log
TRAP=//etc/webmin/virtual-server/procmail-logger.pl
:0wi
VIRTUALMIN=|/etc/webmin/virtual-server/lookup-domain.pl $LOGNAME
:0
* ?/usr/bin/test &quot;$VIRTUALMIN&quot; != &quot;&quot;
{
INCLUDERC=//etc/webmin/virtual-server/procmail/$VIRTUALMIN
}
ORGMAIL=$HOME/Maildir/
DEFAULT=$HOME/Maildir/
DROPPRIVS=yes

:0
* ^X-Spam-Status: Yes
$DEFAULT
:0
$DEFAULT
[/code:1]

<div class='quote'>Is your virtualmin config installed in /etc/webmin/virtual-server directory? Is it elsewhere?</div>

Yep in that directory!

<div class='quote'>What does /etc/webmin/virtual-server/lookup-domain.pl look like?</div>[code:1]
#!/usr/bin/perl
open(CONF, &quot;/etc/webmin/miniserv.conf&quot;&Acirc;&laquo;&Acirc;&raquo;);
while(&lt;CONF&gt;&Acirc;&laquo;&Acirc;&raquo;) {
$root = $1 if (/^root=(.*)/);
}
close(CONF);
$ENV{'WEBMIN_CONFIG'} = &quot;/etc/webmin&quot;;
$ENV{'WEBMIN_VAR'} = &quot;/var/webmin&quot;;
chdir(&quot;$root/virtual-server&quot;&Acirc;&laquo;&Acirc;&raquo;);
exec(&quot;$root/virtual-server/lookup-domain.pl&quot;, @ARGV) || die &quot;Failed to run $root/virtual-server/lookup-domain.pl : $!&quot;;
~
[/code:1]

<div class='quote'>What is root= set to in /etc/webmin/miniserv.conf?</div>
[code:1]root=/usr/libexec/webmin
[/code:1]

Permissions on file are:
[code:1]&#91;code&#93;[root@www ~]# ls -la /etc/webmin/virtual-server/lookup-domain.pl
-rwxr-xr-x 1 root root 360 Aug 2 2006 /etc/webmin/virtual-server/lookup-domain.pl
&#91;/code&#93;[/code:1]

Anything else you can suggest? I am kind of at a loss with this one! having traced it as far as lookupdomain failing.

Nick

Sun, 02/03/2008 - 10:16 (Reply to #18)
SeanWolfe

Nick,

Did you try some of the tests that I posted in the previous posts?
Otherwise you may be in the same place I am. The only thing that concerns me is that you are getting errors that it can't find /etc/webmin/virtual-server/lookup-domain.pl.

But some things that I have seen while testing this is to check a few things. For example, can you run /etc/webmin/virtual-server/lookup-domain.pl from the command line? It might be that one of the files that lookup-domain is trying to find isn't there.

Also, have you reinstalled Webmin? Did you install Virtualmin via the installer script, or from a distro package?

Sun, 02/03/2008 - 10:31 (Reply to #19)
nickiles

Hi Sean

Vmin and Webmin installed via standard installers from the Webmin/Vmin sites. I have followed this post closely and have done all the tests so far. If I run lookup-domain from command line it works fine, producing entries in the log and returning a domain id. This is very wierd!

I can't think of much else to try!

Nick

Sun, 02/03/2008 - 12:10 (Reply to #20)
Joe
Joe's picture

Hi Sean,

After much debugging on your system, I discovered that your procmail behaves differently to the one everywhere else - it runs /etc/procmailrc as the user receiving mail right from the start, rather than only when DROPPRIVS=yes is encountered.

When I copied in the exact same version of procmail from my Ubuntu system (3.22) to /usr/bin/procmail, it started working just fine! My guess is that the version built by Gentoo has some strange patches that cause this. Bizarre ..

Nick - are you on Gentoo as well?

--

Check out the forum guidelines!

Sun, 02/03/2008 - 12:37 (Reply to #21)
nickiles

Jamie

<div class='quote'>Nick - are you on Gentoo as well? </div>

Fraid not - mine is a centos 4.6 box which was upgraded prob from centos 4.1 as its original build.

I can give you access if you need it? or perhaps you can tell me what I am looking for?

Nick

Sun, 02/03/2008 - 12:41 (Reply to #22)
Joe
Joe's picture

One thing to check would be the permissions on /usr/bin/procmail-wrapper - they should be -rwsr-sr-x as shown by ls -l.

Also, make sure that /etc/postfix/main.cf has a line like :

mailbox_command = /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME

--

Check out the forum guidelines!

Sun, 02/03/2008 - 13:00 (Reply to #23)
nickiles

Jamie

I can confirm both are correct:

-rwsr-sr-x 1 root root 6851 Aug 3 2006 /usr/bin/procmail-wrapper

main.cf: mailbox_command = /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME

Nick

Sun, 02/03/2008 - 13:07 (Reply to #24)
Joe
Joe's picture

I'd be happy to login to your system too to take a closer look - if that's OK, email me your login details at jcameron@virtualmin.com

--

Check out the forum guidelines!

Sun, 02/03/2008 - 13:54 (Reply to #25)
SeanWolfe

<div class='quote'>
When I copied in the exact same version of procmail from my Ubuntu system (3.22) to /usr/bin/procmail, it started working just fine! My guess is that the version built by Gentoo has some strange patches that cause this. Bizarre ..
</div>

So it's the exact same version, but just seems to run differently? That is bizzare. I can look further into the Gentoo ebuild and see why it's like that. Do you have any idea what we can possibly do to check about whether procmail runs like this? Maybe you can add that check to your install script.

Did you change anything else on the system besides the binary?

Thanks so much for your help, this has been a head scratcher for <b>Months</b>! Once again, I am much in debt to you! :)

The last only weird problem I have now is that I updated syslog-ng and logrotate a couple weeks ago. This seems to have caused Postfix to once in awhile, stop writing to the mail.log file. I think this usually happens on the logrotate shedule. Should I add a /etc/init.d/postfix reload in the after actions for that rotation?

Sun, 02/03/2008 - 13:55 (Reply to #26)
SeanWolfe

My mail headers are finally showing the results:

<div class='quote'>
X-Spam-Flag: No
X-Spam-Score: -2.3
X-Spam-DCC: _DCCB_: _DCCR_
X-Spam-Checker-Version: SpamAssassin 3.2.1-gr1 (2007-05-02) on
salvonexus.spindlex.com
X-Spam-Level:
X-Spam-Status: No, score=-2.3 required=4.0 tests=AWL,BAYES_00 autolearn=ham
version=3.2.1-gr1
X-Spam-Pyzor:
</div>

Awesome! Thanks again Jamie!

Sun, 02/03/2008 - 15:10 (Reply to #27)
Joe
Joe's picture

Yes, it was the same Procmail version number.

Oh, I also noticed that some Webmin programs were using /var/webmin as their log directory (which doesn't exist), while others used /var/log/webmin . This is why the lookup-domain-daemon.log file wasn't being updated. Once I linked /var/webmin to /var/log/webmin , all was well.

--

Check out the forum guidelines!

Sun, 02/03/2008 - 20:08 (Reply to #28)
Joe
Joe's picture

After looking at Nick's system, I found the *real* cause of this problem, and it turned out to be a bug in procmail !

It seems that if the default mail directory /var/mail doesn't exist, procmail's code will stupidly switch to the user who is receiving email right away, causing most of /etc/procmailrc to fail. When I created the /var/mail directory on his system, it started working again.

I'm going to file a bug with the procmail developers about this ..

--

Check out the forum guidelines!

Sun, 02/03/2008 - 21:48 (Reply to #29)
nickiles

Jamie

Thanks for all the work on this - much appreciated - I thought it was all something I had done. Emails are now properly being tagged!

Nick

Mon, 02/04/2008 - 03:57 (Reply to #30)
SeanWolfe

Jamie,

Great detective work! I see that the procmail bug couldn't have affected my system since I had the /var/mail dir. Did you find this through the source or just investigating? Maybe we can make a patch.

Anyways, thanks again for your help.

Mon, 02/04/2008 - 07:33 (Reply to #31)
Joe
Joe's picture

I'm betting Jamie used his favorite system-level sleuthing tool, strace...but that's just a guess.

--

Check out the forum guidelines!

Mon, 02/04/2008 - 14:25 (Reply to #32)
Joe
Joe's picture

Yeah, strace knows all .. and it was able to point me in the right direction in this case. I also had to look at the procmail source code though.

In Sean's case, I've realized that procmail was looking for mail in the ~/.maildir directory, and incorrect switching IDs when that was not found. This must have been a path compiled into the Gentoo version of procmail, which is why it started working when I replace procmail with the copy from my system (which looks for /var/mail , which exists on Sean's system).

--

Check out the forum guidelines!

Sun, 06/07/2009 - 07:18
SeanWolfe

Ok, someone please answer me if they have an idea. This is driving me crazy.

Here is what I think is really happening.

This is my /etc/procmailrc
[code:1]
# Use maildir-style mailbox in user's home directory
VERBOSE=yes
LOGFILE=/var/log/procmail.log
TRAP=//etc/webmin/virtual-server/procmail-logger.pl
:0wi
VIRTUALMIN=|/etc/webmin/virtual-server/lookup-domain.pl $LOGNAME
:0
* ?/usr/bin/test &quot;$VIRTUALMIN&quot; != &quot;&quot;
{
INCLUDERC=//etc/webmin/virtual-server/procmail/$VIRTUALMIN
}
ORGMAIL=$HOME/Maildir/
DEFAULT=$HOME/Maildir/
DROPPRIVS=yes

:0
* ^X-Spam-Status: Yes
$DEFAULT
[/code:1]

And looking at the procmail log, I see this.

[code:1]
procmail: Assigning &quot;TRAP=//etc/webmin/virtual-server/procmail-logger.pl&quot;
procmail: Assigning &quot;VIRTUALMIN=&quot;
procmail: Executing &quot;/etc/webmin/virtual-server/lookup-domain.pl,joesomeone.mydomain&quot;
procmail: Executing &quot;/usr/bin/test,,!=,&quot;
procmail: Non-zero exitcode (1) from &quot;/usr/bin/test&quot;
procmail: No match on &quot;/usr/bin/test != &quot;
procmail: Assigning &quot;ORGMAIL=/home/windish/homes/amy/Maildir/&quot;
procmail: Assigning &quot;DEFAULT=/home/windish/homes/amy/Maildir/&quot;
procmail: Assigning &quot;DROPPRIVS=yes&quot;
procmail: Assuming identity of the recipient, VERBOSE=off
procmail: No match on &quot;^X-Spam-Status: Yes&quot;
procmail: Assigning &quot;PATH=/home/mydomain/homes/joesomeone/bin:/bin:/usr/bin:/usr/local/bin&quot;
procmail: Assigning &quot;LASTFOLDER=/home/mydomain/homes/joesomeone/Maildir/new/1201644084.13825_0.myserver.mydomain.com&quot;
procmail: Notified comsat: &quot;amy.windishagency@0:/home/mydomain/homes/joesomeone/Maildir/new/1201644084.13825_0.myserver.mydomain.com&quot;
From somebloke@outheresomehwere.com Tue Jan 29 16:01:24 2008
Subject: This is the story of my life
Folder: /home/mydomain/homes/joesomeone/Maildir/new/1201644084.13825_0.myserver.mydomain.com 9016
procmail: Assigning &quot;EXITCODE=0&quot;
procmail: Executing &quot;//etc/webmin/virtual-server/procmail-logger.pl&quot;
Time:1201644084 From:&Acirc;&laquo;&Acirc;&raquo;somebloke@outheresomehwere.com To:joesomeone@mydomain.com User:joesomeone.mydomain Size:9062 Dest:/home/mydomain/homes/joesomeone/Maildir/new/1201644084.13825_0.myserver.mydomain.com Mode:None

[/code:1]

Now look at this...
<div class='quote'>procmail: Assigning &quot;VIRTUALMIN=&quot;
procmail: Executing &quot;/etc/webmin/virtual-server/lookup-domain.pl,joesomeone.mydomain&quot;</div>
VIRTUALMIN is not getting assigned. And the lookup-domain.pl script is being fired AFTER the assignment. This makes no sense to me. As far as I understand Procmail, =| will run the script following it, wait for it to return with data, and then set it to the variable to the left.
Is this not happening for some reason? Is there some magic Procmail etting that is set somewhere that I don't know about?

Any ideas?

Anyone?

Anyone?

Fri, 02/01/2008 - 11:41
Joe
Joe's picture

Ok, your procmailrc file looks fine.

Another thing to check is the log file /var/webmin/lookup-domain-daemon.log for new lines that get logged when email comes in. This should indicate why spam filtering isn't done..

--

Check out the forum guidelines!

Sat, 02/02/2008 - 12:05
nickiles

I have the same issue - have followed all the troubleshooting steps so far and it all seems ok so far. I have similar entries in the logs to the other user - mail just seems not to get processed by spamassassin. So all help greatly appreciated!

Nick

Sat, 02/02/2008 - 12:27 (Reply to #36)
nickiles

I have done some further investigations on my server by looking at the procmail log - there are loads of entries for root, but none for any other user - see below:

Time:1201986014 From:root@www.niuk.net To:root@www.niuk.net User:root Size:913 Dest:/root/Maildir/new/1201986001.11169_1.www.niuk.net Mode:None
From root@www.niuk.net Sat Feb 2 21:00:01 2008
Subject: Cron &lt;root@www&gt; /usr/share/clamav/freshclam-sleep
Folder: /root/Maildir/new/1201986001.11172_1.www.niuk.net 861
Time:1201986025 From:root@www.niuk.net To:root@www.niuk.net User:root Size:911 Dest:/root/Maildir/new/1201986001.11172_1.www.niuk.net Mode:None
From root@www.niuk.net Sat Feb 2 21:00:01 2008
Subject: Cron &lt;root@www&gt; /usr/share/clamav/freshclam-sleep
Folder: /root/Maildir/new/1201986001.11171_1.www.niuk.net 851

Sat, 02/02/2008 - 16:47
SeanWolfe

Also, I did this, just to test that the daemon is responding:

[code:1]
salvonexus seanwolfe # telnet localhost 11000
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
sean.spindlex
11680492405802 spindlex.com 1 1 UNLIMITED
Connection closed by foreign host.
[/code:1]

So, it seems to be doing something.

Sat, 02/02/2008 - 18:07 (Reply to #38)
Joe
Joe's picture

Ok, that all looks fine to me.
I'd have to login to see what is really going wrong, so I have emailed you my public keys..

--

Check out the forum guidelines!

Sun, 02/03/2008 - 05:19
nickiles

Jamie

I am having similar issues - I can see mail is being processed by procmail as per logs below:

<div class='quote'>Feb 3 15:17:37 www postfix/smtpd[12166]: connect from py-out-1112.google.com[64.233.166.180]
Feb 3 15:17:37 www postfix/smtpd[12166]: C75032A803D: client=py-out-1112.google.com[64.233.166.180]
Feb 3 15:17:38 www postfix/cleanup[12283]: C75032A803D: message-id=&lt;866917ad0802030717k11ece977o6b8b015037bb9e2b@mail.gmail.com&gt;
Feb 3 15:17:38 www postfix/qmgr[15822]: C75032A803D: from=&lt;nick.iles@gmail.com&gt;, size=1981, nrcpt=1 (queue active)
Feb 3 15:17:39 www procmail[12285]: Error while writing to &quot;/var/log/procmail.log&quot;
Feb 3 15:17:39 www postfix/local[12284]: C75032A803D: to=&lt;nick.niuk.net@www.niuk.net&gt;, orig_to=&lt;nick@niuk.net&gt;, relay=local, delay=2, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Feb 3 15:17:39 www postfix/qmgr[15822]: C75032A803D: removed
</div>

Any chance you can suggest anything else - this machine is on VMIN Pro 3.51 and Centos 4.6

Nick