Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

quitCloseConnection does not close connection #175

Closed
computerlove opened this issue Nov 29, 2021 · 3 comments · Fixed by #177
Closed

quitCloseConnection does not close connection #175

computerlove opened this issue Nov 29, 2021 · 3 comments · Fixed by #177
Assignees
Labels
Milestone

Comments

@computerlove
Copy link

computerlove commented Nov 29, 2021

Version

Vert.x mail-client 4.2.1, Quarkus 2.5.0

Context

When using connection pooling with smtp.office365.com an error is logged every time a connection has reached keep alive-timeout.
(if timeout is set to 60 seconds, the error is printed ~60s after last email is sent)

2021-11-29 12:24:25,510 ERROR [io.ver.ext.mai.imp.SMTPConnection] (vert.x-eventloop-thread-3) Connection reset

With debug logging:

2021-11-29T11:09:49.252+0100 ERROR [vert.x-eventloop-thread-2] io.vertx.ext.mail.impl.SMTPConnection Connection reset: java.net.SocketException: Connection reset
	at java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:367)
	at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:398)
	at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:253)
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1132)
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:350)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:151)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:832)
: java.net.SocketException: Connection reset
	at java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:367)
	at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:398)
	at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:253)
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1132)
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:350)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:151)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:832)

Stepping though SMTPConnection.quitCloseConnection I can see that QUIT is sent, but the connection is not closed.

The javadoc for quitCloseConnection says

send QUIT and close the connection

So my interpretation is that calling shutdown() is missing in quitCloseConnection. If I call shutdown() after QUIT i sent the connection reset does not happen.

Do you have a reproducer?

https://github.com/computerlove/mailer-reproducer

Steps to reproduce

  1. Setup a account for smtp.office365.com
  2. Fill account properties in application.properties
  3. mvnw quarkus:dev
  4. curl localhost:8080/hello
  5. After ~60s ERROR Connection reset should be logged.
@gaol
Copy link
Member

gaol commented Nov 29, 2021

It looks to me that the smtp server does not reply before closing the connection, which it should do according to https://datatracker.ietf.org/doc/html/rfc5321#section-4.1.1.10

I will check it next week after my current list, thanks.

@gaol gaol self-assigned this Dec 8, 2021
@gaol
Copy link
Member

gaol commented Dec 8, 2021

I can reproduce the error logging, and it seems the smtp server does reply on the QUIT command with 221 2.0.0 Service closing transmission channel, so it is fine.

For some reason, the exceptionHandler of the underline NetSocket gets called after the client gets the response, that is where the error logging comes from.

@gaol
Copy link
Member

gaol commented Dec 10, 2021

I see [RST, ACK] sequence in Wireshark, which indicates that the smtp server does not close the connection gracefully. I don't see this error logging with local Apache James server setup, it closes the connection gracefully with [FIN, ACK] flags.

I don't see much we can do in mail client side except ignoring the exception if QUIT has been sent to smtp server.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Development

Successfully merging a pull request may close this issue.

2 participants