SWA slow to send messages *FIXED*

[cswihart]

I have a general question regarding SWA performance.

In my evaluation of Scalix. I've noticed that SWA seems to take considerably longer when sending messages than either imap, outlook, or pop3 clients. By this I mean a difference of 5-15s for non-SWA clients and 50s-60s+ for SWA. I'm running a base install of Scalix 10.1 on a test server (Pentium 4cpu w/1gb Ram serving 6 users). I'm also running ClamAV and Spamassassin, but have turned them off for testing purposes. All other SWA performance seems fine (ie.. logging in, browsing, creating folders and calendar items. )

Is this normal for web access vs. other clients? Could this be hardware (or lack of) problem? Are there areas of my configuration that I can test or change in order to improve performance? (I've already been through the memory optimization steps noted in the installation guide).

Any insights from the community would be greatly appreciated.

Thanks.

Chris

[florian]

Hi Chris,

while SWA might actually be slower sending out messages than a full application client (tribute to it's thin nature), the times that you're giving here seem way out of scope and actually even your 5-6s times for the other clients sound long.

Either your server machine has a severe performance problem or there is something wrong with your setup.

Things to check:
1) Server load (maybe using "top" or so?)
2) Server network situation (maybe "ping" timing from your SWA workstation)
3) Errors: dmesg? omshowlog? /var/opt/scalix/logs/fatal
4) For sending messages - what is the listener configuration (lsof -i :25)
5) problems in SMTP handling - telnet localhost 25 (can you "simulate" a SMTP conversation)
6) SMTP debug logging (DEBUG_LOG=TRUE in /var/opt/scalix/sys/smtpd.cfg)
7) DNS issues - try looking up your own IP address, forward and reverse, i.e. "hostname --fqdn", "nslookup <that hostname>", "nslookup <my ip address>"

Any behaviour that doesn't look right anywhere?

Florian.

[cswihart]

Hi Florian, Thanks for the advice.

Here are my finding based on your suggestions.

1) Server Load is low, (I'm not using top or so)

2) Network Situation seems fine (The problem is experienced from all workstations using SWA, ping is responding at all locations w/o dropping any packets)

3) Dmesg, omshowlog, /var/opt/scalix/logs/fatal do not indicate any serious errors.

4)lsof -i :25

Code: Select all

sendmail  6419 root    4u  IPv4   12101       TCP localhost:smtp (LISTEN)
omsmtpd  21647 root    5u  IPv4 1253525       TCP scalix.mydomain:smtp (LISTEN)


5) I can simulate a test connection to both sendmail (telnet localhost :25 & scalix smtp :25)
Both instances work, but are slow when processing the rcpt to:<email address> command.

6) Debug log is clear after sending several internal and external messages from SWA and Outlook Clients.

7) Forward & Reverse DNS lookups resolved without error.

Based on the tests it seems there may be a problem with the SMTP handling.

Any suggestions?

Thanks for all the help!

-Chris

[florian]

what happens if you try

ommapsmtp rcpt@email.dom

(using the same recipient address that you used in your telnet session for the RCPT TO).

I've seen this kind of slowness before and it had to do something with hostname/ip/dns configuration.

It's fast on my system.

Code: Select all

fvk-mbp:~ fvk$ telnet one.of.our.production.servers smtp
Trying 1.2.3.4
Connected to stingray.us.scalix.com.
Escape character is '^]'.
220 this.server ESMTP Scalix SMTP Relay 11.0.0.397-beta; Mon, 20 Nov 2006 08:32:49 -0800 (PST)
EHLO localhost
250-this.server Hello this.client [1.2.3.5], pleased to meet you
250-AUTH CRAM-MD5 DIGEST-MD5 LOGIN PLAIN GSSAPI
250-AUTH=LOGIN
250-DSN
250 8BITMIME
MAIL FROM: user@domain.com
250 user@domain.com... Sender ok
RCPT TO: recipient@outsideworld.com
250 Ok
DATA
S354 Enter mail, end with "." on a line by itself (relay)
Subject: Test 1

