Scalix server receiving email performance

Discuss the Scalix Server software

Moderators: ScalixSupport, admin

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Scalix server receiving email performance

Postby vorlon2261 » Mon Mar 20, 2006 8:39 pm

Hi guys,

Upgraded to 10.0.0 recently, and since its happened, Scalix takes its sweet time
to receive emails, some taking as much as 3 hours to arrive when they used to
take moments.

We have a postfix server on a firewall which forwards emails in to the Scalix server
behind our firewall, and its complaining of network timeouts, when nothing else is.
Sending emails out via the Scalix server is unaffected, internal emails are unaffected,
other services involving both the server Scalix lives on and the firewall are unaffected.

Has anyone seen something similar? What can I do to debug this situation further?

thanks,

Greg

ScalixSupport
Scalix
Scalix
Posts: 5503
Joined: Thu Mar 25, 2004 8:15 pm

Postby ScalixSupport » Mon Mar 20, 2006 9:29 pm

Do you have any internet headers for a delayed message ?

Cheers

Dave

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Mon Mar 20, 2006 11:23 pm

This one is only delayed by an hour... Others have delayed longer... Email
addresses changed to protect the innocent... ;-) If I see anything different in
other emails I'll email them to you via the support email address...

Question: Is 10.0.0.175 mentioned in the Scalix SMTP relay meant to be
an IP address or is that the Scalix version?

Code: Select all

Received: from mail.unico.com.au (jumpgate.unico.com.au 10.10.1.2)
    by akiko.unico.com.au (Scalix SMTP Relay 10.0.0.175)
    via ESMTP; Tue, 21 Mar 2006 13:46:48 +1100 (EST)
Received: from mailbo.vtcif.telstra.com.au (mailbo.vtcif.telstra.com.au [202.12.144.19])
   by mail.unico.com.au (Postfix) with ESMTP id 30FD824302
   for <Spam.Someone@to.domain.com>; Tue, 21 Mar 2006 12:49:55 +1100 (EST)
Received: from mailai.vtcif.telstra.com.au (mailai.vtcif.telstra.com.au [202.12.142.17])
   by mailbo.vtcif.telstra.com.au (Postfix) with ESMTP
   id 0912A22D01; Tue, 21 Mar 2006 12:49:44 +1100 (EST)
Received: from mail2.cdn.telstra.com.au (localhost [127.0.0.1])
   by mailai.vtcif.telstra.com.au (Postfix) with ESMTP
   id 195831DA84; Tue, 21 Mar 2006 12:49:44 +1100 (EST)
Received: from wsmsg2952.srv.dir.telstra.com (wsmsg2952.srv.dir.telstra.com [192.74.195.51])
   by mail2.cdn.telstra.com.au (Postfix) with ESMTP
   id B1B8F41F4E; Tue, 21 Mar 2006 12:49:43 +1100 (EST)
Content-class: urn:content-classes:message
Subject: RE: [Case ID: 11037616] Re: Act#1-13846316-Esc#1-11356767    Case:10728552 Task:21499295 Updated at 26-Jan 15:5 [...]
Date: Tue, 21 Mar 2006 12:49:36 +1100
MIME-Version: 1.0
Content-Type: text/plain;
   charset="iso-8859-1"
Content-Transfer-Encoding: quoted-printable
Message-ID: <B15779BF86D9A7439FF960A84650624101755640@WSMSG2151V.srv.dir.telstra.com>
X-MimeOLE: Produced By Microsoft Exchange V6.5
X-MS-Has-Attach:
X-MS-TNEF-Correlator:
Thread-Topic: [Case ID: 11037616] Re: Act#1-13846316-Esc#1-11356767    Case:10728552 Task:21499295 Updated at 26-Jan 15:5 [...]
Thread-Index: AcY7TfAqg7HyXUt0R8GwqpbBR3PjsgRO1s2w
From: "From Person" <From.Person@from.domain.com>
To: <spam@sun.com>
Cc: "To Person" <To.Person@to.domain.com>

ScalixSupport
Scalix
Scalix
Posts: 5503
Joined: Thu Mar 25, 2004 8:15 pm

Postby ScalixSupport » Tue Mar 21, 2006 1:05 am

Code: Select all

Received: from mail.unico.com.au (jumpgate.unico.com.au 10.10.1.2)
    by akiko.unico.com.au (Scalix SMTP Relay 10.0.0.175)
    via ESMTP; Tue, 21 Mar 2006 13:46:48 +1100 (EST)
