Dovecot v2.3.8 released

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
10 messages Options
Reply | Threaded
Open this post in threaded view
|

Dovecot v2.3.8 released

Dovecot mailing list
https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz
https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz.sig
Binary packages in https://repo.dovecot.org/

Changes

+ Added mail_delivery_started and mail_delivery_finished events, see
https://doc.dovecot.org/admin_manual/list_of_events/ for details.
+ dsync-replication: Don't replicate users who have "noreplicate" extra
field in userdb.
+ doveadm service status: Show total number of processes created.
+ When logging to syslog, use instance_name setting's value for the
ident. This commonly is added as a log prefix.
+ Base64 encoding/decoding code was rewritten with additional features.
It shouldn't cause any user visible changes.
- v2.3.7 regression: If a folder only receives new mails without any
other mail access, dovecot.index.log keeps growing forever and
dovecot.index keeps being rewritten for every mail delivery.
- dsync-replication may lose keywords after syncing mails restored from
another replica. This only happened if the mail only had keywords and no
system flags.
- event filters: Non-textual event fields could not be filtered using
wildcards.
- auth: Scope parameter was missing from OAuth password grant request.
- doveadm client-server communication may hang in some situations. It is
also using unnecessarily small TCP/IP packet sizes.
- doveadm who and kick did not flush protocol output correctly.
- imap: SETMETADATA with literal value would delete the metadata value
instead of updating it.
- imap: When client issues FETCH PREVIEW (LAZY=FUZZY) command, the
caching decisions should be updated so that newly saved mails will have
the preview cached.
- With mail_nfs_index=yes and/or mail_nfs_storage=yes setuid/setgid
permission bits in some files may have become dropped with some NFS
servers. Changed NFS flushing to now use chmod() instead of chown().
- quota: warnings did not work if quota root was noenforcing
- acl: Global ACL file ignored the last line if it didn't end with LF.
- doveadm stats dump: With JSON formatter output numbers using the
number type instead of as strings
- lmtp_proxy: Ensure that real_* variables are correctly set when using
lmtp_proxy.
- event exporter: http-post driver had hardcoded timeout and did not
support DNS lookups or TLS connections.
- auth: Fix user iteration to work with userdb passwd with glibc v2.28.
- auth: auth service can crash if auth-policy JSON response is invalid
or returned too fast.
- In some rare situations "ps" output could have shown a lot of "?"
characters after Dovecot process titles.
- When dovecot.index.pvt is empty, an unnecessary error is logged:
  Error: .../dovecot.index.pvt reset, view is now inconsistent
- SMTP address encoder duplicated initial double quote character when
the localpart of an address ended in '..'. For example
"[hidden email]" became ""user+.."@example.com in a
  sieve redirect.

---
Aki Tuomi
Open-Xchange Oy


