Re: [9fans] broken smtpd

[erik quanstrom <quanstro@quanstro.net>]

[-- Attachment #1: Type: text/plain, Size: 1047 bytes --]

acid tells us that we're indirecting a nil senders.last->p.
we know it's senders.last->p because it's at offset 4.
(that was the fault address.)  the Lock at the beginning
of String is bigger than 4 bytes by itself, so it's not the
String and rsys is not the 2d pointer in NetConnInfo,
so that eliminates rsys.

acid: src(0x7463)
/sys/src/cmd/upas/smtp/smtpd.c:628
 623		logged = 0;
 624
 625		/* forwarding() can modify 'path' on loopback request */
 626		if(filterstate == ACCEPT && fflag && !authenticated && forwarding(path)) {
 627			syslog(0, "smtpd", "Bad Forward %s (%s/%s) (%s)",
>628				s_to_c(senders.last->p), him, nci->rsys, s_to_c(path));
 629			rejectcount++;
 630			reply("550 5.7.1 we don't relay.  send to your-path@[] for "
 631				"loopback.\r\n");
 632			return;
 633		}

replace lines 627,628 with

		syslog(0, "smtpd", "Bad Forward %s (%s/%s) (%s)",
			sender, him, nci->rsys, rcpt);

i made this change some time ago and it appears to be working fine.
i may have seen a similar fault.

- erik

[-- Attachment #2: Type: message/rfc822, Size: 3885 bytes --]

From: Kenji Arisawa <arisawa@ar.aichi-u.ac.jp>
To: Fans of the OS Plan 9 from Bell Labs <9fans@9fans.net>
Subject: Re: [9fans] broken smtpd
Date: Wed, 19 Nov 2008 09:25:55 +0900
Message-ID: <5280BC21-18A9-4287-A1AE-23EEAFAE42CF@ar.aichi-u.ac.jp>

Hello,

I added some debugging codes to catchalarm() in smtpd.c

static int
catchalarm(void *a, char *msg)
{
	int rv = 1;
	static int count = 0; // DEBUG by Kenar
	count++;
	if(count > 3)
		return 0;

	USED(a);

	/* log alarms but continue */
	if(strstr(msg, "alarm")){
		if(senders.first && rcvers.first)
			syslog(0, "smtpd", "note: %s->%s: %s",
				s_to_c(senders.first->p),
				s_to_c(rcvers.first->p), msg);
		else
			syslog(0, "smtpd", "note: %s", msg);
		rv = 0;
	}

	syslog(0, "smtpd", "note: %s", msg); // DEBUG by Kenar

	/* kill the children if there are any */
	if(pp)
		syskillpg(pp->pid);

	return rv;
}

after that I found broken smtpd:
none          50392    0:00   0:00      264K Broken   smtpd

note that wasted cpu time is now 0:00

/sys/log/smtpd shows:
ar Nov 19 02:23:05 ehlo from 124.8.67.36 as sotcndhz.com
ar Nov 19 02:23:08 note: sys: trap: fault read addr=0x4 pc=0x00007463
ar Nov 19 02:23:08 note: sys: trap: fault read addr=0x4 pc=0x00007463
ar Nov 19 02:23:08 note: sys: trap: fault read addr=0x4 pc=0x00007463

Kenji Arisawa

On 2008/11/17, at 21:51, erik quanstrom wrote:

> d'oh!  the return value from catchalarm looks reversed.  from
> notify(2)
>
>          [...] A handler must
>          return a non-zero number if the note was recognized (and
>          resolved); otherwise it must return zero.  When the system
>
> i think you're getting into some sort of note loop.  i think it would
> be helpful to log all notes.  i would try something like this
>
> static int
> catchalarm(void *, char *msg)
> {
> 	static int chattycathy;
>
> 	if(chattycathy++ > 5)
> 		return 0;
> 	if(senders.first && rcvers.first)
> 		syslog(0, "smtpd", "note: %s->%s: %s",
> 			s_to_c(senders.first->p),
> 			s_to_c(rcvers.first->p), msg);
> 	else
> 		syslog(0, "smtpd", "note: %s", msg);
> 	if(pp){
> 		syskillpg(pp->pid);
> 		pp = 0;
> 	}
> 	return strstr(msg, "alarm") != 0;
> }
>
> but at a minimum, i would reverse the return values.
>
> - erik
>