The SMTPD Replay stopped (again). Any idea why?

[bluemike]

This happend a few days ago too. I had posted the errors here, but have yet to get any help. Well, it happend again last night. Here are the error logs:

Code: Select all

SERIOUS ERROR SMTP Relay (SMTPD Relay Pr) 02.08.06 17:18:21
[OM 10270] Process about to terminate due to error.
Signal (Segmentation Violation) trapped by process 28262
Procedure trace follows:
<- inet_ParseArpaAddress
-> nm_ParseORN
<- nm_ParseORN
-> nm_PutFieldStr
-> nm_PutFieldMem
-> nm_AppendFieldMem
-> nm_AddSeparators
<- nm_AddSeparators
-> nm_ParseORN
<- nm_ParseORN
<- nm_AppendFieldMem
<- nm_PutFieldMem
<- nm_PutFieldStr
<- inet_ConvArpaORNToORN
-> smtplib_init
<- smtplib_init
 
 
SERIOUS ERROR SMTP Relay (SMTPD Relay Pr) 02.08.06 17:18:21
[OM 10272] BACKTRACE:
[0x554420]
/lib/libc.so.6(fprintf+0x22) [0xd72b6e]
/opt/scalix/lib/libom_smtplib.so(smtplib_mailFrom+0xe4) [0xee89f4]
omsmtpd [0x804eeba]
omsmtpd [0x80534ca]
omsmtpd [0x8054a9d]
/lib/libc.so.6(__libc_start_main+0xc6) [0xd43de6]
omsmtpd [0x804ae21]
 

I would really like to know what I can do about this. What does thie error even mean? What's a 'segmentation violation'?

Thanks

[florian]

Hm.

I believe we'll need to know what message causes this.

one way to determine this is to log the whole SMTP conversation up to the point of error. the way to do this is to add the following line to /var/opt/scalix/sys/smtpd.cfg:

DEBUG_LOG=true

and restarting the smtpd process using

omoff -d 0 -w smtpd; omon -w smtpd

That will create a smtpd.log file in /var/opt/scalix/tmp. Be careful, the file will grow rapidly because it will contain your incoming email traffic. you might want to truncate it regularly until the error happens again.

the error is some kind of internal error that might actually point to a bug in the smtp relay. Which version of scalix are you using?

Florian.

[bluemike]

I have added the DEBUG_LOG=true line to my smtpd.cfg, and restarted the smtpd service.

If/when this happens again, I will post the offending data here.

I am running Scalix version 9.4.0.52

[florian]

ok, just check if the logfile is there.

when you truncate, note that you cannot delete it as the smtpd server process will keep it open, so the way to truncate is to use the ">" syntax...... you might want to copy away the old stuff and gzip it first eventually. or use logrotate.

--- f.

[bluemike]

A file called smtpd.log has appeared in the /var/opt/scalix/tmp folder. It's about 1.4MB and getting bigger.

I'm afraid I don't know the command(s) to truncate the file. I was planning just opening it up in the text editor, deleting the older data, and saving it again. Will that not work, or is there a faster way?

[florian]

cd /var/opt/scalix/tmp

>smtpd.log

:-) truncates, but keeps the original file! :-)

-- f.

[bluemike]

Until I can get this issue resolved, could I just make a cron job to execute 'omon smtpd' every hour? Or would that create more problems than it solves?

During the day, I can monitor it. But if it's off all night, that could be a lot of emails being kicked back to the senders....

[florian]

you can run a script that does that.

problem is we really want to know what caused the issue.

if you can write a script that

check-if-it-still-running...
if-not-running-then-save-smtpd.log in-some-place and restart.
if running, stop, truncate file, restart

every hour, that would be super-useful.

-- .f

[bluemike]

It's getting worse. The relay stopped a few minutes ago, and now it won't stay 'up'. I can start it, but it just stops again. Here is what was in the smtpd.log at the time:

Code: Select all

