[SOLVED] Help with davmail and sending mails without authentication.

sasheto86 · 08-08-2013, 07:41 AM

Hey guys,

Here's the scenario:

We have a server running exchange 2010.

I'm running Davmail as a Tomcat App on a Centos 6.4 VM and have loosely followed the setup described in http://www.openlogic.com/wazi/bid/18...x-Courier-IMAP

Davmail works fine, and as /var/logs/tomcat6/catalina.out shows:

Code:

2013-08-08 05:58:38,278 DEBUG [SmtpConnection-40957] davmail  - > 220 DavMail 4.3.2-2140-trunk SMTP ready at Thu Aug 08 05:58:38 EEST 2013
2013-08-08 05:58:38,279 DEBUG [SmtpConnection-40957] davmail  - < EHLO localhost
2013-08-08 05:58:38,279 DEBUG [SmtpConnection-40957] davmail  - > 250-localhost
2013-08-08 05:58:38,279 DEBUG [SmtpConnection-40957] davmail  - > 250-AUTH LOGIN PLAIN
2013-08-08 05:58:38,279 DEBUG [SmtpConnection-40957] davmail  - > 250-8BITMIME
2013-08-08 05:58:38,279 DEBUG [SmtpConnection-40957] davmail  - > 250 Hello
2013-08-08 05:58:38,319 DEBUG [SmtpConnection-40957] davmail  - < LOGIN ********
2013-08-08 05:58:38,319 DEBUG [SmtpConnection-40957] davmail  - > 334 VXNlcm5hbWU6
2013-08-08 05:58:38,320 DEBUG [SmtpConnection-40957] davmail  - < YWxleGFuZGVyLnZhc3NpbGV2c2tpQGF4cy1vZmZpY2VzLmNvbQ==
2013-08-08 05:58:38,320 DEBUG [SmtpConnection-40957] davmail  - > 334 UGFzc3dvcmQ6
2013-08-08 05:58:38,320 DEBUG [SmtpConnection-40957] davmail  - < ********
2013-08-08 05:58:38,320 DEBUG [SmtpConnection-40957] davmail.exchange.ExchangeSession  - Got session davmail.exchange.ews.EwsExchangeSession@4eb7b28b from cache
2013-08-08 05:58:38,597 DEBUG [SmtpConnection-40957] davmail  - > 235 OK Authenticated
2013-08-08 05:58:38,617 DEBUG [SmtpConnection-40957] davmail  - < MAIL FROM:<my.user@corp.com>
2013-08-08 05:58:38,617 DEBUG [SmtpConnection-40957] davmail  - > 250 Sender OK
2013-08-08 05:58:38,618 DEBUG [SmtpConnection-40957] davmail  - < RCPT TO:<my.user@corp.com>
2013-08-08 05:58:38,618 DEBUG [SmtpConnection-40957] davmail  - > 250 Recipient OK
2013-08-08 05:58:38,618 DEBUG [SmtpConnection-40957] davmail  - < DATA
2013-08-08 05:58:38,619 DEBUG [SmtpConnection-40957] davmail  - > 354 Start mail input; end with <CRLF>.<CRLF>
2013-08-08 05:58:38,725 DEBUG [SmtpConnection-40957] davmail  - > 250 Queued mail for delivery
2013-08-08 05:58:38,726 DEBUG [SmtpConnection-40957] davmail  - < QUIT
2013-08-08 05:58:38,726 DEBUG [SmtpConnection-40957] davmail  - > 221 Closing connection

I can't send mail with no authentication, however.

The above log output is for an authenticated connection which happens when I run the following php script:

Code:

<?php
include("Mail.php");
$recipients = "my.user@corp.com";
$headers["From"] = "my.user@corp.com";
$headers["To"] = "my.user@corp.com";
$headers["Subject"] = "User feedback";
$mailmsg = "Hello, This is a test.";
$smtpinfo["host"] = "192.168.9.79";
$smtpinfo["port"] = "1025";
$smtpinfo["auth"] = true;
$smtpinfo["username"] = "my.user@corp.com";
$smtpinfo["password"] = "*******************";
$mail_object =& Mail::factory("smtp", $smtpinfo);
$mail_object->send($recipients, $headers, $mailmsg);
?>

