very slow sendmail / newaliases

rocky

rocky

Hello all,

I'd like to use `sendmail` on my desktop system but sendmail starts slowy at boot time.

When system boots, `sendmail` daemon will execute the program `newaliases` to generate aliases from /etc/mail/aliases. I note that `newaliases` consumes so much time:

Code: 
# time newaliases
/etc/mail/aliases: 27 aliases, longest 10 bytes, 275 bytes total

real    0m15.016s
user    0m0.000s
sys     0m0.013s

I use the default /etc/mail/aliases. In this file I see the note:

Code: 
# The program "newaliases" must be run after
# his file is updated for any changes to
# show through to sendmail.

I never change /etc/mail/aliases so why do `sendmail` always run `newaliases` to update stuff?

Any idea?

Thanks for your helps.

PS: one of my friends gave up FreeBSD because he couldnot suffer such slow sendmail. He was back to Linux �e
 
Sendmail will only do this (as far as I know) when /etc/mail/aliases is newer than /etc/mail/aliases.db. I've never seen newaliases being run when booting. It just says 'Starting sendmail', and then it moves on to whatever's next.

Oh, and this is normal:

Code: 
/etc/mail/aliases: 29 aliases, longest 10 bytes, 303 bytes total

real	0m0.015s
user	0m0.012s
sys	0m0.002s
 
I don't think that's the default behaviour - I just checked my aliases file and it has not been rebuilt since I last rebooted (actually, it was VirtualBox induced panic).

You're not running sendmail with the -bi command line switch are you? That would cause it to reinit the aliases file every time it was started.

As for the time taken... 15s seems exceedingly excessive! On my Pentium III 1GHz system the time taken is hardly measurable:

Code: 
root@centurion [/home/trev] $ time newaliases
/etc/mail/aliases: 65 aliases, longest 21 bytes, 792 bytes total
0.031u 0.007s 0:00.04 75.0%     764+700k 0+0io 0pf+0w

That's curious, your time output is differently formatted to mine above. Which FreeBSD version are you running? I get the above format on both 6.4 and 7.2.
 
@trev: I used `bash` which has a builtin `time`. So my result is different from your one.

I use FreeBSD-7.2 with default settings of `sendmail` (this means that I made no changes that related to sendmail). (And my friend has the same problem. His sendmail is slow in his first boot after a fresh installation of FreeBSD-7.1)

`newaliases` is very slow on my system. This is really curious. Let us 'truss' it:

Code: 
...
SIGUSR2,0x0) = 0 (0x0)
access("/lib/nss_dns.so.1",0)                    ERR#2 'No such file or directory'
access("/usr/lib/nss_dns.so.1",0)                ERR#2 'No such file or directory'
access("/usr/lib/compat/nss_dns.so.1",0)         ERR#2 'No such file or directory'
access("/usr/local/lib/nss_dns.so.1",0)          ERR#2 'No such file or directory'
access("/usr/local/lib/compat/pkg/nss_dns.so.1",0) ERR#2 'No such file or directory'
access("/usr/local/NX/lib/nss_dns.so.1",0)       ERR#2 'No such file or directory'
access("/usr/local/lib/compat/nss_dns.so.1",0)   ERR#2 'No such file or directory'
access("/usr/local/lib/graphviz/nss_dns.so.1",0) ERR#2 'No such file or directory'
access("/usr/local/lib/kde3/nss_dns.so.1",0)     ERR#2 'No such file or directory'
access("/usr/local/lib/mysql/nss_dns.so.1",0)    ERR#2 'No such file or directory'
access("/usr/local/lib/nss/nss_dns.so.1",0)      ERR#2 'No such file or directory'
access("/usr/local/lib/pth/nss_dns.so.1",0)      ERR#2 'No such file or directory'
access("/usr/local/lib/qt4/nss_dns.so.1",0)      ERR#2 'No such file or directory'
access("/usr/local/lib/wine/nss_dns.so.1",0)     ERR#2 'No such file or directory'
access("/lib/nss_dns.so.1",0)                    ERR#2 'No such file or directory'
access("/usr/lib/nss_dns.so.1",0)                ERR#2 'No such file or directory'
sigprocmask(SIG_SETMASK,0x0,0x0)                 = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0)                 = 0 (0x0)
ioctl(3,TIOCGETA,0xbfbfd2b8)                     ERR#25 'Inappropriate ioctl for device'
close(3)                                         = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0)                 = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0)                 = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0)                 = 0 (0x0)
stat("/etc/nsswitch.conf",{ mode=-rw-r--r-- ,inode=236286,size=322,blksize=4096 }) = 0 (0x0)
stat("/etc/nsswitch.conf",{ mode=-rw-r--r-- ,inode=236286,size=322,blksize=4096 }) = 0 (0x0)
stat("/etc/nsswitch.conf",{ mode=-rw-r--r-- ,inode=236286,size=322,blksize=4096 }) = 0 (0x0)
getegid(0x1,0xbfbfd4f4,0x1,0x0,0x0,0x1)          = 0 (0x0)