SMTP Relay 9.4.0.9 started (24614): Thu, 09 Feb 2006 11:11:51 -0800 (PST)
Accepted client 1 from  (feu30-1-82-242-59-203.fbx.proxad.net)
Cli 24614/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 24614/1 failed: EOF
Accepted client 1 from  (sanhost.bbpi-pdc.billsblue.com)
Cli 24614/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 24614/1 rcvd: 'EHLO sanhost'
Cli 24614/1 sent  : 250-emailserver.bbpi-pdc.billsblue.com Hello sanhost.bbpi-pdc.billsblue.com [192.168.111.13], pleased to meet you
   250-AUTH CRAM-MD5 DIGEST-MD5 GSSAPI PLAIN LOGIN
   250-AUTH=LOGIN
   250-DSN
   250 8BITMIME
   
Cli 24614/1 rcvd: 'RSET'
Cli 24614/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Reset state
   
Cli 24614/1 rcvd: 'MAIL FROM:<services@billsblue.com>'
Cli 24614/1 sent  : 250 services@billsblue.com... Sender ok
   
SMTP Relay 9.4.0.9 started (24659): Thu, 09 Feb 2006 11:13:07 -0800 (PST)
Accepted client 1 from  ()
Cli 24659/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 24659/1 rcvd: 'HELO 144780184'
Cli 24659/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello  [200.172.20.184], pleased to meet you
   
Accepted client 2 from  (sanhost.bbpi-pdc.billsblue.com)
Cli 24659/2 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 24659/2 rcvd: 'EHLO sanhost'
Cli 24659/2 sent  : 250-emailserver.bbpi-pdc.billsblue.com Hello sanhost.bbpi-pdc.billsblue.com [192.168.111.13], pleased to meet you
   250-AUTH CRAM-MD5 DIGEST-MD5 GSSAPI PLAIN LOGIN
   250-AUTH=LOGIN
   250-DSN
   250 8BITMIME
   
Cli 24659/2 rcvd: 'RSET'
Cli 24659/2 sent  : 250 emailserver.bbpi-pdc.billsblue.com Reset state
   
Cli 24659/2 rcvd: 'MAIL FROM:<services@billsblue.com>'
Cli 24659/2 sent  : 250 services@billsblue.com... Sender ok
   
SMTP Relay 9.4.0.9 started (25130): Thu, 09 Feb 2006 11:16:36 -0800 (PST)
Accepted client 1 from  (dialpool-210-214-110-1.maa.sify.net)
Cli 25130/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Accepted client 2 from  (f167202.upc-f.chello.nl)
Cli 25130/2 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25130/2 rcvd: 'HELO dkburnap.com'
Cli 25130/2 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello f167202.upc-f.chello.nl [80.56.167.202], pleased to meet you
   
Cli 25130/2 rcvd: 'MAIL FROM: <flora_terrellmc@cbeng.com>'
Cli 25130/2 sent  : 250 flora_terrellmc@cbeng.com... Sender ok
   
Cli 25130/1 rcvd: 'HELO 142507992'
Cli 25130/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello dialpool-210-214-110-1.maa.sify.net [210.214.110.1], pleased to meet you
   
Cli 25130/2 rcvd: 'RCPT TO: <fitzpatrick@billsblue.com>'
Rejected relay attempt from flora_terrellmc@cbeng.com at 80.56.167.202 to fitzpatrick@billsblue.com
Cli 25130/2 sent  : 550 Denied due to spam list
   
Cli 25130/2 failed: EOF
Cli 25130/1 rcvd: 'MAIL FROM:<autofs@girp.com>'
Cli 25130/1 sent  : 250 autofs@girp.com... Sender ok
   
Cli 25130/1 rcvd: 'RCPT TO:<odell@billsblue.com>'
Rejected relay attempt from autofs@girp.com at 210.214.110.1 to odell@billsblue.com
Cli 25130/1 sent  : 550 Denied due to spam list
   