Received: from mailbo.vtcif.telstra.com.au (mailbo.vtcif.telstra.com.au [202.12.144.19])
   by mail.unico.com.au (Postfix) with ESMTP id 30FD824302
   for <Spam.Someone@to.domain.com>; Tue, 21 Mar 2006 12:49:55 +1100 (EST)


This is the important section.

It looks like mail.unico.com.au is holding on to the message for 1 hour. Is there anything in the postfix logs that show a mail deferral when talking to akiko.unico.com.au ?

Cheers

Dave

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Tue Mar 21, 2006 6:25 pm

Only thing I've found is this when running mailq:

Code: Select all

7E31E24294     6177 Tue Mar 21 10:06:31  1isto@mail.com
(conversation with 10.10.1.5[10.10.1.5] timed out while sending end of data -- message may be sent more than once)
                                         username@unico.com.au


Its an ethernet connection between the 2 and I have replaced all of the hardware in between, so I'm confident its not a hardware issue. Especially since other services that also go through this hardware aren't affected... (IP address 10.10.1.5 is the Scalix server in the above example)

ScalixSupport
Scalix
Scalix
Posts: 5503
Joined: Thu Mar 25, 2004 8:15 pm

Postby ScalixSupport » Tue Mar 21, 2006 6:27 pm

Can you check your fatal file under /var/opt/scalix/logs to see if anything is logged there ?

Cheers

Dave

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Tue Mar 21, 2006 7:32 pm

Dave,

Have mailed fatal file to you. Theres a couple of stack traces in there, but there isn't much to go on...

Greg

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Mon Mar 27, 2006 6:53 pm

Dave,

Have been unable to figure out what Scalix is doing wrong here.

Can you suggest a strategy for falling back to 9.4.2, as it is causing unacceptable delays in email arrival.

thanks!

ScalixSupport
Scalix
Scalix
Posts: 5503
Joined: Thu Mar 25, 2004 8:15 pm

Postby ScalixSupport » Mon Mar 27, 2006 7:04 pm

I haven't been able to look at the fatal file until today as I've been out of the office.

Be advised that there is no fallback to 9.4 after upgrading to 10.

In the fatal log I can see only one reference to a problem.

Code: Select all

SERIOUS ERROR                  Internet Mail (Incoming      ) 03.01.06 14:13:11
[OM.UX 1401] Cannot read message data.
Pid of logging process: 6773


This usually means that the sending side terminated the conversation early.

The first thing to try is to enable SMTP Logging by adding

Code: Select all

DEBUG_LOG=TRUE
to smtpd.cfg and restarting the SMTP Relay.

This will log to /var/opt/scalix/tmp/smtpd.log and will contain the complete SMTP conversation between the SMTP Relay and any sending MTA/client. Beware that this can get large if there's a lot of traffic.

This will help identify if there is a problem on the sending side.

Cheers

Dave

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Mon Mar 27, 2006 11:03 pm

Dave,

Thanks for the follow up. I've enabled debug as requested... Its giving the following:

Code: Select all

Cli 3320/3 rcvd U: 'Cannot read message data.'
Cli 3320/3: Submitted message ': <150401c64ee0$56bfa2c9$1d084743@o2.pl>' to unix.in.
        response: 'Cannot read message data.'
Cli 3320/3 Finished submitting msg  : <150401c64ee0$56bfa2c9$1d084743@o2.pl>
Cli 3320/3 sent  : Cannot read message data.


This is after getting the full message including the final '.'.

If you want, I can send through a sample or two through to the support list...

ScalixSupport
Scalix
Scalix
Posts: 5503
Joined: Thu Mar 25, 2004 8:15 pm

Postby ScalixSupport » Mon Mar 27, 2006 11:17 pm

Can you post more of the SMTP conversation ?

Cheers

Dave

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Mon Mar 27, 2006 11:24 pm

Here 'tis:

Looks like this one figures the end of the email before the actual email ends... See below...

Code: Select all

Accepted client 3 from  (jumpgate.unico.com.au)
Cli 3320/3 sent  : 220 akiko.unico.com.au ESMTP Scalix SMTP Relay 10.0.0.175; Tue, 28 Mar 2006 13:57:35 +1100 (EST)
       
Cli 3320/3 rcvd: 'EHLO mail.unico.com.au'
Cli 3320/3 sent  : 250-akiko.unico.com.au Hello jumpgate.unico.com.au [10.10.1.2], pleased to meet you
        250-AUTH CRAM-MD5 DIGEST-MD5 LOGIN PLAIN GSSAPI
        250-AUTH=LOGIN
        250-DSN
        250 8BITMIME
       
Cli 3320/3 rcvd: 'MAIL FROM:<agent@o2.pl>'
Cli 3320/3 sent  : 250 agent@o2.pl... Sender ok
       
