chibenwa edited a comment on pull request #886:
URL: https://github.com/apache/james-project/pull/886#issuecomment-1042697512
## Quick QA
- [X] `openssl s_client -connect 172.17.0.2:993` :green_apple:
- [X] Thunderbird SMTP SSL sending EMail :green_apple:
- [X] Thunderbord IMAP SSL email access - small email - (listing emails and
opening it) :green_apple:
- [X] Thunderbord IMAP SSL email access - large mail - (listing emails and
opening it) :red_circle:
When I send a multi MB email using Thunderbird, the message is well
appended in the INBOX
However when I open to read it, it takes forever for Thunderbird to read
it. As if the process hanged.
log:
[reading_big_mail_in_tb.log](https://github.com/apache/james-project/files/8087037/reading_big_mail_in_tb.log)
Fun fact: for one of the test message restarting Thunderbird helped, not
for the other one.
- [X] Thunderbird IMAP SSL save the draft (IMAP APPEND) :red_circle:
Thunderbird hangs when saving the draft.
Here are James logs (DEBUG)
```
08:38:32.172 [INFO ] o.a.j.i.n.ImapChannelUpstreamHandler - Connection
established from 172.17.0.1
08:38:32.206 [DEBUG] i.n.h.s.SslHandler - [id: 0xc7662865, L:/172.17.0.2:993
- R:172.17.0.1/172.17.0.1:39360] HANDSHAKEN: protocol:TLSv1.3 cipher
suite:TLS_AES_128_GCM_SHA256
08:38:32.210 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message org.apache.james.imap.message.request.CapabilityRequest@434fb3b2 that
reached at the tail of the pipeline. Please check your pipeline configuration.
08:38:32.210 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xc7662865,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39360].
08:38:32.212 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message AuthenticateRequest{authType=PLAIN} that reached at the tail of the
pipeline. Please check your pipeline configuration.
08:38:32.213 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, lineHandler0, requestDecoder,
coreHandler, DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xc7662865,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39360].
08:38:32.222 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message org.apache.james.imap.message.request.CapabilityRequest@656f939a that
reached at the tail of the pipeline. Please check your pipeline configuration.
08:38:32.222 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xc7662865,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39360].
08:38:32.224 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message EnableRequest{capabilities=[Capability{value=UTF8=ACCEPT}]} that
reached at the tail of the pipeline. Please check your pipeline configuration.
08:38:32.224 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xc7662865,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39360].
...
Few seconds pass
...
08:38:52.240 [INFO ] o.a.j.i.n.ImapChannelUpstreamHandler - Connection
closed for 172.17.0.1
08:38:52.247 [INFO ] o.a.j.i.n.ImapChannelUpstreamHandler - Connection
established from 172.17.0.1
08:38:52.300 [DEBUG] i.n.h.s.SslHandler - [id: 0xef5e4890, L:/172.17.0.2:993
- R:172.17.0.1/172.17.0.1:39362] HANDSHAKEN: protocol:TLSv1.3 cipher
suite:TLS_AES_128_GCM_SHA256
08:38:52.304 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message org.apache.james.imap.message.request.CapabilityRequest@6139c2fb that
reached at the tail of the pipeline. Please check your pipeline configuration.
08:38:52.304 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xef5e4890,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39362].
08:38:52.305 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message AuthenticateRequest{authType=PLAIN} that reached at the tail of the
pipeline. Please check your pipeline configuration.
08:38:52.306 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, lineHandler0, requestDecoder,
coreHandler, DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xef5e4890,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39362].
08:38:52.314 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message org.apache.james.imap.message.request.CapabilityRequest@243b50b8 that
reached at the tail of the pipeline. Please check your pipeline configuration.
08:38:52.314 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xef5e4890,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39362].
08:38:52.316 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message EnableRequest{capabilities=[Capability{value=UTF8=ACCEPT}]} that
reached at the tail of the pipeline. Please check your pipeline configuration.
08:38:52.316 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xef5e4890,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39362].
08:38:57.972 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message org.apache.james.imap.message.request.NoopRequest@669668ac that reached
at the tail of the pipeline. Please check your pipeline configuration.
08:38:57.973 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0x95a2e755,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39358].
08:38:57.982 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message GetQuotaRootRequest{mailboxName=INBOX} that reached at the tail of the
pipeline. Please check your pipeline configuration.
08:38:57.982 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, requestDecoder, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0x95a2e755,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39358].
08:38:57.993 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message org.apache.james.imap.message.request.IdleRequest@2ce9352a that reached
at the tail of the pipeline. Please check your pipeline configuration.
08:38:57.993 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, idleHandler, timeoutHandler,
connectionLimitHandler, connectionPerIpLimitHandler, framer,
connectionCountHandler, chunkWriteHandler, lineHandler0, requestDecoder,
coreHandler, DefaultChannelPipeline$TailContext#0]. Channel : [id: 0x95a2e755,
L:/172.17.0.2:993 - R:172.17.0.1/172.17.0.1:39358].
```
This indicates a mis-management of IMAP literal management in the frame
decoder.
- [x] Thunderbird IMAP STARTTLS save the draft (IMAP APPEND)
I also had this worrying resource management related log
```
08:45:10.266 [INFO ] o.a.j.p.n.BasicChannelUpstreamHandler - Connection
established from 172.17.0.1
08:45:10.294 [DEBUG] i.n.h.s.SslHandler - [id: 0xb73464bf, L:/172.17.0.2:465
- R:172.17.0.1/172.17.0.1:57380] HANDSHAKEN: protocol:TLSv1.3 cipher
suite:TLS_AES_128_GCM_SHA256
08:45:10.297 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message PooledSlicedByteBuf(ridx: 0, widx: 19, cap: 19/19, unwrapped:
PooledUnsafeDirectByteBuf(ridx: 19, widx: 19, cap: 41)) that reached at the
tail of the pipeline. Please check your pipeline configuration.
08:45:10.298 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, connectionLimit, connectionPerIpLimit,
framer, chunkHandler, timeoutHandler, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xb73464bf,
L:/172.17.0.2:465 - R:172.17.0.1/172.17.0.1:57380].
08:45:10.332 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message PooledSlicedByteBuf(ridx: 0, widx: 37, cap: 37/37, unwrapped:
PooledUnsafeDirectByteBuf(ridx: 37, widx: 37, cap: 59)) that reached at the
tail of the pipeline. Please check your pipeline configuration.
08:45:10.332 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, connectionLimit, connectionPerIpLimit,
framer, chunkHandler, timeoutHandler, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xb73464bf,
L:/172.17.0.2:465 - R:172.17.0.1/172.17.0.1:57380].
08:45:10.361 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message PooledSlicedByteBuf(ridx: 0, widx: 37, cap: 37/37, unwrapped:
PooledUnsafeDirectByteBuf(ridx: 37, widx: 37, cap: 59)) that reached at the
tail of the pipeline. Please check your pipeline configuration.
08:45:10.361 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, connectionLimit, connectionPerIpLimit,
framer, chunkHandler, timeoutHandler, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xb73464bf,
L:/172.17.0.2:465 - R:172.17.0.1/172.17.0.1:57380].
08:45:10.364 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message PooledSlicedByteBuf(ridx: 0, widx: 21, cap: 21/21, unwrapped:
PooledUnsafeDirectByteBuf(ridx: 21, widx: 21, cap: 43)) that reached at the
tail of the pipeline. Please check your pipeline configuration.
08:45:10.364 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, connectionLimit, connectionPerIpLimit,
framer, chunkHandler, timeoutHandler, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xb73464bf,
L:/172.17.0.2:465 - R:172.17.0.1/172.17.0.1:57380].
08:45:10.366 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded inbound
message PooledSlicedByteBuf(ridx: 0, widx: 6, cap: 6/6, unwrapped:
PooledUnsafeDirectByteBuf(ridx: 6, widx: 6, cap: 28)) that reached at the tail
of the pipeline. Please check your pipeline configuration.
08:45:10.366 [DEBUG] i.n.c.DefaultChannelPipeline - Discarded message
pipeline : [sslHandler, groupHandler, connectionLimit, connectionPerIpLimit,
framer, chunkHandler, timeoutHandler, lineHandler1, coreHandler,
DefaultChannelPipeline$TailContext#0]. Channel : [id: 0xb73464bf,
L:/172.17.0.2:465 - R:172.17.0.1/172.17.0.1:57380].
08:45:10.618 [ERROR] i.n.u.ResourceLeakDetector - LEAK: ByteBuf.release()
was not called before it's garbage-collected. See
https://netty.io/wiki/reference-counted-objects.html for more information.
Recent access records:
Created at:
io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:402)
io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:188)
io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:179)
io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:116)
io.netty.handler.codec.ByteToMessageDecoder.expandCumulation(ByteToMessageDecoder.java:538)
io.netty.handler.codec.ByteToMessageDecoder$1.cumulate(ByteToMessageDecoder.java:97)
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:274)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1371)
io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1234)
io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1283)
io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658)
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584)
io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
java.base/java.lang.Thread.run(Unknown Source)
```
:orange_circle: Netty debug logs complains of discarded messages and asks us
to check our pipeline configuration. Does this indicates we misses some kind of
terminal elements in the Netty pipeline?
- [X] IMAP IDLE seem to still work :green_apple:
- [x] Check the IMAP timeout configs are well applied....
- [x] Ensure IMAP compression can be enabled
- [x] Ensure STARTTLS injections are not possible for IMAP, SMTP and POP3
cf https://nostarttls.secvuln.info/
- [x] Ensure POP3 still works (Thunderbird)
- [x] REnsure ManageSieve still works (Thunderbird plugin)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