Accepted client 2 from  (gon95-2-82-243-149-71.fbx.proxad.net)
Cli 25130/1 failed: EOF
Cli 25130/2 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25130/2 rcvd: 'HELO scala.net'
Cli 25130/2 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello gon95-2-82-243-149-71.fbx.proxad.net [82.243.149.71], pleased to meet you
   
Cli 25130/2 rcvd: 'MAIL FROM: <e.ortizgj@cbeng.com>'
Cli 25130/2 sent  : 250 e.ortizgj@cbeng.com... Sender ok
   
Cli 25130/2 rcvd: 'RCPT TO: <fitzpatrick@billsblue.com>'
Rejected relay attempt from e.ortizgj@cbeng.com at 82.243.149.71 to fitzpatrick@billsblue.com
Cli 25130/2 sent  : 550 Denied due to spam list
   
Cli 25130/2 failed: EOF
Accepted client 1 from  ()
Cli 25130/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25130/1 rcvd: 'HELO alltel.net'
Cli 25130/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello  [222.99.9.88], pleased to meet you
   
Cli 25130/1 rcvd: 'MAIL FROM: <gamblelv@ardmore.net>'
Cli 25130/1 sent  : 250 gamblelv@ardmore.net... Sender ok
   
Cli 25130/1 rcvd: 'RCPT TO: <fitzpatrick@billsblue.com>'
Rejected relay attempt from gamblelv@ardmore.net at 222.99.9.88 to fitzpatrick@billsblue.com
Cli 25130/1 sent  : 550 Denied due to spam list
   
Cli 25130/1 failed: EOF
Accepted client 1 from  (195.102.119-80.rev.gaoland.net)
Cli 25130/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25130/1 rcvd: 'HELO comcast.net'
Cli 25130/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello 195.102.119-80.rev.gaoland.net [80.119.102.195], pleased to meet you
   
Accepted client 2 from  (c-68-42-76-207.hsd1.mi.comcast.net)
Cli 25130/2 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25130/2 rcvd: 'HELO 143249720'
Cli 25130/2 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello c-68-42-76-207.hsd1.mi.comcast.net [68.42.76.207], pleased to meet you
   
Cli 25130/2 rcvd: 'MAIL FROM:<koordination@glennstephens.com.au>'
Cli 25130/2 sent  : 250 koordination@glennstephens.com.au... Sender ok
   
Cli 25130/1 rcvd: 'MAIL FROM: <lhurst_mf@midcoast.com>'
Cli 25130/1 sent  : 250 lhurst_mf@midcoast.com... Sender ok
   
Cli 25130/2 rcvd: 'RCPT TO:<rosado@billsblue.com>'
Rejected relay attempt from koordination@glennstephens.com.au at 68.42.76.207 to rosado@billsblue.com
Cli 25130/2 sent  : 550 Denied due to spam list
   
Cli 25130/2 failed: EOF
Cli 25130/1 rcvd: 'RCPT TO: <fitzpatrick@billsblue.com>'
Rejected relay attempt from lhurst_mf@midcoast.com at 80.119.102.195 to fitzpatrick@billsblue.com
Cli 25130/1 sent  : 550 Denied due to spam list
   
Cli 25130/1 failed: EOF
Accepted client 1 from  ()
Cli 25130/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25130/1 rcvd: 'HELO sbcglobal.net'
Cli 25130/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Hello  [220.161.2.225], pleased to meet you
   
Cli 25130/1 rcvd: 'MAIL FROM: <gerry_donaldson_eh@execpc.com>'
Cli 25130/1 sent  : 250 gerry_donaldson_eh@execpc.com... Sender ok
   
Cli 25130/1 rcvd: 'RCPT TO: <fitzpatrick@billsblue.com>'
Rejected relay attempt from gerry_donaldson_eh@execpc.com at 220.161.2.225 to fitzpatrick@billsblue.com
Cli 25130/1 sent  : 550 Denied due to spam list
   