no way.
.
250 Ok
quit
221 this.server closing connection
Connection closed by foreign host.


no delays whatsoever in the SMTP conversation.

Florian.

[cswihart]

Florian,

I executed the ommapsmtp command. It hung for several seconds and then returned the address I typed in initially.

Chris

[jch]

Although you say you've checked forward and reverse DNS lookups, this does sound very much like a DNS problem. The timeouts are typical of partially failing DNS queries.

If you take the domain name from that slow ommapsmtp command and do "host <hostname>" with it, how long does that take? It should be pretty well instant. How long does "host google.com" take?

Assuming that they're not more-or-less instant, check the contents of /etc/resolv.conf. Can you ping all the name servers listed there? Are they all local?

What you do next depends on the answers to all those questions!

jch

[cswihart]

Sorry, its taken so long to reply. Thinking this was possibly a hardware issue I've since rebuilt our installation onto our new HP DL380 dual Xeon Server. We've purchased this server to replace our existing mail server and to hopefully replace it with Scalix. However I'm still experiencing the same slowness issues and need help to troubleshoot it. Forward and reverse DNS queries are working fine. Host Domain.name returns instantly. Host Google.com returns instantly. I can ping all name servers in /etc/resolve.conf. The servers are local. What next? Could this be a sendmail problem?

-Chris

[jch]

Tricky one this.

Are you using NIS? Do you get NIS performance problems? Any other performance problems apart from the slow submit time?

You tried looking up google.com in the DNS, but how about one of the "slow" domains?

Can you run "strace -t -p <pid>" where "<pid>" is the process ID of the smtp relay and then run the slow ommapsmtp command -- we can then see which system call(s) the relay is sitting in for a long time.

jch

[cswihart]

Jch,

Thanks for the help!

To answer your questions.

i'm not using NIS.

Sorry I wasn't clear in my post. The slow domain replied quickly as well.

The slowness occurs just when sending mail when I telnet to the server and manually send a message, when I send via SWA, Outlook, or IMAP.
Here is a sample output from /var/log/mail so you can get a feel for the timing of a simple text message.

Code: Select all

Dec 11 13:09:48 scalix sendmail[11754]: kBBI9mYK011754: from=<cswihart@mydomain.org>, size=2042, class=0, nrcpts=1, msgid=<H000006c00000785.1165860588.scalix.mydomain.org@MHS>, proto=ESMTP, relay=root@localhost
Dec 11 13:10:09 scalix sendmail[11770]: kBBI9mgo011770: from=<cswihart@mydomain.org>, size=2254, class=0, nrcpts=1, msgid=<H000006c00000785.1165860588.scalix.mydoain.org@MHS>, proto=ESMTP, daemon=Daemon0, relay=localhost [127.0.0.1]
Dec 11 13:10:09 scalix sendmail[11754]: kBBI9mYK011754: to=<cswihart73@external.net>, delay=00:00:21, xdelay=00:00:21, mailer=relay, pri=32042, relay=[127.0.0.1] [127.0.0.1], dsn=2.0.0, stat=Sent (kBBI9mgo011770 Message accepted for delivery)
Dec 11 13:10:30 scalix sendmail[11774]: kBBI9mgo011770: to=<cswihart73@external.net>, delay=00:00:21, xdelay=00:00:01, mailer=esmtp, pri=122254, relay=gateway-s.external.net. [xx.xxx.xx.xx], dsn=2.0.0, stat=Sent (ok ; id=20061211181005s11003mjq6e)

I ran strce -t -p and here is the output.

Code: Select all