# something happened here and I have to wait for a long time (10s or more)

/etc/mail/aliases: 27 aliases, longest 10 bytes, 275 bytes total
process exit, rval = 0

You see that after executing getegid newaliases behavior is strange but nothing was printed.

Please note that this problem occured on a fresh installation of FreeBSD-7.1 too, though I don't have any 'truss' message now.
 
Does this program return instantly or also take a long time?

Code: 
#include <sys/types.h>
#include <unistd.h>
#include <stdio.h>

int main(void)
{
printf("EGUID: %li\n", getegid());
return(0);
}
 
trev said:
That's curious, your time output is differently formatted to mine above. Which FreeBSD version are you running? I get the above format on both 6.4 and 7.2.
Click to expand...
There's a difference in format of the buildin time command of tcsh, bash and /usr/bin/time.

@Rocky

What does your /etc/nsswitch.conf look like?
 
My /etc/nsswitch.conf:

Code: 
$ cat /etc/nsswitch.conf 
#
# nsswitch.conf(5) - name service switch configuration file
# $FreeBSD: src/etc/nsswitch.conf,v 1.1.8.1 2009/04/15 03:14:26 kensmith Exp $
#                        
group: compat
group_compat: nis
hosts: files dns
networks: files
passwd: compat
passwd_compat: nis
shells: files
services: compat
services_compat: nis
protocols: files
rpc: files

@trev: your test programe works fine
Code: 
$ gcc test.c
$ time ./a.out
EGUID: 3140
real    0m0.001s
user    0m0.001s
sys     0m0.001s
 
I don't think there is any problem with my /etc/hosts

Code: 
# grep -vE '^#' /etc/hosts
::1                     localhost localhost.my.domain
127.0.0.1               localhost localhost.my.domain
127.0.0.1 icy icy.localdomain
 
Does the newalias behaviour change if you remove:

Code: 
127.0.0.1 icy icy.localdomain

Not sure where ".localdomain" comes from, but when I added that to my hosts file, the newalias command took 10 seconds to complete compared with < 1 second.
 
trev said:
Does the newalias behaviour change if you remove:

Code: 
127.0.0.1 icy icy.localdomain

Not sure where ".localdomain" comes from, but when I added that to my hosts file, the newalias command took 10 seconds to complete compared with < 1 second.
Click to expand...

Cool! If I use

Code: 
127.0.0.1 icy.localdomain icy

the `newaliases` goes too fast.

