[Mimedefang] Re: milter timing out

-ray ray at ops.selu.edu
Fri Feb 13 00:14:05 EST 2004


On Fri, 6 Feb 2004, David F. Skoll wrote:

> On Fri, 6 Feb 2004, -ray wrote:
> 
> > Attached is the strace output file when the system was wedged.  I'm not
> > very good at reading strace files, so hopefully you can make sense of it.
> > I ran the md-mx-ctrl scan / command a few times also while strace was
> > running.  Thanks for any info...
> 
> The strace file shows that the multiplexor is working perfectly fine; it's
> activating slaves, passing commands back and forth, and everything looks
> OK.
> 
> The problem is most likely with the milter itself (mimedefang) rather than
> the multiplexor.

When revisiting this problem after doing some homework on MD, David you 
are absolutely correct.  The multiplexor is running fine, always keeping 
minslaves running (25).  The milter itself is what craps out.  (part of my 
confusion was not differentiating between mimedefang.pl perl slaves, and 
mimedefang milter processes).  My new mdchk.sh show this.

Thu Feb 12 22:30:18 CST 2004: Sendmail 18 : md slaves 25: md milters 8
Thu Feb 12 22:30:24 CST 2004: Sendmail 19 : md slaves 25: md milters 7
Thu Feb 12 22:30:29 CST 2004: Sendmail 15 : md slaves 25: md milters 7
Thu Feb 12 22:30:34 CST 2004: Sendmail 14 : md slaves 25: md milters 5
Thu Feb 12 22:30:39 CST 2004: Sendmail 17 : md slaves 25: md milters 7
Thu Feb 12 22:30:45 CST 2004: Sendmail 14 : md slaves 25: md milters 5
Thu Feb 12 22:30:50 CST 2004: Sendmail 15 : md slaves 25: md milters 6
Thu Feb 12 22:30:55 CST 2004: Sendmail 15 : md slaves 25: md milters 6
Thu Feb 12 22:31:00 CST 2004: Sendmail 16 : md slaves 25: md milters 7
Thu Feb 12 22:31:06 CST 2004: Sendmail 16 : md slaves 25: md milters 7
Thu Feb 12 22:31:11 CST 2004: Sendmail 15 : md slaves 25: md milters 6
Thu Feb 12 22:31:16 CST 2004: Sendmail 16 : md slaves 25: md milters 1
Thu Feb 12 22:31:21 CST 2004: Sendmail 20 : md slaves 25: md milters 1
Thu Feb 12 22:31:27 CST 2004: Sendmail 24 : md slaves 25: md milters 1
Thu Feb 12 22:31:32 CST 2004: Sendmail 26 : md slaves 25: md milters 1
Thu Feb 12 22:31:37 CST 2004: Sendmail 29 : md slaves 25: md milters 1
Thu Feb 12 22:31:42 CST 2004: Sendmail 33 : md slaves 25: md milters 1
Thu Feb 12 22:31:48 CST 2004: Sendmail 37 : md slaves 25: md milters 1
Thu Feb 12 22:31:53 CST 2004: Sendmail 42 : md slaves 25: md milters 1
Thu Feb 12 22:31:58 CST 2004: Sendmail 45 : md slaves 25: md milters 1
Thu Feb 12 22:32:03 CST 2004: Sendmail 19 : md slaves 0: md milters 0
Thu Feb 12 22:32:09 CST 2004: Sendmail 18 : md slaves 0: md milters 0
Thu Feb 12 22:32:14 CST 2004: Sendmail 17 : md slaves 4: md milters 4
Thu Feb 12 22:32:19 CST 2004: Sendmail 19 : md slaves 9: md milters 7
Thu Feb 12 22:32:24 CST 2004: Sendmail 18 : md slaves 14: md milters 5
Thu Feb 12 22:32:30 CST 2004: Sendmail 18 : md slaves 19: md milters 6
Thu Feb 12 22:32:35 CST 2004: Sendmail 19 : md slaves 24: md milters 7
Thu Feb 12 22:32:40 CST 2004: Sendmail 20 : md slaves 25: md milters 9


For no apparent reason, all except one of the milters die off.  My restart
script sees this and restarts md.  I believe the only one left is the
parent process.  Here's the one milter left:

[root at norm root]# ps -efl | grep fang | grep pid 
040 S defang 21164 1 0 82 0 - 17822 rt_sig 17:32 ? 00:00:00
/sendmail/software/bin/mimedefang -P
/sendmail/mqueue/MIMEDefang//mimedefang.pid


Is it responsible for forking new milter procceses?  For some reason it
stops.  I added a little debugging code in mimedefang.c around line 1674:

    /* Daemonize */
        syslog(LOG_INFO, "Forking new milter\n");
    i = fork();
    if (i < 0) {
        fprintf(stderr, "%s: fork() failed\n", argv[0]);
        syslog(LOG_INFO, "%s: fork() failed\n", argv[0]);
        exit(EXIT_FAILURE);
    } else if (i != 0) {
        /* parent */
        exit(EXIT_SUCCESS);
    }
    setsid();
    signal(SIGHUP, SIG_IGN);
    i = fork();
    if (i < 0) {
        fprintf(stderr, "%s: fork() failed\n", argv[0]);
        syslog(LOG_INFO, "%s: fork() failed\n", argv[0]);
        exit(EXIT_FAILURE);
    } else if (i != 0) {
        exit(EXIT_SUCCESS);
    }


I added the syslog lines.  I see one 'Forking new milter' message when 
mimedefang starts, but never see any 'fork() failed' messages.  Should i?  
Why the fprintf's to stderr?  Should those show up in any logs?  Is there 
a better way to debug the milter?  I'm not sure of all the ramifications 
of --enable-debugging.

I started logging sendmail at level 10 to monitor the inbound connection 
rate.  The connections/sec never exceeds 10, mostly staying around 3-5.  I 
added -T to milter startup to get filter runtimes.  Most filters are 
finishing within 100-300ms.

System load/mail flow appears normal when the milters stop.  If i could
get any kind of good error message from sendmail or the milter, it might
help.  :)  Again this is sendmail 8.12.9 (patched), md 1.35, SA 2.63, and
clamav, on RH AS 2.1.  Thanks for any ideas.

ray
-- 
=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
Ray DeJean  				       	 http://www.r-a-y.org
Systems Engineer                    Southeastern Louisiana University
IBM Certified Specialist  	      AIX Administration, AIX Support
=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=






More information about the MIMEDefang mailing list