Arkadiusz Miśkiewicz
2018-Mar-22 21:33 UTC
lmtp service timeouting even after receiving full message
I have a problem with some messages passed from exim to dovecot lmtp service:
From exim debug:
using socket /var/run/dovecot/lmtp
LMTP<< 220 mbox8 ready
LMTP>> LHLO mbox8...
LMTP<< 250-mbox8
LMTP<< 250-STARTTLS
LMTP<< 250-8BITMIME
LMTP<< 250-ENHANCEDSTATUSCODES
LMTP<< 250 PIPELINING
LMTP>> MAIL FROM:...
LMTP<< 250 2.1.0 OK
LMTP>> RCPT TO:...
LMTP<< 250 2.1.5 OK
LMTP>> DATA
LMTP<< 354 OK
LMTP>> writing message and terminating "."
cannot use sendfile for body: terminating dot wanted
writing data block fd=6 size=6585 timeout=300
LMTP>> QUIT
LMTP<< 421 4.4.2 mbox8 Disconnected client for inactivity
now above "writting message and terminating" according to exim strace
looks like this:
13413 22:07:24 write(2, " LMTP>> writing message and terminating
\".\"\n", 45) = 45 <0.000018>
13413 22:07:24 stat("/etc/localtime", {st_mode=S_IFREG|0644,
st_size=2705, ...}) = 0 <0.000025>
13413 22:07:24 write(2, "cannot use sendfile for body: terminating dot
wanted\n", 53) = 53 <0.000022>
13413 22:07:24 lseek(3, 19, SEEK_SET) = 19 <0.000015>
[...]
13413 22:07:24 write(2, "writing data block fd=6 size=6585
timeout=300\n", 46) = 46 <0.000019>
13413 22:07:24 alarm(300) = 0 <0.000013>
13413 22:07:24 write(6, "Return-path:
[...]
\nwrap\"><br></span></div>.\n", 6585) = 6585
<0.000023>
and then exim waits for dovecot lmtp to say it accepted message but lmtp never
does that.
Isn't .\n always enough for dovecot to signal end of message? Because exim
wrote full message
to dovecot lmtp unix socket.
Now the interesting this - exim does only one write() with 6585 bytes to write
that message to lmtp.
If exim needs more than one write() to do that (message is larger by some
buffer) then it succeeds,
dovecot accepts it.
Could dovecot lmtp handling for single write() case be broken?
dovecot 2.2.35
--
Arkadiusz Mi?kiewicz, arekm / ( maven.pl | pld-linux.org )
Arkadiusz Miśkiewicz
2018-Mar-23 08:04 UTC
lmtp service timeouting even after receiving full message
On Thursday 22 of March 2018, Arkadiusz Mi?kiewicz wrote:> I have a problem with some messages passed from exim to dovecot lmtp > service: > > From exim debug: > > using socket /var/run/dovecot/lmtp > LMTP<< 220 mbox8 ready > LMTP>> LHLO mbox8... > LMTP<< 250-mbox8 > LMTP<< 250-STARTTLS > LMTP<< 250-8BITMIME > LMTP<< 250-ENHANCEDSTATUSCODES > LMTP<< 250 PIPELINING > LMTP>> MAIL FROM:... > LMTP<< 250 2.1.0 OK > LMTP>> RCPT TO:... > LMTP<< 250 2.1.5 OK > LMTP>> DATA > LMTP<< 354 OK > LMTP>> writing message and terminating "." > cannot use sendfile for body: terminating dot wanted > writing data block fd=6 size=6585 timeout=300 > LMTP>> QUIT > LMTP<< 421 4.4.2 mbox8 Disconnected client for inactivity > > > now above "writting message and terminating" according to exim strace looks > like this: > > 13413 22:07:24 write(2, " LMTP>> writing message and terminating \".\"\n", > 45) = 45 <0.000018> 13413 22:07:24 stat("/etc/localtime", > {st_mode=S_IFREG|0644, st_size=2705, ...}) = 0 <0.000025> 13413 22:07:24 > write(2, "cannot use sendfile for body: terminating dot wanted\n", 53) > 53 <0.000022> 13413 22:07:24 lseek(3, 19, SEEK_SET) = 19 <0.000015> > [...] > 13413 22:07:24 write(2, "writing data block fd=6 size=6585 timeout=300\n", > 46) = 46 <0.000019> 13413 22:07:24 alarm(300) = 0 <0.000013> > 13413 22:07:24 write(6, "Return-path: > [...] > \nwrap\"><br></span></div>.\n", 6585) = 6585 <0.000023> > > and then exim waits for dovecot lmtp to say it accepted message but lmtp > never does that. > > Isn't .\n always enough for dovecot to signal end of message? Because exim > wrote full message to dovecot lmtp unix socket. > > Now the interesting this - exim does only one write() with 6585 bytes to > write that message to lmtp. If exim needs more than one write() to do that > (message is larger by some buffer) then it succeeds, dovecot accepts it. > > Could dovecot lmtp handling for single write() case be broken? > > dovecot 2.2.35And reproducer. Both messages have ".\n" as ending but one has \r\n before it. #!/usr/bin/python3 import socket c = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) c.connect("/var/run/dovecot/lmtp") print(c.recv(1024)) print("LHLO") c.send(b"LHLO mbox8\r\n") print(c.recv(1024)) print("MAIL FROM") c.send(b"MAIL FROM:<someone at example.com>\r\n") print(c.recv(1024)) print("RCPT TO") c.send(b"RCPT TO:<arekm at example.com>\r\n") print(c.recv(1024)) print("DATA") c.send(b"DATA\r\n") print(c.recv(1024)) print("body...") msg_fail = b"testtest<br></span></div>.\n" msg_ok = b"01, 41.82, 30.14\r\n.\n" #c.send(msg_ok) c.send(msg_fail) print(c.recv(1024)) c.close() -- Arkadiusz Mi?kiewicz, arekm / ( maven.pl | pld-linux.org )
On 23.03.2018 10:04, Arkadiusz Mi?kiewicz wrote:> On Thursday 22 of March 2018, Arkadiusz Mi?kiewicz wrote: >> I have a problem with some messages passed from exim to dovecot lmtp >> service: >> >> From exim debug: >> >> using socket /var/run/dovecot/lmtp >> LMTP<< 220 mbox8 ready >> LMTP>> LHLO mbox8... >> LMTP<< 250-mbox8 >> LMTP<< 250-STARTTLS >> LMTP<< 250-8BITMIME >> LMTP<< 250-ENHANCEDSTATUSCODES >> LMTP<< 250 PIPELINING >> LMTP>> MAIL FROM:... >> LMTP<< 250 2.1.0 OK >> LMTP>> RCPT TO:... >> LMTP<< 250 2.1.5 OK >> LMTP>> DATA >> LMTP<< 354 OK >> LMTP>> writing message and terminating "." >> cannot use sendfile for body: terminating dot wanted >> writing data block fd=6 size=6585 timeout=300 >> LMTP>> QUIT >> LMTP<< 421 4.4.2 mbox8 Disconnected client for inactivity >> >> >> now above "writting message and terminating" according to exim strace looks >> like this: >> >> 13413 22:07:24 write(2, " LMTP>> writing message and terminating \".\"\n", >> 45) = 45 <0.000018> 13413 22:07:24 stat("/etc/localtime", >> {st_mode=S_IFREG|0644, st_size=2705, ...}) = 0 <0.000025> 13413 22:07:24 >> write(2, "cannot use sendfile for body: terminating dot wanted\n", 53) >> 53 <0.000022> 13413 22:07:24 lseek(3, 19, SEEK_SET) = 19 <0.000015> >> [...] >> 13413 22:07:24 write(2, "writing data block fd=6 size=6585 timeout=300\n", >> 46) = 46 <0.000019> 13413 22:07:24 alarm(300) = 0 <0.000013> >> 13413 22:07:24 write(6, "Return-path: >> [...] >> \nwrap\"><br></span></div>.\n", 6585) = 6585 <0.000023> >> >> and then exim waits for dovecot lmtp to say it accepted message but lmtp >> never does that. >> >> Isn't .\n always enough for dovecot to signal end of message? Because exim >> wrote full message to dovecot lmtp unix socket. >> >> Now the interesting this - exim does only one write() with 6585 bytes to >> write that message to lmtp. If exim needs more than one write() to do that >> (message is larger by some buffer) then it succeeds, dovecot accepts it. >> >> Could dovecot lmtp handling for single write() case be broken? >> >> dovecot 2.2.35 > And reproducer. Both messages have ".\n" as ending but one has \r\n before it. > > #!/usr/bin/python3 > > import socket > > c = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) > c.connect("/var/run/dovecot/lmtp") > print(c.recv(1024)) > print("LHLO") > c.send(b"LHLO mbox8\r\n") > print(c.recv(1024)) > print("MAIL FROM") > c.send(b"MAIL FROM:<someone at example.com>\r\n") > print(c.recv(1024)) > print("RCPT TO") > c.send(b"RCPT TO:<arekm at example.com>\r\n") > print(c.recv(1024)) > print("DATA") > c.send(b"DATA\r\n") > print(c.recv(1024)) > print("body...") > > msg_fail = b"testtest<br></span></div>.\n" > msg_ok = b"01, 41.82, 30.14\r\n.\n" > > #c.send(msg_ok) > c.send(msg_fail) > > print(c.recv(1024)) > > c.close() >Shouldn't the last dot be own it's own line? Aki