[exim-dev] [Bug 2819] New: /usr/sbin/sendmail interface inef…

Top Page

Reply to this message
Author: admin
Date:  
To: exim-dev
New-Topics: [exim-dev] [Bug 2819] command line inefficient at mail submission, [exim-dev] [Bug 2819] command line inefficient at mail submission, [exim-dev] [Bug 2819] command line inefficient at mail submission, [exim-dev] [Bug 2819] /usr/sbin/sendmail interface inefficient at reading, [exim-dev] [Bug 2819] command line inefficient at mail submission, [exim-dev] [Bug 2819] command line inefficient at mail submission, [exim-dev] [Bug 2819] command line inefficient at mail submission, [exim-dev] [Bug 2819] command line inefficient at mail submission
Subject: [exim-dev] [Bug 2819] New: /usr/sbin/sendmail interface inefficient at reading mail
https://bugs.exim.org/show_bug.cgi?id=2819

            Bug ID: 2819
           Summary: /usr/sbin/sendmail interface inefficient at reading
                    mail
           Product: Exim
           Version: 4.95
          Hardware: x86
               URL: https://bugs.debian.org/996282
                OS: Linux
            Status: NEW
          Severity: bug
          Priority: medium
         Component: Delivery in general
          Assignee: unallocated@???
          Reporter: eximusers@???
                CC: exim-dev@???


Hello,

this was reported by Samuel Thibault in the Debian BTS:

TL;DR:
Sending a large mail through /usr/sbin/sendmail takes a *very* long
time. Setting receive_timeout to 10m makes the send immediate.

Stracing sendmail gives:

select(1, [0], NULL, NULL, {tv_sec=1692, tv_usec=0}) = 1 (in [0], left
{tv_sec=1691, tv_usec=999977})
gettimeofday({tv_sec=1634067536, tv_usec=599153}, NULL) = 0
select(1, [0], NULL, NULL, {tv_sec=1692, tv_usec=0}) = 1 (in [0], left
{tv_sec=1691, tv_usec=999983})
gettimeofday({tv_sec=1634067536, tv_usec=599463}, NULL) = 0
select(1, [0], NULL, NULL, {tv_sec=1692, tv_usec=0}) = 1 (in [0], left
{tv_sec=1691, tv_usec=999977})
gettimeofday({tv_sec=1634067536, tv_usec=599768}, NULL) = 0
select(1, [0], NULL, NULL, {tv_sec=1692, tv_usec=0}) = 1 (in [0], left
{tv_sec=1691, tv_usec=999977})
gettimeofday({tv_sec=1634067536, tv_usec=600085}, NULL) = 0
[...]

i.e. sendmail keeps calling gettimeofday/select ad nauseam. Filtering
them out gives (yes my test mail is just composed of 'a' letters):

22:19:32 write(3, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096
22:19:32 read(0, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096
22:19:34 write(3, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096
22:19:34 read(0, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096
22:19:35 write(3, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096
22:19:35 read(0, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096

I.e. a speed of only a few kilobytes per second. I had a look at gdb,
and saw the following backtrace:

(gdb) bt
#0  __GI___select (nfds=nfds@entry=1, readfds=readfds@entry=0x7fffeb849230,
writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0,
    timeout=timeout@entry=0x7fffeb849220) at
../sysdeps/unix/sysv/linux/select.c:39
#1  0x000055f49ce40c4d in log_close_chk () at receive.c:602
#2  0x000055f49ce43f15 in log_close_chk () at receive.c:699
#3  read_message_data (fout=<optimized out>) at receive.c:663
#4  receive_msg (extract_recip=extract_recip@entry=0) at receive.c:3167
#5  0x000055f49cde5061 in main (argc=7, cargv=<optimized out>) at exim.c:5706


log_close_chk indeed calls gettimeofday and select(), and it happens
that read_message_data() is like this:

  for ( ;
       log_close_chk(), (ch = (receive_getc)(GETC_BUFFER_UNLIMITED)) != EOF;
       last_ch = ch)


{ [...] }

i.e. gettimeofday + select get called at each receive_getc() call, i.e.
for each and every character of the mail...

Fortunately, log_close_chk does not have this behavior when
receive_timeout is defined, so by setting it to 10m, the
gettimeofday+select calls are disabled, making sending mails just
immediate as expected, but that's only a workaround.

Samuel

--
You are receiving this mail because:
You are on the CC list for the bug.