Cli 3320/3 rcvd: 'RCPT TO:<kalo@unico.com.au>'

Cli 3320/3 rcvd U: '220 Scalix ESMTP Ready.'
Cli 3320/3 rcvd U: '250 Ok'
Cli 3320/3 sent U: rcpt to: <kalo@unico.com.au>
       
Cli 3320/3 rcvd U: '250 Ok'
Cli 3320/3 sent  : 250 Ok
       
Cli 3320/3 rcvd: 'DATA'
Cli 3320/3 sent  : 354 Enter mail, end with "." on a line by itself (relay)
       
Cli 3320/3 sent U: data
       
Cli 3320/3 rcvd U: '354 Enter mail, end with "." on a line by itself.'

Cli 3320/3 sent U: Received: from mail.unico.com.au (jumpgate.unico.com.au 10.10.1.2)
            by akiko.unico.com.au (Scalix SMTP Relay 10.0.0.175)
            via ESMTP; Tue, 28 Mar 2006 13:57:36 +1100 (EST)
        Received: from 59.24.0.170 (unknown [59.24.0.170])
                by mail.unico.com.au (Postfix) with SMTP id DCF6224393
                for <XXXX@unico.com.au>; Sat, 25 Mar 2006 04:12:47 +1100 (EST)
        Message-ID: <150401c64ee0$56bfa2c9$1d084743@o2.pl>
        From: abc@uol.com.br <agent@o2.pl>
        To: XXXX@unico.com.au
        Subject: =?windows-1251?B?0eDs7vHy7v/y5ev87e7lIO/w7uLl5OXt6OUg7ODw6uXy6O3j7uL79SDo8fHr5eTu?=
                =?windows-1251?B?4uDt6Ok=?=
        Date: Fri, 24 Mar 2006 04:13:07 +0300
        MIME-Version: 1.0
        Content-Type: multipart/alternative;
            boundary="----=_NextPart_000_0000_DCFC24E2.B70B1675"
        X-Priority: 3
        X-MSMail-Priority: Normal
        X-Mailer: Microsoft Outlook Express V6.00.2900.2180
        X-MimeOLE: Produced By Microsoft MimeOLE V6.00.2900.2180
       
        This is a multi-part message in MIME format.
       
        ------=_NextPart_000_0000_DCFC24E2.B70B1675
        Content-Type: text/plain;
            charset="windows-1251"
        Content-Transfer-Encoding: 8bit

    SPAM SPAM SPAM SPAM


Cli 3320/3 sent U:  =C3=E8=EB=FC=E4=E8=E8 =EC=E0=F0=EA=E5=F2=EE=EB=EE=E3=EE=E2 =
        =D0=EE=F1=F1=E8=E8, =E8=EC=E5=E5=F2 =F1=F2=E5=EF=E5=ED=FC =CC=C2=C0. =
        =CE=EF=FB=F2=ED=FB=E9 =F1=EF=E5=F6=E8=E0=EB=E8=F1=F2 =E2 =
        =EE=F0=E3=E0=ED=E8=E7=E0=F6=E8=E8 =
        =EC=E0=F0=EA=E5=F2=E8=ED=E3=EE=E2=EE=E9 =
        =E4=E5=FF=F2=E5=EB=FC=ED=EE=F1=F2=E8, =F2=E5=F5=ED=EE=EB=EE=E3=E8=FF=F5 =
        =F1=EE=E7=E4=E0=ED=E8=FF =EC=E0=F0=EA=E5=F2=E8=ED=E3=EE=E2=FB=F5 =
        =EF=EE=E4=F0=E0=E7=E4=E5=EB=E5=ED=E8=E9 &laquo;=F1 =ED=F3=EB=FF&raquo;, =
        =EF=F0=EE=E2=E5=E4=E5=ED=E8=E8 =EC=E0=F0=EA=E5=F2=E8=ED=E3=EE=E2=FB=F5 =
        =E8=F1=F1=EB=E5=E4=EE=E2=E0=ED=E8=E9 =EB=FE=E1=EE=E9 =
        =F1=EB=EE=E6=ED=EE=F1=F2=E8, =EF=EB=E0=ED=E8=F0=EE=E2=E0=ED=E8=E8 =
        =F0=E5=EA=EB=E0=EC=ED=EE=E9 =E4=E5=FF=F2=E5=EB=FC=ED=EE=F1=F2=E8. =
        =D0=E5=E0=EB=E8=E7=EE=E2=E0=EB =E1=EE=EB=E5=E5 50 =
        =EF=F0=EE=E5=EA=F2=EE=E2 =E2 =EE=E1=EB=E0=F1=F2=E8 =
        =EC=E0=F0=EA=E5=F2=E8=ED=E3=E0, =E1=F0=E5=ED=E4=E8=ED=E3=E0 =E8 =
        =F0=E5=EA=EB=E0=EC=FB, =EE=F0=E3=E0=ED=E8=E7=E0=F6=E8=E8 =
       