The problem is that the simple mail function program doesn't work:

Code:

<?php

$to      = 'my.user@corp.com';

$subject = 'the subject';

$message = 'hello';

$headers = 'From: my.user@corp.com' . "\r\n" .

    'Reply-To: my.user@corp.com' . "\r\n" .

    'X-Mailer: PHP/' . phpversion();

mail($to, $subject, $message, $headers);

?>

In php.ini I have:

Code:

SMTP = 192.168.9.79
smtp_port = 1025

and I have the application bind to the same address and port, so this is correct.

Nothing shows up when I tail catalina.out, and when I straced the program which uses the mail() function, I could see things like this:

Code:

chdir("/var/spool/postfix")             = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGXFSZ, {SIG_IGN, [XFSZ], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGINT, {0x7f1b74d7ad00, [INT], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {0x7f1b74d7ad00, [QUIT], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGTERM, {SIG_IGN, [TERM], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGTERM, {0x7f1b74d7ad00, [TERM], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_IGN, [TERM], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, 8) = 0
rt_sigaction(SIGHUP, {SIG_IGN, [HUP], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGHUP, {0x7f1b74d7ad00, [HUP], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, {SIG_IGN, [HUP], SA_RESTORER|SA_RESTART, 0x7f1b72790920}, 8) = 0
open("maildrop/857140.1613", O_RDWR|O_CREAT|O_EXCL, 0644) = 4
fstat(4, {st_dev=makedev(253, 0), st_ino=7865657, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=90, st_blksize=4096, st_blocks=0, st_size=0, st_atime=2013/08/08-06:46:41, st_mtime=2013/08/08-06:46:41, st_ctime=2013/08/08-06:46:41}) = 0
rename("maildrop/857140.1613", "maildrop/D15B0780539") = 0
write(1, "queue_id\0D15B0780539\0\0", 22) = 22
read(0, "A\25rewrite_context=localF\4rootS\4rootM\0N'To: my.user@corp.comN\24Subject: the subjectN#X-PHP-Originating-Script: 500:m.phpN,From: my.user@corp.com\rN.Reply-To: my.user@corp.com\rN\23X-Mailer: PHP/5.3.3N\0N\5helloX\0R#my.user@corp.comE\0", 4096) = 302
write(4, "T\0211375933601 857138A\25rewrite_context=localF\4rootS\4rootM\0N'To: my.user@corp.comN\24Subject: the subjectN#X-PHP-Originating-Script: 500:m.phpN,From: my.user@corp.com\rN.Reply-To: my.user@corp.com\rN\23X-Mailer: PHP/5.3.3N\0N\5helloX\0R#my.user@corp.comE\0", 321)                               = 321
fchmod(4, 0744)                         = 0
fsync(4)                                = 0
close(4)                                = 0
stat("public/pickup", {st_dev=makedev(253, 0), st_ino=7865244, st_mode=S_IFIFO|0622, st_nlink=1, st_uid=89, st_gid=89, st_blksize=4096, st_blocks=0, st_size=0, st_atime=2013/08/08-06:46:01, st_mtime=2013/08/08-06:46:01, st_ctime=2013/08/08-06:46:01}) = 0
open("public/pickup", O_WRONLY|O_NONBLOCK) = -1 ENXIO (No such device or address)
write(1, "status\0000\0reason\0\0\0", 18) = 18

Which to me means that sendmail here is trying to leave the message in public/pickup for postfix to pickup but this means that we are not connecting to Davmail at all.

So anyway, my idea was to make postfix act as a relay for Davmail (with authentication), or to remove postfix entirely and replace the sendmail program, and change the commandline params in php.ini.

Can you please give me some advice on how to proceed with either. I can provide you with any conf file or system info that you need.

sasheto86 · 08-09-2013, 02:48 AM

sasheto86 · 08-09-2013, 03:52 AM

OK - maybe I scared everyone away with the long explanation.

Basically I need some help with configuring postfix (or just a custom sendmail binary) to do the following:

- I need anonymous mail (without authentication) to be allowed
- the daemon (say postfix) needs to be able to relay all sent mail to the davmail which is already running on port 1025
- the deamon (say postfix) needs to rewrite the sender address (from anonymous) to a default address and then needs to authenticate with davmail to send the mail

I'm reading the postfix documentation as we speak - I'm just hoping someone can help with some pointers - thank you.

sasheto86 · 08-09-2013, 07:00 AM

So, after reading a bit about how sendmail and postfix works, i decided to check /var/spool/postfix/active and :

Code:

[root@exchange-relay postfix]# postcat active/* | tail -n 24
*** ENVELOPE RECORDS active/E743C78053F ***
message_size:             470             192               1               0             470
message_arrival_time: Thu Aug  8 06:06:10 2013
create_time: Thu Aug  8 06:06:10 2013
named_attribute: rewrite_context=local
sender_fullname: root
sender: root@exchange-relay.corp.com
*** MESSAGE CONTENTS active/E743C78053F ***
Received: by exchange-relay.corp.com (Postfix, from userid 0)
        id E743C78053F; Thu,  8 Aug 2013 06:06:10 +0300 (EEST)
To: my.user@corp.com
Subject: the subject
X-PHP-Originating-Script: 500:m.php
From: my.user@corp.com
Reply-To: my.user@corp.com
X-Mailer: PHP/5.3.3
Message-Id: <20130808030610.E743C78053F@exchange-relay.corp.com>
Date: Thu,  8 Aug 2013 06:06:10 +0300 (EEST)

hello
*** HEADER EXTRACTED active/E743C78053F ***
original_recipient: my.user@corp.com
recipient: my.user@corp.com
*** MESSAGE FILE END active/E743C78053F ***

This means that the mails are reaching the active queue.

Also, I straced the qmgr daemon's PID and I see the following:

Code:

alarm(333)                              = 331
ioctl(3, FIONREAD, [100])               = 0
epoll_wait(8, {{EPOLLIN, {u32=6, u64=4589496568108810246}}}, 100, 297000) = 1
write(5, "\331\30\0\0\271\4\0\0\0\0\0\0", 12) = 12
read(6, "W", 1024)                      = 1
open("incoming", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 9
write(5, "\331\30\0\0\271\4\0\0\1\0\0\0", 12) = 12
alarm(333)                              = 138
getdents(9, {{d_ino=7865151, d_off=1962655142159378278, d_reclen=24, d_name="."} {d_ino=7865674, d_off=6241122602702652197, d_reclen=32, d_name="112D378054A"} {d_ino=7865143, d_off=9223372036854775807, d_reclen=24, d_name=".."}}, 32768) = 80
lstat("incoming/112D378054A", {st_dev=makedev(253, 0), st_ino=7865674, st_mode=S_IFREG|0700, st_nlink=1, st_uid=89, st_gid=89, st_blksize=4096, st_blocks=8, st_size=739, st_atime=2013/08/09-06:47:35, st_mtime=2013/08/09-06:47:35, st_ctime=2013/08/09-06:47:35}) = 0
rename("incoming/112D378054A", "active/112D378054A") = 0
open("active/112D378054A", O_RDWR)      = 10
flock(10, LOCK_EX|LOCK_NB)              = 0
lseek(10, 0, SEEK_CUR)                  = 0
read(10, "CO            472             189               1               0             472T\0211376020054 959075A\26create_time=1376020055A\25rewrite_context=localF\0S$my.user@exchange-relay.corp.comM\0NFReceived: by exchange-relay.corp.com (Postfix, from userid 500)N7\tid 112D378054A; Fri,  9 Aug 2013 06:47:34 +0300 (EEST)N'To: my.user@corp.comN\24Subject: the subjectN#X-PHP-Originating-Script: 500:m.phpN,From: my.user@corp.com\rN.Reply-To: my.user@corp.com\rN\23X-Mailer: PHP/5.3.3NGMessage-Id: <20130809034735.112D378054A@exchange-relay.corp.com>N,Date: Fri,  9 Aug 2013 06:47:34 +0300 (EEST)N\0N\5helloX\0O#my.user@corp.comR#my.user@corp.comE\0", 4096) = 739
sendto(7, "<22>Aug  9 06:47:35 postfix/qmgr[6361]: 112D378054A: from=<my.user@exchange-relay.corp.com>, size=472, nrcpt=1 (queue active)", 130, MSG_NOSIGNAL, NULL, 0) = 130
lseek(10, -78, SEEK_CUR)                = 661
read(10, "X\0O#my.user@corp.comR#my.user@corp.comE\0", 4096) = 78
unlink("defer/1/112D378054A")           = -1 ENOENT (No such file or directory)
socket(PF_FILE, SOCK_STREAM, 0)         = 11
fcntl(11, F_GETFL)                      = 0x2 (flags O_RDWR)
fcntl(11, F_SETFL, O_RDWR)              = 0
connect(11, {sa_family=AF_FILE, path="private/rewrite"}, 110) = 0
fcntl(11, F_GETFD)                      = 0
fcntl(11, F_SETFD, FD_CLOEXEC)          = 0
epoll_ctl(8, EPOLL_CTL_ADD, 11, {EPOLLIN, {u32=11, u64=4589979425512095755}}) = 0
poll([{fd=11, events=POLLOUT}], 1, 3600000) = 1 ([{fd=11, revents=POLLOUT}])
write(11, "request\0resolve\0sender\0my.user@exchange-relay.corp.com\0address\0my.user@corp.com\0\0", 105) = 105
poll([{fd=11, events=POLLIN}], 1, 3600000) = 1 ([{fd=11, revents=POLLIN}])
read(11, "flags\0000\0transport\0smtp\0nexthop\0[192.168.9.79]:1025\0recipient\0my.user@corp.com\0flags\0004096\0\0", 4096) = 109
close(10)                               = 0
ioctl(3, FIONREAD, [99])                = 0
write(4, "\0", 1)                       = 1
epoll_wait(8, {}, 100, 0)               = 0
alarm(333)                              = 333
getdents(9, {}, 32768)                  = 0
close(9)                                = 0
ioctl(3, FIONREAD, [100])               = 0
epoll_wait(8, {}, 100, 5000)            = 0
epoll_ctl(8, EPOLL_CTL_DEL, 11, {EPOLLIN, {u32=11, u64=747951374729227}}) = 0
close(11)                               = 0
alarm(333)                              = 328
ioctl(3, FIONREAD, [100])               = 0
epoll_wait(8,  <unfinished ...>

Interesting from above is this:

Code:

read(11, "flags\0000\0transport\0smtp\0nexthop\0[192.168.9.79]:1025\0recipient\0my.user@corp.com\0flags\0004096\0\0", 4096) = 109

This nexthop location is exactly what it should be.

I also straced the tomcat process which is running the DAVMAIL, but nothing turned up none of the childs, so I am at a dead end here.

I think next I'll post my conf files for postfix - hopefully somebody can give me some assit...

sasheto86 · 08-09-2013, 08:01 AM

Also, I can see that the mails sent via the php script ( mail() script ) are here:

Code:

[root@exchange-relay postfix]#  postqueue -p  
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
56EC17804E2*     466 Fri Jul 12 09:20:15  root@exchange-relay.corp.com
                                         my.user@corp.com

145D078053E*     470 Thu Aug  8 06:05:52  root@exchange-relay.corp.com
                                         my.user@corp.com

35D4C780546*     470 Thu Aug  8 06:38:24  root@exchange-relay.corp.com
                                         my.user@corp.com

...

5DD0A7804E3*     466 Fri Jul 12 09:20:27  root@exchange-relay.corp.com
                                         my.user@corp.com

-- 24 Kbytes in 30 Requests.

So I decided to check /var/log/maillog.

In there I noticed a lot of error messages like

Code:

...
Aug  9 06:28:38 exchange-relay postfix/master[2158]: warning: /usr/libexec/postfix/smtp: bad command startup -- throttling
...

After some google, I ran

Code:

[root@exchange-relay postfix]# postalias /etc/aliases

and this showed up in maillog:

Code:

Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 4546E780542: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 19BCB780545: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active BCE91780534: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 803547804E1: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active E743C78053F: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 77578780547: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active E34A7780543: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 01905780540: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 5DD0A7804E3: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 2EF0F7804CA: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active EB63B780549: No such file or directory
Aug  9 07:51:02 exchange-relay postfix/smtp[7092]: warning: open active 112D378054A: No such file or directory
Aug  9 07:51:08 exchange-relay postfix/smtp[7096]: 0334D780546: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, delay=3813, delays=3421/387/5.3/0, dsn=4.7.4, status=deferred (TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:08 exchange-relay postfix/smtp[7093]: E2FF07804E2: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, delay=92716, delays=92324/386/5.5/0, dsn=4.7.4, status=deferred (TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:08 exchange-relay postfix/smtp[7095]: EEE0B78053E: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, delay=90764, delays=90372/386/5.5/0, dsn=4.7.4, status=deferred (TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:08 exchange-relay postfix/smtp[7092]: CF4317804C7: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, delay=2413854, delays=2413461/386/6.4/0, dsn=4.7.4, status=deferred (TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:08 exchange-relay postfix/smtp[7103]: 1609D780541: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, delay=93371, delays=92978/387/5.8/0, dsn=4.7.4, status=deferred (TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:08 exchange-relay postfix/smtp[7101]: 0B58378054A: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, delay=92423, delays=92030/387/6/0, dsn=4.7.4, status=deferred (TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7109]: 1DC737804CB: to=<my.user@corp.com>, relay=none, delay=2165960, delays=2165567/393/0/0.09, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7109]: 26687780519: to=<my.user@corp.com>, relay=none, delay=2414253, delays=2413860/393/0/0.05, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7109]: 364817804C9: to=<my.user@corp.com>, relay=none, delay=2414017, delays=2413624/393/0/0.01, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7110]: 2E0647804DE: to=<my.user@corp.com>, relay=none, delay=2416844, delays=2416451/393/0/0.08, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7109]: 3C7E07804DF: to=<my.user@corp.com>, relay=none, delay=93201, delays=92808/393/0/0.06, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7109]: 5585E780518: to=<my.user@corp.com>, relay=none, delay=4398, delays=4005/393/0/0.01, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7110]: 44B7178053D: to=<my.user@corp.com>, relay=none, delay=2165985, delays=2165592/393/0/0.08, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7109]: 5FC537804CA: to=<my.user@corp.com>, relay=none, delay=176847, delays=176454/393/0/0.08, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])
Aug  9 07:51:09 exchange-relay postfix/error[7110]: 69494780481: to=<my.user@corp.com>, relay=none, delay=90268, delays=89875/393/0/0.12, dsn=4.7.4, status=deferred (delivery temporarily suspended: TLS is required, but was not offered by host 192.168.9.79[192.168.9.79])

I'll continue updating this with my progress.

sasheto86 · 08-09-2013, 08:27 AM

I removed the MUST line from my /etc/postfix/tls_per_site and ran postmap again on the file, and started getting these errors:

Code:

Aug  9 07:59:28 exchange-relay postfix/smtp[7150]: 0B58378054A: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, conn_use=3, delay=92923, delays=92912/11/0/0.1, dsn=4.0.0, status=deferred (host 192.168.9.79[192.168.9.79] said: 451 Error : davmail.exchange.ews.EWSException: ErrorSendAsDenied The user account which was used to submit this request does not have the right to send mail on behalf of the specified sending account. (in reply to end of DATA command))
Aug  9 07:59:28 exchange-relay postfix/smtp[7174]: A4A9E780542: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, conn_use=3, delay=91542, delays=91531/11/0/0.09, dsn=4.0.0, status=deferred (host 192.168.9.79[192.168.9.79] said: 451 Error : davmail.exchange.ews.EWSException: ErrorSendAsDenied The user account which was used to submit this request does not have the right to send mail on behalf of the specified sending account. (in reply to end of DATA command))
Aug  9 07:59:28 exchange-relay postfix/smtp[7149]: 0334D780546: to=<my.user@corp.com>, relay=192.168.9.79[192.168.9.79]:1025, conn_use=5, delay=4314, delays=4303/11/0/0.13, dsn=4.0.0, status=deferred (host 192.168.9.79[192.168.9.79] said: 451 Error : davmail.exchange.ews.EWSException: ErrorSendAsDenied The user account which was used to submit this request does not have the right to send mail on behalf of the specified sending account. (in reply to end of DATA command))

which is progress, because I started getting emails routed to my mailbox (but some of them failed).

The successful ones:

Code:

2013-08-09 07:59:18,235 DEBUG [davmail.smtp.SmtpServer] davmail  - Connection from /192.168.9.79 on port 1025
2013-08-09 07:59:23,301 DEBUG [SmtpConnection-40974] davmail.exchange.ExchangeSession  - Test configuration status: 301
2013-08-09 07:59:23,362 DEBUG [SmtpConnection-40974] davmail  - > 220 DavMail 4.3.2-2140-trunk SMTP ready at Fri Aug 09 07:59:23 EEST 2013
2013-08-09 07:59:23,304 DEBUG [SmtpConnection-40972] davmail.exchange.ExchangeSession  - Test configuration status: 301
2013-08-09 07:59:23,362 DEBUG [SmtpConnection-40972] davmail  - > 220 DavMail 4.3.2-2140-trunk SMTP ready at Fri Aug 09 07:59:23 EEST 2013
2013-08-09 07:59:23,304 DEBUG [SmtpConnection-40973] davmail.exchange.ExchangeSession  - Test configuration status: 301
2013-08-09 07:59:23,363 DEBUG [SmtpConnection-40973] davmail  - > 220 DavMail 4.3.2-2140-trunk SMTP ready at Fri Aug 09 07:59:23 EEST 2013
2013-08-09 07:59:23,363 DEBUG [SmtpConnection-40972] davmail  - < EHLO exchange-relay.corp.com
2013-08-09 07:59:23,363 DEBUG [SmtpConnection-40972] davmail  - > 250-exchange-relay.corp.com
2013-08-09 07:59:23,364 DEBUG [SmtpConnection-40972] davmail  - > 250-AUTH LOGIN PLAIN
2013-08-09 07:59:23,364 DEBUG [SmtpConnection-40972] davmail  - > 250-8BITMIME
2013-08-09 07:59:23,364 DEBUG [SmtpConnection-40972] davmail  - > 250 Hello
2013-08-09 07:59:23,364 DEBUG [SmtpConnection-40974] davmail  - < EHLO exchange-relay.corp.com
2013-08-09 07:59:23,364 DEBUG [SmtpConnection-40974] davmail  - > 250-exchange-relay.corp.com
2013-08-09 07:59:23,364 DEBUG [SmtpConnection-40973] davmail  - < EHLO exchange-relay.corp.com
2013-08-09 07:59:23,365 DEBUG [SmtpConnection-40973] davmail  - > 250-exchange-relay.corp.com
2013-08-09 07:59:23,365 DEBUG [SmtpConnection-40974] davmail  - > 250-AUTH LOGIN PLAIN
2013-08-09 07:59:23,365 DEBUG [SmtpConnection-40974] davmail  - > 250-8BITMIME
2013-08-09 07:59:23,365 DEBUG [SmtpConnection-40974] davmail  - > 250 Hello
2013-08-09 07:59:23,365 DEBUG [SmtpConnection-40973] davmail  - > 250-AUTH LOGIN PLAIN
2013-08-09 07:59:23,365 DEBUG [SmtpConnection-40973] davmail  - > 250-8BITMIME
2013-08-09 07:59:23,365 DEBUG [SmtpConnection-40973] davmail  - > 250 Hello
2013-08-09 07:59:23,304 DEBUG [SmtpConnection-40976] davmail.exchange.ExchangeSession  - Test configuration status: 301
...
2013-08-09 07:59:27,337 DEBUG [SmtpConnection-40973] davmail  - > 235 OK Authenticated
2013-08-09 07:59:27,338 DEBUG [SmtpConnection-40973] davmail  - < MAIL FROM:<root@exchange-relay.corp.com> AUTH=<>
2013-08-09 07:59:27,338 DEBUG [SmtpConnection-40973] davmail  - > 250 Sender OK
2013-08-09 07:59:27,338 DEBUG [SmtpConnection-40973] davmail  - < RCPT TO:<my.user@corp.com>
2013-08-09 07:59:27,338 DEBUG [SmtpConnection-40973] davmail  - > 250 Recipient OK
2013-08-09 07:59:27,338 DEBUG [SmtpConnection-40973] davmail  - < DATA
2013-08-09 07:59:27,338 DEBUG [SmtpConnection-40973] davmail  - > 354 Start mail input; end with <CRLF>.<CRLF>

The failed ones:

Code:

 request: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:t="http://schemas.microsoft.com/exchange/services/2006/types" xmlns:m="http://schemas.microsoft.com/exchange/services/2006/messages"><soap:Header><t:RequestServerVersion Version="Exchange2010_SP1"/></soap:Header><soap:Body><m:CreateItem MessageDisposition="SendAndSaveCopy"><m:SavedItemFolderId><t:DistinguishedFolderId Id="sentitems"/></m:SavedItemFolderId><m:Items><t:Message><t:MimeContent>UmVjZWl2ZWQ6IGJ5IGV4Y2hhbmdlLXJlbGF5LmF4cy1vZmZpY2VzLmNvbSAoUG9zdGZpeCwgZnJvbSB1c2VyaWQgODkpDQoJaWQgMTYwOUQ3ODA1NDE7IEZyaSwgIDkgQXVnIDIwMTMgMDU6NDQ6MTcgKzAzMDAgKEVFU1QpDQpSZWNlaXZlZDogYnkgZXhjaGFuZ2UtcmVsYXkuYXhzLW9mZmljZXMuY29tIChQb3N0Zml4LCBmcm9tIHVzZXJpZCA1MDApDQoJaWQgQzUxMUY3ODA0Q0I7IFRodSwgIDggQXVnIDIwMTMgMDU6NTQ6NTggKzAzMDAgKEVFU1QpDQpUbzogYWxleGFuZGVyLnZhc3NpbGV2c2tpQGF4c21hcmluZS5jb20NClN1YmplY3Q6IHRoZSBzdWJqZWN0DQpYLVBIUC1PcmlnaW5hdGluZy1TY3JpcHQ6IDUwMDptLnBocA0KRnJvbTogYWxleGFuZGVyLnZhc3NpbGV2c2tpQGF4cy1vZmZpY2VzLmNvbQ0KUmVwbHktVG86IGFsZXhhbmRlci52YXNzaWxldnNraUBheHNtYXJpbmUuY29tDQpYLU1haWxlcjogUEhQLzUuMy4zDQpNZXNzYWdlLUlkOiA8MjAxMzA4MDgwMzA1MDEuQzUxMUY3ODA0Q0JAZXhjaGFuZ2UtcmVsYXkuYXhzLW9mZmljZXMuY29tPg0KRGF0ZTogVGh1LCAgOCBBdWcgMjAxMyAwNTo1NDo1OCArMDMwMCAoRUVTVCkNCg0KaGVsbG8=</t:MimeContent></t:Message></m:Items></m:CreateItem></soap:Body></soap:Envelope> ErrorSendAsDenied The user account which was used to submit this request does not have the right to send mail on behalf of the specified sending account.
 request: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:t="http://schemas.microsoft.com/exchange/services/2006/types" xmlns:m="http://schemas.microsoft.com/exchange/services/2006/messages"><soap:Header><t:RequestServerVersion Version="Exchange2010_SP1"/></soap:Header><soap:Body><m:CreateItem MessageDisposition="SendAndSaveCopy"><m:SavedItemFolderId><t:DistinguishedFolderId Id="sentitems"/></m:SavedItemFolderId><m:Items><t:Message><t:MimeContent>UmVjZWl2ZWQ6IGJ5IGV4Y2hhbmdlLXJlbGF5LmF4cy1vZmZpY2VzLmNvbSAoUG9zdGZpeCwgZnJvbSB1c2VyaWQgODkpDQoJaWQgMTYwOUQ3ODA1NDE7IEZyaSwgIDkgQXVnIDIwMTMgMDU6NDQ6MTcgKzAzMDAgKEVFU1QpDQpSZWNlaXZlZDogYnkgZXhjaGFuZ2UtcmVsYXkuYXhzLW9mZmljZXMuY29tIChQb3N0Zml4LCBmcm9tIHVzZXJpZCA1MDApDQoJaWQgQzUxMUY3ODA0Q0I7IFRodSwgIDggQXVnIDIwMTMgMDU6NTQ6NTggKzAzMDAgKEVFU1QpDQpUbzogYWxleGFuZGVyLnZhc3NpbGV2c2tpQGF4c21hcmluZS5jb20NClN1YmplY3Q6IHRoZSBzdWJqZWN0DQpYLVBIUC1PcmlnaW5hdGluZy1TY3JpcHQ6IDUwMDptLnBocA0KRnJvbTogYWxleGFuZGVyLnZhc3NpbGV2c2tpQGF4cy1vZmZpY2VzLmNvbQ0KUmVwbHktVG86IGFsZXhhbmRlci52YXNzaWxldnNraUBheHNtYXJpbmUuY29tDQpYLU1haWxlcjogUEhQLzUuMy4zDQpNZXNzYWdlLUlkOiA8MjAxMzA4MDgwMzA1MDEuQzUxMUY3ODA0Q0JAZXhjaGFuZ2UtcmVsYXkuYXhzLW9mZmljZXMuY29tPg0KRGF0ZTogVGh1LCAgOCBBdWcgMjAxMyAwNTo1NDo1OCArMDMwMCAoRUVTVCkNCg0KaGVsbG8=</t:MimeContent></t:Message></m:Items></m:CreateItem></soap:Body></soap:Envelope>
2013-08-09 07:59:27,519 DEBUG [SmtpConnection-40973] davmail  - < QUIT
2013-08-09 07:59:27,520 DEBUG [SmtpConnection-40973] davmail  - > 221 Closing connection
2013-08-09 07:59:27,524 DEBUG [SmtpConnection-40976] davmail  - < QUIT
2013-08-09 07:59:27,544 DEBUG [SmtpConnection-40976] davmail  - > 221 Closing connection
2013-08-09 07:59:27,534 DEBUG [davmail.smtp.SmtpServer] davmail  - Connection from /192.168.9.79 on port 1025
2013-08-09 07:59:27,532 DEBUG [SmtpConnection-40975] davmail  - < QUIT
2013-08-09 07:59:27,546 DEBUG [SmtpConnection-40975] davmail  - > 221 Closing connection
2013-08-09 07:59:27,525 DEBUG [SmtpConnection-40974] davmail  - < QUIT
2013-08-09 07:59:27,546 DEBUG [SmtpConnection-40974] davmail  - > 221 Closing connection

sasheto86 · 08-09-2013, 09:19 AM

I found the problem with the bounced mails - it was a problem in the script ( the from address was not legit )

I think I've resolved my own problem, so I'll update the thread with this.