signature.asc (499 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list
Am Tue, 08 Oct 2019 14:18:14 +0300 schrieb Aki Tuomi via dovecot:

> https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz
> https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz.sig Binary
> packages in https://repo.dovecot.org/

Hi,

this commit

https://github.com/dovecot/core/commit/
cebaac29a31fba40ce570c8668dddb15e5e22c87#diff-441ae8b2b019c411b6b4adb26efbaa63R48

causes a build error:

libtool: link: /home/bernd/buildroot/br6/output/host/bin/x86_64-linux-gcc
-std=gnu99 -D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -
D_FILE_OFFSET_BITS=64 -Os -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=2 -
mfunction-return=thunk -mindirect-branch=thunk -Wall -W -Wmissing-
prototypes -Wmissing-declarations -Wpointer-arith -Wchar-subscripts -
Wformat=2 -Wbad-function-cast -fno-builtin-strftime -Wstrict-aliasing=2 -
I/home/bernd/buildroot/br6/output/host/bin/../x86_64-buildroot-linux-
uclibc/sysroot/usr/include -static -o test-iostream-ssl test-iostream-
ssl.o  ./.libs/libssl_iostream_openssl.so -L/home/bernd/buildroot/br6/
output/host/bin/../x86_64-buildroot-linux-uclibc/sysroot/usr/
lib64 ./.libs/libssl_iostream.a ../lib-test/.libs/libtest.a ../lib/.libs/
liblib.a -lssl -lcrypto -Wl,-rpath -Wl,/home/bernd/buildroot/br6/output/
build/dovecot-2.3.8/src/lib-ssl-iostream/.libs -Wl,-rpath -Wl,/usr/lib/
dovecot

/home/bernd/buildroot/br6/output/host/opt/ext-toolchain/bin/../lib/gcc/
x86_64-buildroot-linux-uclibc/7.4.0/../../../../x86_64-buildroot-linux-
uclibc/bin/ld: attempted static link of dynamic object `./.libs/
libssl_iostream_openssl.so'

Removing "-static" fixes the problem.

Regards, Bernd

Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list
In reply to this post by Dovecot mailing list
On 2019-10-08 13:18, Aki Tuomi via dovecot wrote:
> https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz
> https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz.sig
> Binary packages in https://repo.dovecot.org/

> - imap: SETMETADATA with literal value would delete the metadata value
> instead of updating it.
> - imap: When client issues FETCH PREVIEW (LAZY=FUZZY) command, the
> caching decisions should be updated so that newly saved mails will have
> the preview cached.
> - With mail_nfs_index=yes and/or mail_nfs_storage=yes setuid/setgid
> permission bits in some files may have become dropped with some NFS
> servers. Changed NFS flushing to now use chmod() instead of chown().

I am seeing a lot of errors since the upgrade, on multiple client
accounts:

Info: Connection closed: read(size=7902) failed: Connection reset by
peer (UID FETCH running for 0.242 + waiting input/output for 108.816
secs, 60 B in + 24780576+8192 B out, state=wait-output)

Using NFS storage (not running with the mail_nfs_index or
mail_nfs_storage)

Was something changed in terms of IO/Idle timeouts?

Tried doing reindex/resync, but did not help.

--
Tom
Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list


On 2019-10-18 13:25, Tom Sommer via dovecot wrote:

> I am seeing a lot of errors since the upgrade, on multiple client
> accounts:
>
> Info: Connection closed: read(size=7902) failed: Connection reset by
> peer (UID FETCH running for 0.242 + waiting input/output for 108.816
> secs, 60 B in + 24780576+8192 B out, state=wait-output)
>
> Using NFS storage (not running with the mail_nfs_index or
> mail_nfs_storage)
>
> Was something changed in terms of IO/Idle timeouts?

We are also seeing different I/O patterns since the upgrade, more I/O is
being used than normal.

This is mail_debug from one of the accounts in question:

Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17854: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17854: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17855: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17855: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17856: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17856: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17857: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17857: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17858: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17858: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17859: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17859: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17860: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17860: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17861: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17861: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17862: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17862: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17863: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17863: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17864: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17864: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17865: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17865: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17866: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17866: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17867: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17867: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17868: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17868: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17869: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17869: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17870: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17870: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17871: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17871: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17872: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17872: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17873: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17873: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17874: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17874: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17875: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17875: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17876: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17876: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17877: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17877: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17878: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17878: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17879: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17879: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17880: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17880: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17881: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17881: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17882: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17882: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17883: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17883: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17884: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17884: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17885: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17885: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17886: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17886: Opened mail because: full mail
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17887: Opened mail because: prefetch
Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17887: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17888: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17888: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17889: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17889: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17890: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17890: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17891: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17891: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17892: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17892: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17893: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17893: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17894: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17894: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17895: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17895: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17896: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17896: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17897: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17897: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17898: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17898: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17899: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17899: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17900: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17900: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17901: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17901: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17902: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17902: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17903: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17903: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17904: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17904: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17905: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17905: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17906: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17906: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17907: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17907: Opened mail because: full mail
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17908: Opened mail because: prefetch
Oct 18 13:39:41 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17908: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17909: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17909: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17910: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17910: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17911: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17911: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17912: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17912: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17913: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17913: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17914: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17914: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17915: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17915: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17916: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17916: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17917: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17917: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17918: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17918: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17919: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17919: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17920: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17920: Opened mail because: full mail
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17921: Opened mail because: prefetch
Oct 18 13:39:43 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17921: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17922: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17922: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17923: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17923: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17924: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17924: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17925: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17925: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17926: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17926: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17927: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17927: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17928: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17928: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17929: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17929: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17930: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17930: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17931: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17931: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17932: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17932: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17933: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17933: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17934: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17934: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17935: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17935: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17936: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17936: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17937: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17937: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17938: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17938: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17939: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17939: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17940: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17940: Opened mail because: full mail
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17941: Opened mail because: prefetch
Oct 18 13:39:46 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17941: Opened mail because: full mail
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17942: Opened mail because: prefetch
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17942: Opened mail because: full mail
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17943: Opened mail because: prefetch
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17943: Opened mail because: full mail
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17944: Opened mail because: prefetch
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17944: Opened mail because: full mail
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17945: Opened mail because: prefetch
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17945: Opened mail because: full mail
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17946: Opened mail because: prefetch
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17946: Opened mail because: full mail
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17947: Opened mail because: prefetch
Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
INBOX: UID 17947: Opened mail because: full mail
Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox Junk:
Mailbox opened because: autoexpunge
Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox Junk
E-mail: Mailbox opened because: autoexpunge
Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Info: Connection
closed: read(size=7902) failed: Connection reset by peer (UID FETCH
running for 0.542 + waiting input/output for 78.357 secs, 60 B in +
39221480+8192 B out, state=wait-output) in=290 out=39401283 deleted=0
expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=94
body_bytes=39210315
Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list
In reply to this post by Dovecot mailing list

> On 18/10/2019 14:25 Tom Sommer via dovecot <[hidden email]> wrote:
>
>  
> On 2019-10-08 13:18, Aki Tuomi via dovecot wrote:
> > https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz
> > https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz.sig
> > Binary packages in https://repo.dovecot.org/
>
> > - imap: SETMETADATA with literal value would delete the metadata value
> > instead of updating it.
> > - imap: When client issues FETCH PREVIEW (LAZY=FUZZY) command, the
> > caching decisions should be updated so that newly saved mails will have
> > the preview cached.
> > - With mail_nfs_index=yes and/or mail_nfs_storage=yes setuid/setgid
> > permission bits in some files may have become dropped with some NFS
> > servers. Changed NFS flushing to now use chmod() instead of chown().
>
> I am seeing a lot of errors since the upgrade, on multiple client
> accounts:
>
> Info: Connection closed: read(size=7902) failed: Connection reset by
> peer (UID FETCH running for 0.242 + waiting input/output for 108.816
> secs, 60 B in + 24780576+8192 B out, state=wait-output)
>

This is not actually an error, it's indicating that the remote end disconnected mid-command.

Aki
Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list


On 2019-10-18 14:55, Aki Tuomi via dovecot wrote:

>> On 18/10/2019 14:25 Tom Sommer via dovecot <[hidden email]>
>> wrote:
>>
>>
>> On 2019-10-08 13:18, Aki Tuomi via dovecot wrote:
>> > https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz
>> > https://dovecot.org/releases/2.3/dovecot-2.3.8.tar.gz.sig
>> > Binary packages in https://repo.dovecot.org/
>>
>> > - imap: SETMETADATA with literal value would delete the metadata value
>> > instead of updating it.
>> > - imap: When client issues FETCH PREVIEW (LAZY=FUZZY) command, the
>> > caching decisions should be updated so that newly saved mails will have
>> > the preview cached.
>> > - With mail_nfs_index=yes and/or mail_nfs_storage=yes setuid/setgid
>> > permission bits in some files may have become dropped with some NFS
>> > servers. Changed NFS flushing to now use chmod() instead of chown().
>>
>> I am seeing a lot of errors since the upgrade, on multiple client
>> accounts:
>>
>> Info: Connection closed: read(size=7902) failed: Connection reset by
>> peer (UID FETCH running for 0.242 + waiting input/output for 108.816
>> secs, 60 B in + 24780576+8192 B out, state=wait-output)
>>
>
> This is not actually an error, it's indicating that the remote end
> disconnected mid-command.

Right, but this a symptom of the increased IO and thus latency in 2.3.8,
so the client disconnects while waiting for a response?

---
Tom
Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list
In reply to this post by Dovecot mailing list

> On 18 Oct 2019, at 13.43, Tom Sommer via dovecot <[hidden email]> wrote:
>
>> I am seeing a lot of errors since the upgrade, on multiple client accounts:
>> Info: Connection closed: read(size=7902) failed: Connection reset by
>> peer (UID FETCH running for 0.242 + waiting input/output for 108.816
>> secs, 60 B in + 24780576+8192 B out, state=wait-output)
>> Using NFS storage (not running with the mail_nfs_index or mail_nfs_storage)
>> Was something changed in terms of IO/Idle timeouts?
>
> We are also seeing different I/O patterns since the upgrade, more I/O is being used than normal.

What was the previous version you were running?

> This is mail_debug from one of the accounts in question:
>
> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: Mailbox opened because: SELECT
> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: UID 17854: Opened mail because: prefetch
> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: UID 17854: Opened mail because: full mail
..
> Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: UID 17947: Opened mail because: full mail

Quite a lot of mail downloads for a single session. I wonder if the user really had that many new mails or if they were being redownloaded for some reason?

> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox Junk: Mailbox opened because: autoexpunge
> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox Junk E-mail: Mailbox opened because: autoexpunge
> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Info: Connection closed: read(size=7902) failed: Connection reset by peer (UID FETCH running for 0.542 + waiting input/output for 78.357 secs, 60 B in + 39221480+8192 B out, state=wait-output) in=290 out=39401283 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=94 body_bytes=39210315

state=wait-output means Dovecot was waiting for client to read the data it is sending. In v2.3.7 there was some changes related to this, but were you previously successfully running v2.3.7? In v2.3.8 I can't really think of such changes.

Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list

On 2019-10-20 11:30, Timo Sirainen via dovecot wrote:

>> On 18 Oct 2019, at 13.43, Tom Sommer via dovecot <[hidden email]>
>> wrote:
>>
>>> I am seeing a lot of errors since the upgrade, on multiple client
>>> accounts:
>>> Info: Connection closed: read(size=7902) failed: Connection reset by
>>> peer (UID FETCH running for 0.242 + waiting input/output for 108.816
>>> secs, 60 B in + 24780576+8192 B out, state=wait-output)
>>> Using NFS storage (not running with the mail_nfs_index or
>>> mail_nfs_storage)
>>> Was something changed in terms of IO/Idle timeouts?
>>
>> We are also seeing different I/O patterns since the upgrade, more I/O
>> is being used than normal.
>
> What was the previous version you were running?

2.3.7.2

>> This is mail_debug from one of the accounts in question:
>>
>> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> INBOX: Mailbox opened because: SELECT
>> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> INBOX: UID 17854: Opened mail because: prefetch
>> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> INBOX: UID 17854: Opened mail because: full mail
> ..
>> Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> INBOX: UID 17947: Opened mail because: full mail
>
> Quite a lot of mail downloads for a single session. I wonder if the
> user really had that many new mails or if they were being redownloaded
> for some reason?

They might redownload because of UID FETCH failing?

>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> Junk: Mailbox opened because: autoexpunge
>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> Junk E-mail: Mailbox opened because: autoexpunge
>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Info: Connection
>> closed: read(size=7902) failed: Connection reset by peer (UID FETCH
>> running for 0.542 + waiting input/output for 78.357 secs, 60 B in +
>> 39221480+8192 B out, state=wait-output) in=290 out=39401283 deleted=0
>> expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=94
>> body_bytes=39210315
>
> state=wait-output means Dovecot was waiting for client to read the
> data it is sending. In v2.3.7 there was some changes related to this,
> but were you previously successfully running v2.3.7? In v2.3.8 I can't
> really think of such changes.

Yes, we were successfully running 2.3.7.2 before, the issue started just
after the upgrade

It can't be related to changes in the indexes? Increasing I/O

There were no input/output errors in the logs prior to 2.3.8

---
Tom
Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list
On 20 Oct 2019, at 11.37, Tom Sommer via dovecot <[hidden email]> wrote:

>
>>> This is mail_debug from one of the accounts in question:
>>> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: Mailbox opened because: SELECT
>>> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: UID 17854: Opened mail because: prefetch
>>> Oct 18 13:39:37 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: UID 17854: Opened mail because: full mail
>> ..
>>> Oct 18 13:39:48 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox INBOX: UID 17947: Opened mail because: full mail
>> Quite a lot of mail downloads for a single session. I wonder if the
>> user really had that many new mails or if they were being redownloaded
>> for some reason?
>
> They might redownload because of UID FETCH failing?

The client successfully downloaded all but the last mail. So it should be redownloading only the latest one, not all of them. (I don't think there are any clients stupid enough to redownload everything..)

>>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox Junk: Mailbox opened because: autoexpunge
>>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox Junk E-mail: Mailbox opened because: autoexpunge
>>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Info: Connection closed: read(size=7902) failed: Connection reset by peer (UID FETCH running for 0.542 + waiting input/output for 78.357 secs, 60 B in + 39221480+8192 B out, state=wait-output) in=290 out=39401283 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=94 body_bytes=39210315
>> state=wait-output means Dovecot was waiting for client to read the
>> data it is sending. In v2.3.7 there was some changes related to this,
>> but were you previously successfully running v2.3.7? In v2.3.8 I can't
>> really think of such changes.
>
> Yes, we were successfully running 2.3.7.2 before, the issue started just after the upgrade
>
> It can't be related to changes in the indexes? Increasing I/O
>
> There were no input/output errors in the logs prior to 2.3.8

How large are the IO latencies now and before? The IO wait% in e.g. iostat? And load average in general?

I can't see any reason for IO to be different in v2.3.8 than v2.3.7. The only thing even close to it is the one index file bugfix. I did some further testing with it and I can't see it doing any more work now than it used to.

Reply | Threaded
Open this post in threaded view
|

Re: Dovecot v2.3.8 released

Dovecot mailing list
In reply to this post by Dovecot mailing list

On 2019-10-20 11:30, Timo Sirainen via dovecot wrote:
>> On 18 Oct 2019, at 13.43, Tom Sommer via dovecot <[hidden email]>
>> wrote:

> Quite a lot of mail downloads for a single session. I wonder if the
> user really had that many new mails or if they were being redownloaded
> for some reason?
>
>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> Junk: Mailbox opened because: autoexpunge
>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Debug: Mailbox
>> Junk E-mail: Mailbox opened because: autoexpunge
>> Oct 18 13:40:56 imap(XXXX)<7552><ebbmyS2VPPFOxv4t>: Info: Connection
>> closed: read(size=7902) failed: Connection reset by peer (UID FETCH
>> running for 0.542 + waiting input/output for 78.357 secs, 60 B in +
>> 39221480+8192 B out, state=wait-output) in=290 out=39401283 deleted=0
>> expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=94
>> body_bytes=39210315
>
> state=wait-output means Dovecot was waiting for client to read the
> data it is sending.

This made me think it might be a connection (TCP/IP) thing.

My Director is running with 3 listen-IPs, I removed two of them and this
appeared to have made the errors stop.

Unsure if anything was changed in this regard between 2.3.7.2 and 2.3.8.

---
Tom