Cli 25130/1 failed: EOF
Accepted client 1 from  (sanhost.bbpi-pdc.billsblue.com)
Cli 25130/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25130/1 rcvd: 'EHLO sanhost'
Cli 25130/1 sent  : 250-emailserver.bbpi-pdc.billsblue.com Hello sanhost.bbpi-pdc.billsblue.com [192.168.111.13], pleased to meet you
   250-AUTH CRAM-MD5 DIGEST-MD5 GSSAPI PLAIN LOGIN
   250-AUTH=LOGIN
   250-DSN
   250 8BITMIME
   
Cli 25130/1 rcvd: 'RSET'
Cli 25130/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Reset state
   
Cli 25130/1 rcvd: 'MAIL FROM:<services@billsblue.com>'
Cli 25130/1 sent  : 250 services@billsblue.com... Sender ok
   
SMTP Relay 9.4.0.9 started (25388): Thu, 09 Feb 2006 11:18:15 -0800 (PST)
Accepted client 1 from  (sanhost.bbpi-pdc.billsblue.com)
Cli 25388/1 sent  : 220 emailserver.bbpi-pdc.billsblue.com Pay no attention to the man behind the curtain.
   
Cli 25388/1 rcvd: 'EHLO sanhost'
Cli 25388/1 sent  : 250-emailserver.bbpi-pdc.billsblue.com Hello sanhost.bbpi-pdc.billsblue.com [192.168.111.13], pleased to meet you
   250-AUTH CRAM-MD5 DIGEST-MD5 GSSAPI PLAIN LOGIN
   250-AUTH=LOGIN
   250-DSN
   250 8BITMIME
   
Cli 25388/1 rcvd: 'RSET'
Cli 25388/1 sent  : 250 emailserver.bbpi-pdc.billsblue.com Reset state
   
Cli 25388/1 rcvd: 'MAIL FROM:<services@billsblue.com>'
Cli 25388/1 sent  : 250 services@billsblue.com... Sender ok

[ScalixSupport]

The crash seems to be happening every time services@billsblue.com is submitting a message. Is this an automated process that's trying to submit messages ?

Is there a reason why it needs to issue the RSET command before sending the MAIL FROM command ?

I've tried this on my 9.4 server and the problem does not occur.

Can you post the uncommented sections from /var/opt/scalix/sys/smtpd.cfg ?

Cheers

Dave

[bluemike]

Services@billsblue.com is our primamry email account. It mostly receives messages, and rarely sends them. But sometimes a user will send a message using that account.

I do have a syslog running on another server that will automatically send an email to me is ceratin events occur. The syslog software requires a valid 'from' address, and I have been using services@billsblue.com.

We have several users who use IMAP to monitor the 'services' inbox.

I don't know what the RSET means.

Here is all the uncommented stff from smtpd.cfg:

Code: Select all

DEBUG_LOG=TRUE
EXTENSIONS=AUTH,DSN,8BITMIME
GREETING=Pay no attention to the man behind the curtain.
SMTPFILTER=TRUE
RELAY accept 127.0.0.1
RELAY accept 192.168.111.0/255.255.255.0
RELAY accept .bbpi-pdc.billsblue.com
RELAY Log_Reject ALL
RECIPIENT Log_Reject *@*@*
RECIPIENT Log_Reject *%*
RECIPIENT Log_Reject *!*
RECIPIENT Log_Reject *#*@*

[bluemike]

I *think* I have resolved this. In the syslog software I mentioned, I changed the from address to read 'services@bbpi-pdc.billsblue.com' (I added our internal domain to the address). Within a few minutes, I started receiving emails again, and SMTP relay has been up for 10 minutes now.

I'm not sure why this worked fine for the past few months, and just now decided to completely fail. But at least it (appears) to ahve been solved.

Thanks for your help Dave and Florian