Cli 3320/3 got .
Cli 3320/3 sent U: =EC=E0=F0=EA=E5=F2=E8=ED=E3=EE=E2=EE=E9 =F1=EB=F3=E6=E1=FB =E8 =
        =F0=E0=E7=F0=E0=E1=EE=F2=EA=E5 =EA=EE=ED=F6=E5=EF=F6=E8=E8 =
        =EC=E0=F0=EA=E5=F2=E8=ED=E3=E0. =C1=EE=EB=E5=E5 500 =
        =E2=FB=EF=F3=F1=EA=ED=E8=EA=EE=E2 =F8=EA=EE=EB=FB =
        =F0=E0=E1=EE=F2=E0=FE=F2 =ED=E0 =F0=F3=EA=EE=E2=EE=E4=FF=F9=E8=F5 =
        =E4=EE=EB=E6=ED=EE=F1=F2=FF=F5 =EA=E0=EA =E2 =
        =F0=EE=F1=F1=E8=E9=F1=EA=E8=F5, =F2=E0=EA =E8 =E2 =
        =E7=E0=F0=F3=E1=E5=E6=ED=FB=F5 =EA=EE=EC=EF=E0=ED=E8=FF=F5. =
        </font></div>
        <div align=3D"center"><strong><font =
        face=3D"Arial">&nbsp;</font></strong></div>
        <div align=3D"center"><font face=3D"Arial"><font =
        size=3D"4"><strong>=C7=E2=EE=ED=E8=F2=E5: </strong><strong>8 926 =
        2=C72-25-9=D7</strong></font></font></div>
        </font>
        </BODY>
        </HTML>
       
       
        ------=_NextPart_000_0000_DCFC24E2.B70B1675--
       
        {NULL}
        .

Cli 3320/3 rcvd U: 'Cannot read message data.'
Cli 3320/3: Submitted message ': <150401c64ee0$56bfa2c9$1d084743@o2.pl>' to unix.in.
        response: 'Cannot read message data.'
Cli 3320/3 Finished submitting msg  : <150401c64ee0$56bfa2c9$1d084743@o2.pl>
Cli 3320/3 sent  : Cannot read message data.

ScalixSupport
Scalix
Scalix
Posts: 5503
Joined: Thu Mar 25, 2004 8:15 pm

Postby ScalixSupport » Mon Mar 27, 2006 11:59 pm

Do you know why there is a {NULL} being sent ?

Cheers

Dave

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Tue Mar 28, 2006 2:23 am

Can't say that I do... I assume from your question that you doubt they would be part of the email? I've reviewed a couple of hours worth of smtpd.log file entries and its not that common. Only about 8 occurances. Currently a backlog of several hundred messages spanning ~ 5 hours...

The other item that I've noticed is occurances along the lines of:

Code: Select all

Cli 3320/5 rcvd: 'MAIL From:<>'
Cli 3320/5 sent  : 250 ... Sender ok

Cli 3320/5 rcvd: 'RCPT To:<root@mailhost.domain.com>'
Cli 3320/5 sent  : 501 5.5.2 Syntax error in parameters scanning "FROM"

Cli 3320/5 rcvd: 'RSET'
Cli 3320/5 sent  : 250 akiko.unico.com.au Reset state


However these don't revolve around the same errors that have been seen elsewhere in logs...

The only other occurance in the logs is several hundred lines as follows:

Code: Select all

Cli 3320/6 failed: EOF


They usually seem to be preceeded with an RSET after a number of failed attempts to set a MAIL FROM and RCPT TO (usually the MAIL FROM is claimed to be blank by Scalix, though I haven't got any evidence of actual blank from addresses in the emails themselves. Certainly none in the queue at present...

vorlon2261
Posts: 70
Joined: Tue Oct 04, 2005 2:38 am
Location: Australia

Postby vorlon2261 » Wed Mar 29, 2006 5:25 pm

Dave,

Just a thought... Would the Scalix server be attempting any external communications whilst receiving an email? Eg. some mail servers attempt to establish the liegitimacy of the server making the incoming connection, etc...

Am asking because if it is, then its likely that this particular functionality is probably failing...

Greg


Return to “Scalix Server”



Who is online

Users browsing this forum: No registered users and 2 guests