This is my typo error when editing the /etc/hosts :( So sorry for my fault!

Thank you all for your patience and helps.
 
trev said:
You're welcome. Glad it's sorted.
Click to expand...

Thank you.

After I reboot the machine, the problem is still the same.

Code: 
# /usr/bin/time dig icy > /dev/null
        0.00 real         0.00 user         0.00 sys

# /usr/bin/time newaliases

/etc/mail/aliases: 27 aliases, longest 10 bytes, 275 bytes total
       15.01 real         0.00 user         0.00 sys

#  grep -vE '^#' /etc/hosts
::1                     localhost localhost.my.domain
127.0.0.1               localhost localhost.my.domain
127.0.0.1               icy     icy.localdomain
127.0.0.1               icy.localdomain icy

# I tried to change /etc/hosts
# and run `/etc/rc.d/netif restart`

Because `dig` replies DNS query for `icy` very fast I don't think the problem is caused by DNS query.

Looking back to `truss` message above. After getegid is executed the program `newaliases` waits for something for a long time . Don't know what it is... I should check the source code of `newaliases` instead :D
 
rocky said:
Thank you.

After I reboot the machine, the problem is still the same.

Code: 
127.0.0.1               icy     icy.localdomain
127.0.0.1               icy.localdomain icy
Click to expand...

I'd remove the icy lines above from the hosts file and see what happens. I'm betting everything will be fine.

Looking back to `truss` message above. After getegid is executed the program `newaliases` waits for something for a long time . Don't know what it is... I should check the source code of `newaliases` instead :D
Click to expand...

newaliases is simply an alias for "sendmail -bi", so you're after the sendmail source code :)
 
I read the sendmail source code (infact, I read `/usr/src/contrib/sendmail/src/main.c`) but there aren't any script to build sendmail (FreeBSD has removed Build script to generate her own one when running, for e.g., `buildworld`). So I don't think again of recompiling stuff. That isn't necessary.

Anyway I luckily find another way to debug `sendmail`.

Code: 
# as normal user
$ sendmail -v -bi -d 99.99
 getauthinfo: pi@localhost

============ SYSTEM IDENTITY (after readcf) ============
      (short domain name) $w = icy
  (canonical domain name) $j = icy.localdomain
         (subdomain name) $m = localdomain
              (node name) $k = icy.localdomain
========================================================

Deny user 314 attempt to rebuild the alias map
Permission denied (real uid not trusted)

====finis: stat 64 e_id=NOQUEUE e_flags=1<OLDSTYLE>

After `sendmail` prints " getauthinfo: pi@localhost" I have to wait for 10 seconds or more until it prints "SYSTEM IDENTITY".

Code: 
# truss sendmail -v -bi -d 99.99

....

write(1,"getauthinfo: pi@localhost\n",26)        = 26 (0x1a)
socket(PF_INET,SOCK_DGRAM,0)                     = 3 (0x3)
ioctl(3,SIOCGIFCONF,0xbfbfd544)                  = 0 (0x0)
ioctl(3,SIOCGIFFLAGS,0xbfbfd514)                 = 0 (0x0)
ioctl(3,SIOCGIFFLAGS,0xbfbfd514)                 = 0 (0x0)
stat("/etc/nsswitch.conf",{ mode=-rw-r--r-- ,inode=236286,size=322,blksize=4096 }) = 0 (0x0)
kqueue(0x0,0xbfbfd1b0,0x730ea681,0x28116100,0x0,0x0) = 4 (0x4)

socket(PF_INET,SOCK_DGRAM,0)                     = 5 (0x5)
connect(5,{ AF_INET 127.0.0.1:53 },16)           = 0 (0x0)

sendto(5,"\M^?\^Y\^A\0\0\^A\0\0\0\0\0\0\^A"...,90,0x0,NULL,0x0) = 90 (0x5a)
clock_gettime(0,{1243052459.774355679 })         = 0 (0x0)
kevent(4,{0x5,EVFILT_READ,EV_ADD|EV_ONESHOT,0,0x0,0x0},1,{},1,{5.000000000 }) = 0 (0x0)
sendto(5,"\M^?\^Y\^A\0\0\^A\0\0\0\0\0\0\^A"...,90,0x0,NULL,0x0) = 90 (0x5a)
clock_gettime(0,{1243052464.777030180 })         = 0 (0x0)
kevent(4,{0x5,EVFILT_READ,EV_ADD|EV_ONESHOT,0,0x0,0x0},1,{},1,{10.000000000 }) = 0 (0x0)
close(5)                                         = 0 (0x0)
close(4)                                         = 0 (0x0)
open("/etc/hosts",O_RDONLY,0666)                 = 4 (0x4)
fstat(4,{ mode=-rw-r--r-- ,inode=236273,size=1154,blksize=4096 }) = 0 (0x0)
read(4,"# $FreeBSD: src/etc/hosts,v 1.16"...,4096) = 1154 (0x482)
close(4)                                         = 0 (0x0)
ioctl(3,SIOCGIFFLAGS,0xbfbfd514)                 = 0 (0x0)
stat("/etc/nsswitch.conf",{ mode=-rw-r--r-- ,inode=236286,size=322,blksize=4096 }) = 0 (0x0)
kqueue(0x4,0xbfbfd1b0,0x73010000,0xbfbfc7c4,0x0,0x0) = 4 (0x4)

socket(PF_INET,SOCK_DGRAM,0)                     = 5 (0x5)
connect(5,{ AF_INET 127.0.0.1:53 },16)           = 0 (0x0)

sendto(5,"\M^?\^Z\^A\0\0\^A\0\0\0\0\0\0\^A"...,40,0x0,NULL,0x0) = 40 (0x28)
clock_gettime(0,{1243052474.781901540 })         = 0 (0x0)
kevent(4,{0x5,EVFILT_READ,EV_ADD|EV_ONESHOT,0,0x0,0x0},1,{0x5,EVFILT_READ,EV_ONESHOT,0,0x3f,0x0},1,{5.000000000 }) = 1 (0x1)
recvfrom(5,"\M^?\^Z\M^A\M^@\0\^A\0\^A\0\0\0"...,65536,0x0,{ AF_INET 127.0.0.1:53 },0xbfbfc054) = 63 (0x3f)
close(5)                                         = 0 (0x0)
close(4)                                         = 0 (0x0)
ioctl(3,SIOCGIFFLAGS,0xbfbfd514)                 = 0 (0x0)
stat("/etc/nsswitch.conf",{ mode=-rw-r--r-- ,inode=236286,size=322,blksize=4096 }) = 0 (0x0)
kqueue(0x4,0xbfbfd1b0,0x73010000,0xbfbfc7c4,0x0,0x0) = 4 (0x4)
socket(PF_INET,SOCK_DGRAM,0)                     = 5 (0x5)

connect(5,{ AF_INET 127.0.0.1:53 },16)           = 0 (0x0)
sendto(5,"\M^?\^[\^A\0\0\^A\0\0\0\0\0\0\^A"...,40,0x0,NULL,0x0) = 40 (0x28)
clock_gettime(0,{1243052474.783245984 })         = 0 (0x0)
kevent(4,{0x5,EVFILT_READ,EV_ADD|EV_ONESHOT,0,0x0,0x0},1,{},1,{5.000000000 }) = 0 (0x0)
sendto(5,"\M^?\^[\^A\0\0\^A\0\0\0\0\0\0\^A"...,40,0x0,NULL,0x0) = 40 (0x28)
clock_gettime(0,{1243052479.786728620 })         = 0 (0x0)
kevent(4,{0x5,EVFILT_READ,EV_ADD|EV_ONESHOT,0,0x0,0x0},1,{},1,{10.000000000 }) = 0 (0x0)
close(5)                                         = 0 (0x0)
close(4)                                         = 0 (0x0)
open("/etc/hosts",O_RDONLY,0666)                 = 4 (0x4)
fstat(4,{ mode=-rw-r--r-- ,inode=236273,size=1154,blksize=4096 }) = 0 (0x0)
read(4,"# $FreeBSD: src/etc/hosts,v 1.16"...,4096) = 1154 (0x482)
close(4)                                         = 0 (0x0)
ioctl(3,SIOCGIFFLAGS,0xbfbfd514)                 = 0 (0x0)
close(3)                                         = 0 (0x0)

============ SYSTEM IDENTITY (after readcf)

.....

Yes it's true that `sendmail` tries to Find our real host name for future logging (see `sendmail/src/main.c`). And my problem was caused by DNS resolver which is provided by DHCP server.

In short, to avoid this type of problem (if you're a newbie and eager to install a fresh FreeBSD on your machine) the following steps may be useful:

  1. in `/etc/rc.conf`:
    Code: 
    host="icy.localdomain"
    Don't use "icy" when FreeBSD installation asks you for `hostname`. Read man rc.conf(5) for details.
  2. in `/etc/nsswitch.conf`:
    Code: 
    hosts: files dns
  3. in `/etc/hosts`
    Code: 
    127.0.0.1       icy.localdomain         icy
   # see hosts(8) for details

I will write a tutorial on setting up personal DNS resolver so that I can "hosts: dns files" (as my log show).

Thank you all for helps and following my issue.
 
If we use "hosts: dns files" in /etc/nsswitch.conf, the DNS resolver must support IPV6.

When searching for the host name of the IP 127.0.0.1 `sendmail` first tries the IPv6 address of 127.0.0.1 (`sendmail` will sends to the resolver the string "...ip6.arpa"). If DNS resolver doesn't support IPV6, the query takes a long time to finish. This is exactly my problem.

We may use IPv4 version of `sendmail` (but I don't know how to compile `sendmail` without IPv6 support).

A final note: to rebuild `sendmail` please go to /usr/src/usr.sbin/sendmail then type make ;)
 
You must log in or register to reply here.
Back
Top