Tuesday, February 25, 2003

Well, that (see yesterdays blog) didn't work. I got a call from the admin this morning that email didn't work, and sure enough it was not delivering mail at all. I undid the change to /var/qmail/control/ldaptimeout and restarted. It took about 5 restarts ((vi /etc/inittab; kill -HUP 1)*2), but eventually it got through the whole deliver queue. The problem still remained of why was this happening. One clue was found by setting /var/qmail/control/loglevel-send to 127 and restarting. I would get something like exhibit 1, except the "success" time was a minute and a half later than the "executing..." time.

The other big clue was that "top" on the openldap server box showed slapd pegged at close to 100% of the cpu. This told me that OpenLDAP was too busy.

Upon further examination of exhibit 1, I noticed that the mailAlternateAddress was being searched every time. The "mail" field is indexed by default, but the mailAlternateAddress was not indexed. I changed the /etc/openldap/slapd file on the OpenLDAP server by adding the line index mailAlternateAddress eq, and that seems to have fixed everything up quite nicely.

Along the way, I developed two useful utilities for looking at the logs; delivery and deliveries. Delivery's output is shown in exhibit 1. It shows all the information about a specific delivery. The source is in exhibit 2. Deliveries simply shows multiple deliveries. It's source is in exhibit 3.

Exhibit 1

[root@mail qmail]# ./delivery 42

2003-02-25 15:48:18.344906500 starting delivery 42: msg 451289 to local eddie@client.net
2003-02-25 15:48:18.402715500 delivery 42: log: LOGLEVEL_set_to_127/
2003-02-25 15:48:18.402858500 delivery 42: log: mailaddr:_eddie@client.net/
2003-02-25 15:48:18.422529500 delivery 42: log: ldapfilter:_'(|(mail=eddie@client.net) ...
(mailAlternateAddress=eddie@client.net))'/
2003-02-25 15:48:18.431933500 delivery 42: log: ldap_get_userinfo:_qmailUID:_
2003-02-25 15:48:18.432307500 delivery 42: log: 508_(default)/
2003-02-25 15:48:18.435458500 delivery 42: log: homeDirectory=/u/eddie_(from_server)/
{ SOME INFORMATION SKIPPED FOR SPACE }
2003-02-25 15:48:18.439944500 delivery 42: log: found:_user='eddie'_uid=508_gid=508_...
homedir='/u/eddie'_mms='/u/eddie/Maildir/'_...
host='mail.client.com'_status=-1/
2003-02-25 15:48:18.441235500 delivery 42: log: executing_'qmail-local_--_eddie_/u/eddie_...
eddie@client.net_ann@abc.com_...
/u/eddie/Maildir/'_under_uid=508,_gid=508/
2003-02-25 15:48:18.604907500 delivery 42: success: did_1+0+0/

Exhibit 2: delivery

#!/bin/sh

CAT="@* current"
cat $CAT | grep "delivery $1:" | /command/tai64nlocal

Exhibit 3: deliveries

#!/bin/sh

START=$1
FINI=$2
if [ -z "$START" ]; then
echo "$0 usage:"
echo "$0 r1 {r2}"
echo "if r2 is not given, then deliveries 1-r1 are shown, else"
echo "deliveries r1-r2 are shown"
exit 1
fi
if [ -z "$FINI" ]; then
FINI=$START
START=1
fi


for i in `awk 'BEGIN{for(i='$START';i<='$FINI';i++)print i;}'`;do
clear
./delivery $i
/bin/echo -n "continue: "
read x
done


Comments: Post a Comment

<< Home

This page is powered by Blogger. Isn't yours?