As I write this, I'm getting ready to announce this system to the public on my web site. I've asked a few friends to test the system for me, but I haven't heard anything back from them about it, so I don't know if they have run into any problems, or if they've even looked at it. So the only problems I know about are the ones that I have personally run into, or the ones which I can guess will be common issues.
If you do run into any problems which aren't answered here, please ask on the qmail-patch mailing list instead of emailing me directly (unless you want to hire me as a consultant to take care of a specific issue, of course.)
I have tried to test the system on three different machines, using all three database engines listed above (PostgreSQL, MySQL, and SQLite.) However, most of my testing and all of my live usage has been on my own server, where I use PostgreSQL, so the other two engines honestly haven't been tested as well as PostgreSQL has.
Most of the problems you will encounter will be while trying to test or use either the web interface, or the rcptcheck.pl processing script. If you are having an issue with the database itself, your best bet is to review the setup instructions for the database engine you're using.
The web interface sends error messages and other diagnostic information to Apache's error log file. The ErrorLog directive in your httpd.conf file will tell you where this is.
The browser shows a "Server error!" or "Error 500" page, and the error log tells me "Can't locate Rules.pm in @INC".
You may not have created your .htaccess file yet. If not, copy the .htaccess.dist file to .htaccess, run the fix-permissions.sh script, and edit the .htaccess file as explained below.
$ cp .htaccess.dist .htaccess
$ sh fix-permissions.sh
$ nano .htaccess I prefer nano, but feel free to use
whatever text editor you like.
Your .htaccess file should contain a line which sets the
PERL5LIB variable. This variable needs to contain the full path
to where the Rules.pm module is. If the system is installed in
The browser tells me The database connection is not configured.
Your .htaccess file should contain a line which sets the G4DBCONN variable. This variable needs to contain a string which tells Perl how to reach your database. See the appropriate section of the web page explaining how to set up your database engine:
The browser tells me The database connection is not working.
The error log tells me "Can't locate DBD/something.pm in @INC".
This could be one of two things:
The DBD module for your database engine is not installed, or is not installed correctly. See the appropriate section of the web page explaining how to set up your database engine:
If you installed the module using CPAN, you may also need to fix the permissions on the files which were installed. My pfix script can be helpful in this case.
You may have mis-spelled the name of the module in your G4DBCONN string. If the module is called "DBD::Pg", the G4DBCONN string should start with "DBI:Pg:". Check your spelling and try again.
The browser tells me The database connection is not working.
The error log tells me "Cannot connect to "dbi:Pg(PrintError=>0):dbname=rules": FATAL: Ident authentication failed for user "g4web"".
This could be one of several things:
The database name in your G4DBCONN string could be spelled incorrectly, or you haven't actually created the database yet.
As a PostgreSQL super-user (normally just the postgres user) try the command "psql -l". This should show you a list of the databases on the system.
Make sure that the database you created for this system is listed, and make sure that it's spelled the same way in the list as what you have in the "database=" part of your G4DBCONN string.
PostgreSQL security may not be configured correctly. If it were, PostgreSQL wouldn't be trying to do "Ident authentication" for this database.
Please review the PostgreSQL security setup directions.
Fix and try again.
The browser tells me The database connection is not working.
The error log tells me "Cannot connect to "dbi:Pg(PrintError=>0):dbname=rules": FATAL: password authentication failed for user "g4web"".
One of several things might be wrong:
The userid or password is incorrect.
Check the G4DBUSER and G4DBPASS variables in your .htaccess file. Make sure the userids are the same ones you created when setting things up, and make sure the passwords are correct. You can test a userid and password from the command line like this:
$ psql rules g4web
("rules" is the database name, and "g4web" is the userid.)
Password for user g4web: (wrong password)
psql: FATAL: password authentication failed for user "g4web"
$ psql rules g4web Password for user g4web: (correct password) Welcome to psql 8.1.23, the PostgreSQL interactive terminal. Type: \copyright for distribution terms \h for help with SQL commands \? for help with psql commands \g or terminate with semicolon to execute query \q to quit rules=> \q
If you need to, you can reset a PostgreSQL user's password by running the psql program as a PostgreSQL super-user and issuing an ALTER USER query:
The other possibility is that the userid was never created.
Please review the PostgreSQL setup instructions, make sure you enter the CREATE USER queries correctly, and that you see "CREATE ROLE" after each command (instead of an error message.)
The browser tells me The database connection is not working.
The error log tells me "Cannot connect to "dbi:Pg(PrintError=>0):dbname=rules": FATAL: database "rules" does not exist".
Either you didn't create the database, or you're spelling the database name incorrectly in your G4DBCONN string.
Most of the troubles I see people having with the rcptcheck.pl script will revolve around setting the necessary environment variables. Because the program's configuration and the data it uses for the tests will mostly be coming from environment variables, a useful debugging tool would be the ability to see all of the variables the script is receiving when it starts.
In order to help with this, I have added a block of code to the beginning of the script which will dump the entire environment out to the log file, if the file /var/qmail/control/g4dump exists. The contents and permissions don't really matter, the script checks to see if it exists and, if so, dumps its environment before starting its normal processing.
As long as qmail-smtpd is actually calling the script, you will be able to see all of the environment variables it's starting with, so that you can tell what data it's receiving, and hopefully tell if a problem is being caused by a bug in the script, or by qmail-smtpd (or some other program, such as tcpserver) not adding the variables you or I think should be added.
If you create the /var/qmail/control/g4dump file, please delete it as soon as you're finished with your testing. You may want to use two windows for this - watch the log file in one window, and in the other window create the file (using the "touch" command) and be ready to remove the file as soon as one or two messages have been processed. Leaving this file in place will make your log file grow much more quickly than it normally would.
Here's an example:
# touch /var/qmail/control/g4dump # tail -F /service/qmail-stmp/log/main/current @40000000500cd4a71ed88d94 tcpserver: end 16583 status 0 @40000000500cd4a71ed8994c tcpserver: status: 0/30 @40000000500cd4a8110ae464 tcpserver: status: 1/30 @40000000500cd4a8110b4224 tcpserver: pid 16594 from 65.55.90.34 @40000000500cd4a819e101f4 tcpserver: ok 16594 a.mx.jms1.net:69.28.72.69:25 snt0-omc1-s23.snt0.hotmail.com:65.55.90.34::38908 @40000000500cd4b2323b8904 qmail-smtpd[16594]: MFCHECK pass [65.55.90.34] hotmail.com @40000000500cd4b30b811f2c qmail-smtpd[16594]: Received-SPF: pass (a.mx.jms1.net: SPF record at spf-a.hotmail.com designates 65.55.90.34 as permitted sender) @40000000500cd4b30b812ae4 qmail-smtpd[16594]: MAIL FROM:<xxxxxx@hotmail.com> @40000000500cd4b3102f1eac qmail-smtpd[16594]: RCPT TO:<joe@xxxxxx.com> @40000000500cd4b3102f2a64 qmail-smtpd[16594]: validrcptto [65.55.90.34] trying: joe@xxxxxx.com @40000000500cd4b3102f3234 qmail-smtpd[16594]: validrcptto [65.55.90.34] found: joe@xxxxxx.com @40000000500cd4b40d2b96f4 rcptcheck.pl[16595][16594]: DUMP: ALLOW_INSECURE_AUTH="0" @40000000500cd4b40d2ba2ac rcptcheck.pl[16595][16594]: DUMP: AUTH_CDB="/var/qmail/control/auth.cdb" @40000000500cd4b40d2baa7c rcptcheck.pl[16595][16594]: DUMP: AUTH_SET_DATABYTES="0" @40000000500cd4b40d2bb24c rcptcheck.pl[16595][16594]: DUMP: AUTH_SET_SPFBEHAVIOR="1" @40000000500cd4b40d2bb634 rcptcheck.pl[16595][16594]: DUMP: DENY_TLS="0" @40000000500cd4b40d2bbe04 rcptcheck.pl[16595][16594]: DUMP: DIEMSG="421 a.mx.jms1.net Service not available, try later." @40000000500cd4b40d2c1fac rcptcheck.pl[16595][16594]: DUMP: DIEMSG_MAXCONNC="421 a.mx.jms1.net Too many connections from your network." @40000000500cd4b40d2c2b64 rcptcheck.pl[16595][16594]: DUMP: DIEMSG_MAXCONNIP="421 a.mx.jms1.net Too many connections from your IP address." @40000000500cd4b40d2c3334 rcptcheck.pl[16595][16594]: DUMP: DIEMSG_MAXLOAD="421 a.mx.jms1.net Server busy, try again later." @40000000500cd4b40d2c5e2c rcptcheck.pl[16595][16594]: DUMP: DROP_PRE_GREET="1" @40000000500cd4b40d2c6214 rcptcheck.pl[16595][16594]: DUMP: FORCE_TLS="0" @40000000500cd4b40d2c69e4 rcptcheck.pl[16595][16594]: DUMP: G4DBCONN="DBI:Pg(PrintError=>0):dbname=rules" @40000000500cd4b40d2c71b4 rcptcheck.pl[16595][16594]: DUMP: G4DBPASS="xxxxxx" @40000000500cd4b40d2c7984 rcptcheck.pl[16595][16594]: DUMP: G4DBUSER="g4mail" @40000000500cd4b40d2c9cac rcptcheck.pl[16595][16594]: DUMP: G4GREY24="0" @40000000500cd4b40d2ceeb4 rcptcheck.pl[16595][16594]: DUMP: GREETDELAY="10" @40000000500cd4b40d2cf684 rcptcheck.pl[16595][16594]: DUMP: HELO="snt0-omc1-s23.snt0.hotmail.com" @40000000500cd4b40d2cfe54 rcptcheck.pl[16595][16594]: DUMP: MAXCONNC="5" @40000000500cd4b40d2d023c rcptcheck.pl[16595][16594]: DUMP: MAXCONNIP="2" @40000000500cd4b40d2d0a0c rcptcheck.pl[16595][16594]: DUMP: MAXLOAD="800" @40000000500cd4b40d2d11dc rcptcheck.pl[16595][16594]: DUMP: MAXRCPT="100" @40000000500cd4b40d2dae1c rcptcheck.pl[16595][16594]: DUMP: MFCHECK="3" @40000000500cd4b40d2db204 rcptcheck.pl[16595][16594]: DUMP: NOP0FCHECK="1" @40000000500cd4b40d2db9d4 rcptcheck.pl[16595][16594]: DUMP: PATH="/var/qmail/bin:~vpopmail/bin:/usr/local/bin:/usr/bin:/bin" @40000000500cd4b40d2dc1a4 rcptcheck.pl[16595][16594]: DUMP: PROTO="TCP" @40000000500cd4b40d2dc974 rcptcheck.pl[16595][16594]: DUMP: PWD="/var/service/qmail-smtp" @40000000500cd4b40d2dcd5c rcptcheck.pl[16595][16594]: DUMP: QMAILQUEUE="/var/qmail/bin/simscan" @40000000500cd4b40d2df854 rcptcheck.pl[16595][16594]: DUMP: QMAILSMTPD_LOG_MAIL="1" @40000000500cd4b40d2e0024 rcptcheck.pl[16595][16594]: DUMP: QMAILSMTPD_LOG_RCPT="1" @40000000500cd4b40d2e07f4 rcptcheck.pl[16595][16594]: DUMP: RCPTCHECK="/var/qmail/bin/rcptcheck.pl" @40000000500cd4b40d2e0bdc rcptcheck.pl[16595][16594]: DUMP: RECIPIENT="joe@xxxxxx.com" @40000000500cd4b40d2e13ac rcptcheck.pl[16595][16594]: DUMP: RELAYREJ="1" @40000000500cd4b40d2e3abc rcptcheck.pl[16595][16594]: DUMP: REQUIRE_AUTH="0" @40000000500cd4b40d2e8cc4 rcptcheck.pl[16595][16594]: DUMP: SENDER="xxxxxx@hotmail.com" @40000000500cd4b40d2e90ac rcptcheck.pl[16595][16594]: DUMP: SHLVL="0" @40000000500cd4b40d2e987c rcptcheck.pl[16595][16594]: DUMP: SIMSCAN_DEBUG="0" @40000000500cd4b40d2ea04c rcptcheck.pl[16595][16594]: DUMP: SIMSCAN_DEBUG_FILES="0" @40000000500cd4b40d2ea434 rcptcheck.pl[16595][16594]: DUMP: SPFBEHAVIOR="3" @40000000500cd4b40d2eac04 rcptcheck.pl[16595][16594]: DUMP: SPFRESULT="pass" @40000000500cd4b40d2ed314 rcptcheck.pl[16595][16594]: DUMP: SPF_BLOCK_PLUS_ALL="1" @40000000500cd4b40d2edae4 rcptcheck.pl[16595][16594]: DUMP: SPF_LOG="1" @40000000500cd4b40d2ee2b4 rcptcheck.pl[16595][16594]: DUMP: SSL="0" @40000000500cd4b40d2eea84 rcptcheck.pl[16595][16594]: DUMP: TCPLOCALHOST="a.mx.jms1.net" @40000000500cd4b40d2eee6c rcptcheck.pl[16595][16594]: DUMP: TCPLOCALIP="69.28.72.69" @40000000500cd4b40d2ef63c rcptcheck.pl[16595][16594]: DUMP: TCPLOCALPORT="25" @40000000500cd4b40d2f1d4c rcptcheck.pl[16595][16594]: DUMP: TCPREMOTEHOST="snt0-omc1-s23.snt0.hotmail.com" @40000000500cd4b40d2f251c rcptcheck.pl[16595][16594]: DUMP: TCPREMOTEIP="65.55.90.34" @40000000500cd4b40d2f2cec rcptcheck.pl[16595][16594]: DUMP: TCPREMOTEPORT="38908" @40000000500cd4b40d2f30d4 rcptcheck.pl[16595][16594]: DUMP: TLS_SERVER_CERT="/var/qmail/control/servercert.pem" @40000000500cd4b40d2f38a4 rcptcheck.pl[16595][16594]: DUMP: USE_FD4="1" @40000000500cd4b40d2f5fb4 rcptcheck.pl[16595][16594]: DUMP: VALIDRCPTTO_CDB="/var/qmail/control/validrcptto.cdb" @40000000500cd4b40d2fb1bc rcptcheck.pl[16595][16594]: DUMP: VALIDRCPTTO_LIMIT="10" @40000000500cd4b40d2fb5a4 rcptcheck.pl[16595][16594]: DUMP: VALIDRCPTTO_LOG="2" @40000000500cd4b40d2fbd74 rcptcheck.pl[16595][16594]: xxxxxx@hotmail.com joe@xxxxxx.com 65.55.90.34 OK A @40000000500cd4b428a07594 tcpserver: end 16594 status 0 @40000000500cd4b428a134fc tcpserver: status: 0/30 (Hit CONTROL-C here) # rm /var/qmail/control/g4dump
Obviously I have obscured a few details to protect the identities of my clients and the people sending mail to them, as well as the real password I'm using for my PostgreSQL database, but otherwise everything you see is what actually appeared on my screen when I did this just now.
You will probably notice a few things in the log entries for rcptcheck.pl:
The log entires have two PIDs on them. The first one (in this example 16595) is the PID of rcptcheck.pl itself. The second one (in this example 16594) is the PID of the qmail-smtpd process which spawned this instance of rcptcheck.pl. This allows you to reliably correlate the log entries without having to guess which rcptcheck.pl goes with which qmail-smtpd.
The lines which start with "DUMP:" are the ones printed because the /var/qmail/control/g4dump file existed when the script ran. Normally you would not see these lines.
Other than the DUMP: lines, the rcptcheck.pl script only printed a single line of output, showing the sender, recipient, IP address, and disposition. In this case, the disposition "OK A" means that the message was accepted because of an "all messages" rule. This particular client has an "accept all messages" rule for their domain, because they don't want to risk losing email due to a blacklist. They seem to be okay with wading through the flood of spam they receive every day, and I'm certainly not going to force them to use any filtering they don't want.
Here's a more typical set of log entries. This is a test message that I just sent from my home test machine to myself on my server:
@40000000500cd917144aa22c tcpserver: status: 1/30 @40000000500cd9171452e374 tcpserver: pid 16831 from x.x.x.x @40000000500cd917145b4bcc tcpserver: ok 16831 a.mx.jms1.net:69.28.72.69:25 x-x-x-x.tpa.clearwire-wmx.net:x.x.x.x::36683 @40000000500cd92136b7ddac qmail-smtpd[16831]: AUTH successful [x.x.x.x] homeserver@domain.xyz @40000000500cd922007f76dc qmail-smtpd[16831]: MFCHECK pass [x.x.x.x] jms1.net @40000000500cd922007f8294 qmail-smtpd[16831]: MAIL FROM:<root@jms1.net> @40000000500cd9220fc29d54 qmail-smtpd[16831]: RCPT TO:<jms1@jms1.net> @40000000500cd922136dd2d4 rcptcheck.pl[16832][16831]: 1/1(5) I 69.28.72.64/28 no @40000000500cd922136de65c rcptcheck.pl[16832][16831]: 2/2(55) T "^xxxxxx" no @40000000500cd922136dee2c rcptcheck.pl[16832][16831]: 3/1(47) E "xxxxxx@gmail.com" no @40000000500cd922136df5fc rcptcheck.pl[16832][16831]: 3/2(12) E "@xxxxxx.com" no @40000000500cd922136f97f4 rcptcheck.pl[16832][16831]: 5/1(50) U MATCH (homeserver@domain.xyz) @40000000500cd922136f9fc4 rcptcheck.pl[16832][16831]: root@jms1.net jms1@jms1.net x.x.x.x OK U @40000000500cd9222a7a428c tcpserver: end 16831 status 0 @40000000500cd9222a7a4a5c tcpserver: status: 0/30
The lines which look like "3/1(47) E "^xxxxxx@gmail.com" no" are produced when a debug rule is present in the processing chain. The numbers "3/1(47)" are the phase, sequence, and rule ID being processed (so this one is "phase=3, seq=1, id=47".) The "E "^xxxxxx@gmail.com"" part tells that this is a "check sender email" rule, looking for the pattern shown, and the "no" at the end tells you that this message did not match that particular rule.
You may notice that phase 2 sequence 1 is missing. This is because this is the debug rule which turned on debugging for the jms1.net domain. I'm okay with using debugging on my own domain, but I don't need to enable it for the entire machine.
2012-08-20 Niamh Holding pointing out an interesting issue... If a recipient address has a "-" character in it, and qmail is also using "-" as the separator charcter for extension addresses, it can cause problems. I need to look into this.
In addition, I just noticed that when I wrote rcptcheck.pl, I have the "-" character hard-coded into the script. That needs to be fixed, but it won't happen today (I'm in the middle of packing up for a move.)