12:52:58 select(6, [5], [], NULL, NULL) = 1 (in [5])
12:53:02 accept(5, {sa_family=AF_FILE, path=@@H}, [2]) = 4
12:53:02 fcntl64(4, F_GETFD)            = 0
12:53:02 fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
12:53:02 open("/etc/hosts", O_RDONLY)   = 16
12:53:02 fcntl64(16, F_GETFD)           = 0
12:53:02 fcntl64(16, F_SETFD, FD_CLOEXEC) = 0
12:53:02 fstat64(16, {st_mode=S_IFREG|0644, st_size=732, ...}) = 0
12:53:02 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40852000
12:53:02 read(16, "#\n# hosts         This file desc"..., 4096) = 732
12:53:02 read(16, "", 4096)             = 0
12:53:02 read(16, "", 4096)             = 0
12:53:02 close(16)                      = 0
12:53:02 munmap(0x40852000, 4096)       = 0
12:53:02 time([1165859582])             = 1165859582
12:53:02 stat64("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=51, ...}) = 0
12:53:02 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 16
12:53:02 connect(16, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("192.168.249.18")}, 28) = 0
12:53:02 fcntl64(16, F_GETFL)           = 0x2 (flags O_RDWR)
12:53:02 fcntl64(16, F_SETFL, O_RDWR|O_NONBLOCK) = 0
12:53:02 gettimeofday({1165859582, 304949}, NULL) = 0
12:53:02 poll([{fd=16, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
12:53:02 send(16, "_\264\1\0\0\1\0\0\0\0\0\0\0010\0010\0010\0010\7in-addr"..., 38, 0) = 38
12:53:02 poll([{fd=16, events=POLLIN}], 1, 5000) = 0
12:53:07 gettimeofday({1165859587, 305931}, NULL) = 0
12:53:07 poll([{fd=16, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
12:53:07 send(16, "_\264\1\0\0\1\0\0\0\0\0\0\0010\0010\0010\0010\7in-addr"..., 38, 0) = 38
12:53:07 poll([{fd=16, events=POLLIN}], 1, 5000) = 0
12:53:12 close(16)                      = 0
12:53:12 time(NULL)                     = 1165859592
12:53:12 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
12:53:12 time([1165859592])             = 1165859592
12:53:12 select(6, [5], [4], NULL, NULL) = 1 (out [4])
12:53:12 write(4, "220 scalix.mydomain.org ESM"..., 102) = 102
12:53:12 time(NULL)                     = 1165859592
12:53:12 time([1165859592])             = 1165859592
12:53:12 select(6, [4 5], [], NULL, {3600, 0}) = 1 (in [4], left {3600, 0})
12:53:12 read(4, "xommap cswihart@mydomain.or"..., 1024) = 35
12:53:12 time([1165859592])             = 1165859592
12:53:12 select(6, [5], [4], NULL, NULL) = 1 (out [4])
12:53:12 write(4, "251 Not OpenMail Address\r\n", 26) = 26
12:53:12 time(NULL)                     = 1165859592
12:53:12 time([1165859592])             = 1165859592
12:53:12 select(6, [4 5], [], NULL, {3600, 0}) = 1 (in [4], left {3600, 0})
12:53:12 read(4, "quit\r\n", 1024)      = 6
12:53:12 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
12:53:12 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
12:53:12 time([1165859592])             = 1165859592
12:53:12 select(6, [5], [4], NULL, NULL) = 1 (out [4])
12:53:12 write(4, "221 scalix.mydomain.org clo"..., 49) = -1 EPIPE (Broken pipe)
12:53:12 --- SIGPIPE (Broken pipe) @ 0 (0) ---
12:53:12 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
12:53:12 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
12:53:12 close(4)                       = 0
12:53:12 time([1165859592])             = 1165859592
12:53:12 select(6, [5], [], NULL, NULL


Suggestions?

Thanks again,

-Chris[/code]

[slapshotct]

This is exactly the issue we are having as well.

Have you had any luck finding a solution?

[cswihart]

Sorry, No luck yet. I've been waiting to hear back. I do believe the problem is somehow related to sendmail. I can telnet locally to the scalix smtpd relay and perform a manual send with no delay. However, when I telnet locally to sendmail response is slow when resolving the mail from: and rcpt to: commands.

Good Luck and I will post if I am able to resolve anything.

-Chris

[dkelly]

I suspect the problem is related to DNS. In particular, this trace shows:

Code: Select all

12:53:02 connect(16, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("192.168.249.18")}, 28) = 0
12:53:02 fcntl64(16, F_GETFL)           = 0x2 (flags O_RDWR)
12:53:02 fcntl64(16, F_SETFL, O_RDWR|O_NONBLOCK) = 0
12:53:02 gettimeofday({1165859582, 304949}, NULL) = 0
12:53:02 poll([{fd=16, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
12:53:02 send(16, "_\264\1\0\0\1\0\0\0\0\0\0\0010\0010\0010\0010\7in-addr"..., 38, 0) = 38
12:53:02 poll([{fd=16, events=POLLIN}], 1, 5000) = 0
12:53:07 gettimeofday({1165859587, 305931}, NULL) = 0
12:53:07 poll([{fd=16, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
12:53:07 send(16, "_\264\1\0\0\1\0\0\0\0\0\0\0010\0010\0010\0010\7in-addr"..., 38, 0) = 38
12:53:07 poll([{fd=16, events=POLLIN}], 1, 5000) = 0
12:53:12 close(16)

Which says to me that the DNS server failed to respond to the request. It looks like the resolver libraries attempted twice and so you have a 10s delay trying to talk to the DNS server.

Cheers

Dave

[slapshotct]

I am a bit discouraged about how long this thread has been open without a resolution. What can we try? Both myself and cswihart have checked forward and reverse DNS and it is functioning promptly and as expected.

I ran a trace on a regular email coming through omsmtpd and take a look at this lag:

Code: Select all

00:46:29 open("/etc/hosts", O_RDONLY)   = 9
00:46:29 fcntl64(9, F_GETFD)            = 0
00:46:29 fcntl64(9, F_SETFD, FD_CLOEXEC) = 0
00:46:29 fstat64(9, {st_mode=S_IFREG|0644, st_size=594, ...}) = 0
00:46:29 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fc7000
00:46:29 read(9, "# Do not remove the following li"..., 4096) = 594
00:46:29 close(9)                       = 0
00:46:29 munmap(0xb7fc7000, 4096)       = 0
00:46:29 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 9
00:46:29 open("/etc/hosts", O_RDONLY)   = 10
00:46:29 fcntl64(10, F_GETFD)           = 0
00:46:29 fcntl64(10, F_SETFD, FD_CLOEXEC) = 0
00:46:29 fstat64(10, {st_mode=S_IFREG|0644, st_size=594, ...}) = 0
00:46:29 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fc7000
00:46:29 read(10, "# Do not remove the following li"..., 4096) = 594
00:46:29 close(10)                      = 0
00:46:29 munmap(0xb7fc7000, 4096)       = 0
00:46:29 connect(9, {sa_family=AF_INET, sin_port=htons(25), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
00:46:29 fcntl64(9, F_GETFL)            = 0x2 (flags O_RDWR)
00:46:29 fstat64(9, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
00:46:29 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fc7000
00:46:29 _llseek(9, 0, 0xbff026b4, SEEK_CUR) = -1 ESPIPE (Illegal seek)
00:46:29 fcntl64(9, F_GETFL)            = 0x2 (flags O_RDWR)
00:46:29 fstat64(9, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
00:46:29 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb79e3000
00:46:29 _llseek(9, 0, 0xbff026b4, SEEK_CUR) = -1 ESPIPE (Illegal seek)
00:46:29 read(9, "220 mail.ourdomain.com ESMTP Sendmai"..., 1024) = 82
00:46:29 write(9, "EHLO mail.ourdomain.com\r\n", 21) = 21
00:46:29 read(9, "250-mail.ourdomain.com Hello localho"..., 1024) = 215
00:46:29 write(9, "MAIL FROM: AlP@acc.i"..., 35) = 35
00:46:29 read(9, "250 2.1.0 AlP@acc.it"..., 1024) = 47
00:46:40 write(9, "RCPT TO: devine@ourdomain.com\r\n", 27) = 27
00:46:40 read(9, "550 5.1.1 devine@ourdomain.com... Us"..., 1024) = 44
00:46:40 write(9, "QUIT\r\n", 6)        = 6
00:46:40 read(9, "221 2.0.0 mail.ourdomain.com closing"..., 1024) = 45
00:46:40 close(9)                       = 0
00:46:40 munmap(0xb7fc7000, 4096)       = 0
00:46:40 close(9)                       = -1 EBADF (Bad file descriptor)
00:46:40 munmap(0xb79e3000, 4096)       = 0
00:46:40 time([1166507200])             = 1166507200
00:46:40 write(3, "Cli 22098/2 rcvd: \'RCPT TO: <dev"..., 48) = 48
00:46:40 select(37, [4 5 32 36], [6], NULL, {3589, 0}) = 4 (in [4 5 36], out [6], left {3589, 0})
00:46:40 read(36, "\205", 1)            = 1
00:46:40 accept(5, {sa_family=AF_INET, sin_port=htons(4623), sin_addr=inet_addr("211.169.68.150")}, [16]) = 9
00:46:40 fcntl64(9, F_GETFD)            = 0
00:46:40 fcntl64(9, F_SETFD, FD_CLOEXEC) = 0


There is a 11 second delay and it is not during the DNS lookup.

I wrote a little script that looks like this:

Code: Select all

#!/usr/bin/perl
@domains = ("google.com","yahoo.com","msn.com","scalix.com","216.239.57.25","209.191.118.103","72.18.242.131");
open(OUT,">DNStimes.txt");
for(@domains) {
     my $t = localtime();
     print OUT "$t -- testing $_\n";
     my $r = `nslookup $_`;
     my $t2 = localtime();
     print OUT "$t2 -- $r\n";
}
close(OUT);


Using that script, I can see that every DNS query comes back in less than a second because the line that says "testing" and the result line share the same timestamp even though I issue a second before printing the result. In fact, the entire script runs within a second. In my script, I also have our mail server name and ip address so I can check the times there.

If it is DNS, where should we be checking and/or can you point us to some definitive documentation on how DNS should be set up for a Scalix server? I have read everything about it in the administration guide and have followed everything to no avail.

Thanks,
SlapShot

[dkelly]

When the SMTP Relay receives a message, after checking to see if the recipient is in the Scalix SYSTEM directory, is to talk to sendmail to find out if the user is a local one. This is done by opening up a socket connection to localhost:25 and faking an SMTP conversation.

So, the strace you posted shows that conversation. In a lot of cases, we have been able to see that DNS is absolutely the cause of the problem by stracing the command sendmail -bt, i.e.

Code: Select all

[root@desktop ~]# sendmail -bt
ADDRESS TEST MODE (ruleset 3 NOT automatically invoked)
Enter <ruleset> <address>
> 3,0 test.user@gmail.com
canonify           input: test . user @ gmail . com
Canonify2          input: test . user < @ gmail . com >
Canonify2        returns: test . user < @ gmail . com . >
canonify         returns: test . user < @ gmail . com . >
parse              input: test . user < @ gmail . com . >
Parse0             input: test . user < @ gmail . com . >
Parse0           returns: test . user < @ gmail . com . >
ParseLocal         input: test . user < @ gmail . com . >
ScalixMapper       input: < test . user < @ gmail . com . > > < test . user @ gmail . com >
ScalixMapper     returns: test . user < @ gmail . com . >
ParseLocal       returns: test . user < @ gmail . com . >
Parse1             input: test . user < @ gmail . com . >
Mailertable        input: < gmail . com > test . user < @ gmail . com . >
Mailertable        input: gmail . < com > test . user < @ gmail . com . >
Mailertable      returns: test . user < @ gmail . com . >
Mailertable      returns: test . user < @ gmail . com . >
MailerToTriple     input: < > test . user < @ gmail . com . >
MailerToTriple   returns: test . user < @ gmail . com . >
Parse1           returns: $# esmtp $@ gmail . com . $: test . user < @ gmail . com . >
parse            returns: $# esmtp $@ gmail . com . $: test . user < @ gmail . com . >
>

Use CTRL-D to exit.

Please can you provide another strace ?

Cheers

Dave

[cswihart]

Dave,

Here is the results of sendmail -bt

Code: Select all

ADDRESS TEST MODE (ruleset 3 NOT automatically invoked)
Enter <ruleset> <address>
> 3,0 test.user@gamil.com
canonify           input: test . user @ gamil . com
Canonify2          input: test . user < @ gamil . com >
Canonify2        returns: test . user < @ gamil . com . >
canonify         returns: test . user < @ gamil . com . >
parse              input: test . user < @ gamil . com . >
Parse0             input: test . user < @ gamil . com . >
Parse0           returns: test . user < @ gamil . com . >
ParseLocal         input: test . user < @ gamil . com . >
ParseLocal       returns: test . user < @ gamil . com . >
Parse1             input: test . user < @ gamil . com . >
Mailertable        input: < gamil . com > test . user < @ gamil . com . >
Mailertable        input: gamil . < com > test . user < @ gamil . com . >
Mailertable      returns: test . user < @ gamil . com . >
Mailertable      returns: test . user < @ gamil . com . >
MailerToTriple     input: < > test . user < @ gamil . com . >
MailerToTriple   returns: test . user < @ gamil . com . >
Parse1           returns: $# esmtp $@ gamil . com . $: test . user < @ gamil . com . >
parse            returns: $# esmtp $@ gamil . com . $: test . user < @ gamil . com . >
>

Here is the results of strace

Code: Select all

scalix:~ # strace -t -p 15615
Process 15615 attached - interrupt to quit
14:24:00 select(5, [4], [], NULL, NULL) = 1 (in [4])
14:24:13 accept(4, {sa_family=AF_FILE, path=@@H}, [2]) = 3
14:24:13 fcntl64(3, F_GETFD)            = 0
14:24:13 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
14:24:13 open("/etc/hosts", O_RDONLY)   = 15
14:24:13 fcntl64(15, F_GETFD)           = 0
14:24:13 fcntl64(15, F_SETFD, FD_CLOEXEC) = 0
14:24:13 fstat64(15, {st_mode=S_IFREG|0644, st_size=736, ...}) = 0
14:24:13 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40852000
14:24:13 read(15, "#\n# hosts         This file desc"..., 4096) = 736
14:24:13 read(15, "", 4096)             = 0
14:24:13 read(15, "", 4096)             = 0
14:24:13 close(15)                      = 0
14:24:13 munmap(0x40852000, 4096)       = 0
14:24:13 time([1166556253])             = 1166556253
14:24:13 stat64("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
14:24:13 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 15
14:24:13 connect(15, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.16.0.3")}, 28) = 0
14:24:13 fcntl64(15, F_GETFL)           = 0x2 (flags O_RDWR)
14:24:13 fcntl64(15, F_SETFL, O_RDWR|O_NONBLOCK) = 0
14:24:13 gettimeofday({1166556253, 32830}, NULL) = 0
14:24:13 poll([{fd=15, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
14:24:13 send(15, "\365\341\1\0\0\1\0\0\0\0\0\0\0010\0010\0010\0010\7in-a"..., 38, 0) = 38
14:24:13 poll([{fd=15, events=POLLIN}], 1, 5000) = 0
14:24:18 gettimeofday({1166556258, 33915}, NULL) = 0
14:24:18 poll([{fd=15, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
14:24:18 send(15, "\365\341\1\0\0\1\0\0\0\0\0\0\0010\0010\0010\0010\7in-a"..., 38, 0) = 38
14:24:18 poll([{fd=15, events=POLLIN}], 1, 5000) = 0
14:24:23 close(15)                      = 0
14:24:23 time(NULL)                     = 1166556263
14:24:23 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
14:24:23 time([1166556263])             = 1166556263
14:24:23 select(5, [4], [3], NULL, NULL) = 1 (out [3])
14:24:23 write(3, "220 scalix.berriencounty.org ESM"..., 102) = 102
14:24:23 time(NULL)                     = 1166556263
14:24:23 time([1166556263])             = 1166556263
14:24:23 select(5, [3 4], [], NULL, {3600, 0}) = 1 (in [3], left {3600, 0})
14:24:23 read(3, "xommap test.user@gamil.com\r\n", 1024) = 28
14:24:23 rt_sigaction(SIGALRM, {0x40069b88, [ALRM], SA_RESTART}, {SIG_IGN}, 8) = 0
14:24:23 alarm(60)                      = 0
14:24:23 fcntl64(7, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
14:24:23 alarm(0)                       = 60
14:24:23 rt_sigaction(SIGALRM, {SIG_IGN}, {0x40069b88, [ALRM], SA_RESTART}, 8) = 0
14:24:23 fstat64(7, {st_mode=S_IFREG|0666, st_size=0, ...}) = 0
14:24:23 lseek(9, 0, SEEK_SET)          = 0
14:24:23 read(9, "\377\377\377\377\2\0\0\0\0\0\0\0", 12) = 12
14:24:23 lseek(9, 4096, SEEK_SET)       = 4096
14:24:23 read(9, "\t\307\201E\35\0\377\377\377\377\t\0001\0\0\0\313SCALI"..., 4096) = 4096
14:24:23 lseek(8, 0, SEEK_SET)          = 0
14:24:23 read(8, "\377\377\377\377\2\0\0\0\0\0\0\0", 12) = 12
14:24:23 lseek(8, 4096, SEEK_SET)       = 4096
14:24:23 read(8, "\366\36(D\0\0\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
14:24:23 rt_sigaction(SIGALRM, {0x40069b88, [ALRM], SA_RESTART}, {SIG_IGN}, 8) = 0
14:24:23 alarm(60)                      = 0
14:24:23 fcntl64(7, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
14:24:23 alarm(0)                       = 60
14:24:23 rt_sigaction(SIGALRM, {SIG_IGN}, {0x40069b88, [ALRM], SA_RESTART}, 8) = 0
14:24:23 open("/var/opt/scalix/sys/unixmap.in", O_RDONLY) = -1 ENOENT (No such file or directory)
14:24:23 open("/var/opt/scalix/sys/unixin.rules", O_RDONLY) = 15
14:24:23 fcntl64(15, F_GETFD)           = 0
14:24:23 fcntl64(15, F_SETFD, FD_CLOEXEC) = 0
14:24:23 fstat64(15, {st_mode=S_IFREG|0444, st_size=1736, ...}) = 0
14:24:23 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40852000
14:24:23 read(15, "# @(#)$Id: unixin.rules,v 1.2 20"..., 4096) = 1736
14:24:23 close(15)                      = 0
14:24:23 munmap(0x40852000, 4096)       = 0
14:24:23 open("/var/opt/scalix/sys/unixmap.gw", O_RDONLY) = -1 ENOENT (No such file or directory)
14:24:23 rt_sigaction(SIGALRM, {0x40069b88, [ALRM], SA_RESTART}, {SIG_IGN}, 8) = 0
14:24:23 alarm(60)                      = 0
14:24:23 fcntl64(7, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
14:24:23 alarm(0)                       = 60
14:24:23 rt_sigaction(SIGALRM, {SIG_IGN}, {0x40069b88, [ALRM], SA_RESTART}, 8) = 0
14:24:23 fstat64(7, {st_mode=S_IFREG|0666, st_size=0, ...}) = 0
14:24:23 lseek(9, 0, SEEK_SET)          = 0
14:24:23 read(9, "\377\377\377\377\2\0\0\0\0\0\0\0", 12) = 12
14:24:23 lseek(9, 4096, SEEK_SET)       = 4096
14:24:23 read(9, "\t\307\201E\35\0\377\377\377\377\t\0001\0\0\0\313SCALI"..., 4096) = 4096
14:24:23 lseek(8, 0, SEEK_SET)          = 0
14:24:23 read(8, "\377\377\377\377\2\0\0\0\0\0\0\0", 12) = 12
14:24:23 lseek(8, 4096, SEEK_SET)       = 4096
14:24:23 read(8, "\366\36(D\0\0\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
14:24:23 rt_sigaction(SIGALRM, {0x40069b88, [ALRM], SA_RESTART}, {SIG_IGN}, 8) = 0
14:24:23 alarm(60)                      = 0
14:24:23 fcntl64(7, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
14:24:23 alarm(0)                       = 60
14:24:23 rt_sigaction(SIGALRM, {SIG_IGN}, {0x40069b88, [ALRM], SA_RESTART}, 8) = 0
14:24:23 open("/var/opt/scalix/sys/unixmap.in", O_RDONLY) = -1 ENOENT (No such file or directory)
14:24:23 open("/var/opt/scalix/sys/unixin.rules", O_RDONLY) = 15
14:24:23 fcntl64(15, F_GETFD)           = 0
14:24:23 fcntl64(15, F_SETFD, FD_CLOEXEC) = 0
14:24:23 fstat64(15, {st_mode=S_IFREG|0444, st_size=1736, ...}) = 0
14:24:23 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40852000
14:24:23 read(15, "# @(#)$Id: unixin.rules,v 1.2 20"..., 4096) = 1736
14:24:23 close(15)                      = 0
14:24:23 munmap(0x40852000, 4096)       = 0
14:24:23 open("/var/opt/scalix/sys/unixmap.gw", O_RDONLY) = -1 ENOENT (No such file or directory)
14:24:23 open("/var/opt/scalix/sys/defmnode", O_RDONLY) = 15
14:24:23 fcntl64(15, F_GETFD)           = 0
14:24:23 fcntl64(15, F_SETFD, FD_CLOEXEC) = 0
14:24:23 lseek(15, 1024, SEEK_SET)      = 1024
14:24:23 read(15, "\35\35\35\35internet\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024) = 1024
14:24:23 close(15)                      = 0
14:24:23 time([1166556263])             = 1166556263
14:24:23 select(5, [4], [3], NULL, NULL) = 1 (out [3])
14:24:23 write(3, "251 Not OpenMail Address and no "..., 43) = 43
14:24:23 time(NULL)                     = 1166556263
14:24:23 time([1166556263])             = 1166556263
14:24:23 select(5, [3 4], [], NULL, {3600, 0}) = 1 (in [3], left {3600, 0})
14:24:23 read(3, "quit\r\n", 1024)      = 6
14:24:23 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
14:24:23 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
14:24:23 time([1166556263])             = 1166556263
14:24:23 select(5, [4], [3], NULL, NULL) = 1 (out [3])
14:24:23 write(3, "221 scalix.mydomain.org clo"..., 49) = -1 EPIPE (Broken pipe)
14:24:23 --- SIGPIPE (Broken pipe) @ 0 (0) ---
14:24:23 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
14:24:23 write(-1, "quit\n", 5)         = -1 EBADF (Bad file descriptor)
14:24:23 close(3)                       = 0
14:24:23 time([1166556263])             = 1166556263
14:24:23 select(5, [4], [], NULL, NULL


Let me know if you need anything else

Thanks,

Chris