dovecot - Nov 2019 - IMAP session hangs on 8k-long commands if COMPRESS=DEFLATE is enabled

Hi there,

Dovecot 2.3.7 appears to hang when the client sends a long command after
enabling the IMAP COMPRESS extension [RFC 4978].  PoC script attached
along with the doveconf(1) output.

Without COMPRESS=DEFLATE, and with the default ?imap_max_line_length?
value (64k) I'm able send commands up to 65539 bytes long (that's 3
bytes more than 2??, so maybe the leading tag and the trailing CRLF
aren't counted), after which Dovecot rightfully replies with tagged BAD
responses.

    $ COMPRESS=n /tmp/many-fetch.pl 65539
    [?]
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[65539 bytes]
    S: x OK Fetch completed (0.005 + 0.001 + 0.004 secs).
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[65540 bytes]
    S: x BAD Error in IMAP command UID FETCH: IMAP command line too large (0.001
+ 0.001 secs).
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[65541 bytes]
    S: x BAD Error in IMAP command UID FETCH: IMAP command line too large (0.001
+ 0.001 secs).

With COMPRESS=DEFLATE however, the server never sends anything back when
the command size exceeds 8192 bytes:

    $ COMPRESS=y /tmp/many-fetch.pl 8192
    [?]
    S: x OK [READ-ONLY] Examine completed (0.001 + 0.000 secs).
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,? [8191
bytes]
    S: x OK Fetch completed (0.001 + 0.000 secs).
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,? [8192
bytes]
    S: x OK Fetch completed (0.001 + 0.000 secs).
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,? [8193
bytes]
    [ _hangs until the server terminates the session for inactivity_ ]
    S: * BYE Disconnected for inactivity.

strace(1) show that Dovecot didn't send the response, even though the
server log indicates that it's able to fully read the command.

Interestingly, when setting ?imap_max_line_length? to 4096, the server
also hangs after receiving a command of size >4096 bytes (instead of
replying with a tagged BAD response).

    $ COMPRESS=y /tmp/many-fetch.pl 4096
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,? [4095
bytes]
    S: x OK Fetch completed (0.001 + 0.000 secs).
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,? [4096
bytes]
    S: x OK Fetch completed (0.001 + 0.000 secs).
    C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,? [4097
bytes]
    [ _hangs until the server terminates the session for inactivity_ ]

I'm also able to reproduce the buggy behavior against Dovecot versions
found in other Debian releases.  It's identical with 2.3.4 (Buster), the
server also hang past 8192 bytes.  2.2.27 (Stretch) and 2.2.13 (Jessie)
are able to send replies to 8k-long commands, but hang past 65536 bytes.
For all 3 releases, without COMPRESS=DEFLATE Dovecot doesn't hang and
rightfully sends tagged BAD responses to commands of size >65539 bytes.

So while the hanging behavior appears to be a long-standing bug, the
fact that's it's now hit at min($imap_max_line_length, 8192) instead of
$imap_max_line_length seems to be a regression from somewhere between
2.2.27 and 2.3.4.

Cheers,
-- 
Guilhem.
-------------- next part --------------
# 2.3.7.2 (3c910f64b): /tmp/dovecot.conf
# Pigeonhole version 0.5.7.2 ()
# OS: Linux 5.2.0-3-amd64 x86_64 Debian bullseye/sid 
# Hostname: odin.guilhem.org
auth_mechanisms = anonymous
base_dir = /dev/shm/dovecot-test/run
default_internal_group = guilhem
default_internal_user = guilhem
default_login_user = guilhem
listen = 127.0.0.1
log_path = /tmp/mail.log
mail_home = /dev/shm/dovecot-test/%u
mail_location = dbox:~/mail
mail_plugins = " zlib"
protocols = imap
service anvil {
  chroot = 
}
service imap-login {
  chroot = 
  inet_listener imap {
    port = 10143
  }
}
service stats {
  chroot = 
}
ssl = no
protocol imap {
  mail_plugins = " zlib imap_zlib"
}
-------------- next part --------------
A non-text attachment was scrubbed...
Name: many-fetch.pl
Type: text/x-perl
Size: 2013 bytes
Desc: not available
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20191113/4ddc7ffe/attachment.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: not available
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20191113/4ddc7ffe/attachment.sig>

On 13/11/2019 00:22, Guilhem Moulin via dovecot wrote:
> Hi there,
>
> Dovecot 2.3.7 appears to hang when the client sends a long command after
> enabling the IMAP COMPRESS extension [RFC 4978].  PoC script attached
> along with the doveconf(1) output.
>
> Without COMPRESS=DEFLATE, and with the default ?imap_max_line_length?
> value (64k) I'm able send commands up to 65539 bytes long (that's 3
> bytes more than 2??, so maybe the leading tag and the trailing CRLF
> aren't counted), after which Dovecot rightfully replies with tagged BAD
> responses.
>
>      $ COMPRESS=n /tmp/many-fetch.pl 65539
>      [?]
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[65539 bytes]
>      S: x OK Fetch completed (0.005 + 0.001 + 0.004 secs).
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[65540 bytes]
>      S: x BAD Error in IMAP command UID FETCH: IMAP command line too large
(0.001 + 0.001 secs).
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[65541 bytes]
>      S: x BAD Error in IMAP command UID FETCH: IMAP command line too large
(0.001 + 0.001 secs).
>
> With COMPRESS=DEFLATE however, the server never sends anything back when
> the command size exceeds 8192 bytes:
>
>      $ COMPRESS=y /tmp/many-fetch.pl 8192
>      [?]
>      S: x OK [READ-ONLY] Examine completed (0.001 + 0.000 secs).
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[8191 bytes]
>      S: x OK Fetch completed (0.001 + 0.000 secs).
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[8192 bytes]
>      S: x OK Fetch completed (0.001 + 0.000 secs).
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[8193 bytes]
>      [ _hangs until the server terminates the session for inactivity_ ]
>      S: * BYE Disconnected for inactivity.
>
> strace(1) show that Dovecot didn't send the response, even though the
> server log indicates that it's able to fully read the command.
>
> Interestingly, when setting ?imap_max_line_length? to 4096, the server
> also hangs after receiving a command of size >4096 bytes (instead of
> replying with a tagged BAD response).
>
>      $ COMPRESS=y /tmp/many-fetch.pl 4096
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[4095 bytes]
>      S: x OK Fetch completed (0.001 + 0.000 secs).
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[4096 bytes]
>      S: x OK Fetch completed (0.001 + 0.000 secs).
>      C: x UID FETCH 1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,?
[4097 bytes]
>      [ _hangs until the server terminates the session for inactivity_ ]
>
> I'm also able to reproduce the buggy behavior against Dovecot versions
> found in other Debian releases.  It's identical with 2.3.4 (Buster),
the
> server also hang past 8192 bytes.  2.2.27 (Stretch) and 2.2.13 (Jessie)
> are able to send replies to 8k-long commands, but hang past 65536 bytes.
> For all 3 releases, without COMPRESS=DEFLATE Dovecot doesn't hang and
> rightfully sends tagged BAD responses to commands of size >65539 bytes.
>
> So while the hanging behavior appears to be a long-standing bug, the
> fact that's it's now hit at min($imap_max_line_length, 8192)
instead of
> $imap_max_line_length seems to be a regression from somewhere between
> 2.2.27 and 2.3.4.
I was able to confirm this problem with the current master. Tracking 
internally as DOP-1591.

Regards,

Stephan.