Thread blocked and login problems

Question

Thread blocked and login problems

yazalulloa opened this issue 4 years ago · 10 comments

I'm using version 4.0.0.Beta3

I'm having problems connecting to an SMTP server with Vertx Mail Client

I think it have something to do with the configuracion because with javax.mail it works perfectly.

`final var mailConfig = new MailConfig()
.setHostname("local ip")
.setPort(25)
.setStarttls(StartTLSOptions.OPTIONAL)
.setKeepAlive(true)
.setTrustAll(true)
.setSsl(false)
.setUsername("username")
.setPassword("password")
.setMetricsName("MAIL_CLIENT")
.setLogActivity(true)
.setLogin(LoginOption.REQUIRED)
.setAuthMethods("PLAIN");

public class MailServiceVerticle extends AbstractVerticle {

@Override
public void start() {


    vertx.eventBus().<JsonObject>consumer("mail-send-event", message -> {


        final var mailConfig = new MailConfig(config());

        vertx.<MailClient>executeBlocking(promise -> {
            try {
                final var mailClient = MailClient.createShared(vertx, mailConfig, config().getString("mail-pool"));
                promise.complete(mailClient);
            } catch (Exception e) {
                promise.fail(e);
            }

        }, result -> {
            if (result.succeeded()) {
                sendMessage(result.result(), message);
            } else {
                message.reply(VertxUtil.replyException(result.cause()));
            }

        });

    });
}

private void sendMessage(MailClient mailClient, Message<JsonObject> message) {
    mailClient.sendMail(new MailMessage(message.body()), result -> {
        if (result.succeeded()) {
            final var jsonObject = new JsonObject()
                    .put("code", 200)
                    .put("message", "SUCCESS");
            message.reply(jsonObject);
        } else {
            message.reply(VertxUtil.replyException(result.cause()));
        }

    });
}

}`

Everytime I tried to run it I get a Thread Blocked warning:

! io.vertx.core.VertxException: Thread blocked
! at java.base@11.0.7/java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
! at java.base@11.0.7/java.net.InetAddress$PlatformNameService.lookupAllHostAddr(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress.getAddressesFromNameService(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress$NameServiceAddresses.get(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress.getAllByName0(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress.getLocalHost(Unknown Source)
! at java.management@11.0.7/sun.management.VMManagementImpl.getVmId(Unknown Source)
! at java.management@11.0.7/sun.management.RuntimeImpl.getName(Unknown Source)
! at java.base@11.0.7/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
! at java.base@11.0.7/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
! at java.base@11.0.7/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
! at java.base@11.0.7/java.lang.reflect.Method.invoke(Unknown Source)
! at app//io.netty.channel.DefaultChannelId.defaultProcessId(DefaultChannelId.java:120)
! at app//io.netty.channel.DefaultChannelId.(DefaultChannelId.java:77)
! at app//io.netty.channel.AbstractChannel.newId(AbstractChannel.java:101)
! at app//io.netty.channel.AbstractChannel.(AbstractChannel.java:73)
! at app//io.netty.channel.nio.AbstractNioChannel.(AbstractNioChannel.java:80)
! at app//io.netty.channel.nio.AbstractNioByteChannel.(AbstractNioByteChannel.java:66)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:105)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:95)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:88)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:81)
! at app//io.vertx.core.net.impl.transport.Transport$$Lambda$931/0x0000000100a2e840.newChannel(Unknown Source)
! at app//io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:310)
! at app//io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:155)
! at app//io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:139)
! at app//io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:137)
! at app//io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:90)
! at app//io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:76)
! at app//io.vertx.core.net.impl.NetClientImpl.doConnect(NetClientImpl.java:209)
! at app//io.vertx.core.net.impl.NetClientImpl.doConnect(NetClientImpl.java:190)
! at app//io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:180)
! at app//io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:122)
! at app//io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:117)
! at app//io.vertx.ext.mail.impl.SMTPConnection.openConnection(SMTPConnection.java:192)
! at app//io.vertx.ext.mail.impl.SMTPStarter.start(SMTPStarter.java:52)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.createConnection(SMTPConnectionPool.java:249)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.createNewConnection(SMTPConnectionPool.java:233)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.getConnection0(SMTPConnectionPool.java:157)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.getConnection(SMTPConnectionPool.java:82)
! at app//io.vertx.ext.mail.impl.MailClientImpl.getConnection(MailClientImpl.java:118)
! at app//io.vertx.ext.mail.impl.MailClientImpl.lambda$sendMail$2(MailClientImpl.java:102)
! at app//io.vertx.ext.mail.impl.MailClientImpl$$Lambda$923/0x0000000100a28840.handle(Unknown Source)
! at app//io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:125)
! at app//io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:53)
! at app//io.vertx.core.impl.future.FutureBase$$Lambda$292/0x00000001005a5840.run(Unknown Source)
! at app//io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
! at app//io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
! at app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
! at app//io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
! at app//io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
! at app//io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
! at java.base@11.0.7/java.lang.Thread.run(Unknown Source)
WARN [2020-10-18 13:23:54,136] io.vertx.core.impl.BlockedThreadChecker: Thread Thread[vert.x-eventloop-thread-0,5,main] has been blocked for 6017 ms, time limit is 2000 ms
! io.vertx.core.VertxException: Thread blocked
! at java.base@11.0.7/java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
! at java.base@11.0.7/java.net.InetAddress$PlatformNameService.lookupAllHostAddr(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress.getAddressesFromNameService(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress$NameServiceAddresses.get(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress.getAllByName0(Unknown Source)
! at java.base@11.0.7/java.net.InetAddress.getLocalHost(Unknown Source)
! at java.management@11.0.7/sun.management.VMManagementImpl.getVmId(Unknown Source)
! at java.management@11.0.7/sun.management.RuntimeImpl.getName(Unknown Source)
! at java.base@11.0.7/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
! at java.base@11.0.7/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
! at java.base@11.0.7/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
! at java.base@11.0.7/java.lang.reflect.Method.invoke(Unknown Source)
! at app//io.netty.channel.DefaultChannelId.defaultProcessId(DefaultChannelId.java:120)
! at app//io.netty.channel.DefaultChannelId.(DefaultChannelId.java:77)
! at app//io.netty.channel.AbstractChannel.newId(AbstractChannel.java:101)
! at app//io.netty.channel.AbstractChannel.(AbstractChannel.java:73)
! at app//io.netty.channel.nio.AbstractNioChannel.(AbstractNioChannel.java:80)
! at app//io.netty.channel.nio.AbstractNioByteChannel.(AbstractNioByteChannel.java:66)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:105)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:95)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:88)
! at app//io.netty.channel.socket.nio.NioSocketChannel.(NioSocketChannel.java:81)
! at app//io.vertx.core.net.impl.transport.Transport$$Lambda$931/0x0000000100a2e840.newChannel(Unknown Source)
! at app//io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:310)
! at app//io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:155)
! at app//io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:139)
! at app//io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:137)
! at app//io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:90)
! at app//io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:76)
! at app//io.vertx.core.net.impl.NetClientImpl.doConnect(NetClientImpl.java:209)
! at app//io.vertx.core.net.impl.NetClientImpl.doConnect(NetClientImpl.java:190)
! at app//io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:180)
! at app//io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:122)
! at app//io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:117)
! at app//io.vertx.ext.mail.impl.SMTPConnection.openConnection(SMTPConnection.java:192)
! at app//io.vertx.ext.mail.impl.SMTPStarter.start(SMTPStarter.java:52)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.createConnection(SMTPConnectionPool.java:249)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.createNewConnection(SMTPConnectionPool.java:233)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.getConnection0(SMTPConnectionPool.java:157)
! at app//io.vertx.ext.mail.impl.SMTPConnectionPool.getConnection(SMTPConnectionPool.java:82)
! at app//io.vertx.ext.mail.impl.MailClientImpl.getConnection(MailClientImpl.java:118)
! at app//io.vertx.ext.mail.impl.MailClientImpl.lambda$sendMail$2(MailClientImpl.java:102)
! at app//io.vertx.ext.mail.impl.MailClientImpl$$Lambda$923/0x0000000100a28840.handle(Unknown Source)
! at app//io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:125)
! at app//io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:53)
! at app//io.vertx.core.impl.future.FutureBase$$Lambda$292/0x00000001005a5840.run(Unknown Source)
! at app//io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
! at app//io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
! at app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
! at app//io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
! at app//io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
! at app//io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
! at java.base@11.0.7/java.lang.Thread.run(Unknown Source)

And at the end I get this error:

DEBUG [2020-10-18 13:24:00,849] io.vertx.ext.mail.impl.SMTPStarter: SMTPAuthentication
DEBUG [2020-10-18 13:24:00,851] io.vertx.ext.mail.impl.SMTPStarter: handleError:io.vertx.core.impl.NoStackTraceThrowable: login is required, but no allowed AUTH methods available. You may need to do STARTTLS
DEBUG [2020-10-18 13:24:00,851] io.vertx.ext.mail.impl.SMTPConnection: setting connection to broken
DEBUG [2020-10-18 13:24:00,851] io.vertx.ext.mail.impl.SMTPConnection: closing connection

If I set StartTLSOptions to REQUIRED I get this:

WARN [2020-10-18 13:05:10,172] io.vertx.ext.mail.impl.SMTPInitialDialogue: STARTTLS required but not supported by server
DEBUG [2020-10-18 13:05:10,172] io.vertx.ext.mail.impl.SMTPInitialDialogue: handleError:STARTTLS required but not supported by server
DEBUG [2020-10-18 13:05:10,172] io.vertx.ext.mail.impl.SMTPStarter: handleError:io.vertx.core.impl.NoStackTraceThrowable: STARTTLS required but not supported by server
DEBUG [2020-10-18 13:05:10,172] io.vertx.ext.mail.impl.SMTPConnection: setting connection to broken
DEBUG [2020-10-18 13:05:10,172] io.vertx.ext.mail.impl.SMTPConnection: closing connection

For reference this is my configuration with javax.mail:

`
Properties properties = System.getProperties();
properties.setProperty("mail.smtp.auth", "true");
properties.setProperty("mail.smtp.starttls.enable", "true");
properties.setProperty("mail.smtp.host", "local ip");
properties.put("mail.smtp.port", 25);
properties.setProperty("mail.smtp.user", "username");
properties.setProperty("mail.smtp.password", "password");
properties.put("mail.debug", true);
properties.put("mail.smtp.ssl.socketFactory", new MailSSLSocketFactory());

Session session = Session.getDefaultInstance(properties, new javax.mail.Authenticator() {
@OverRide
protected PasswordAuthentication getPasswordAuthentication() {
return new PasswordAuthentication(config.username(), config.password());
}
});
`

Answer 1 · 2020-10-19T02:04:31.000Z

From the exception you provided, I guess your mail server does not support STARTTLS and PLAIN, would you please remove the setAuthMethods("PLAIN") in your code to let the vertx-mail-client negotiate with the mail server to use the authentication method supported by both sides?

Answer 2 · 2020-10-19T02:16:24.000Z

On the STARTTLS capability, please also check if you configure the SSL options correctly by MailConfig.setKeyStoreOptions() or related ssl set up.

Answer 3 · 2020-10-19T18:51:07.000Z

From the exception you provided, I guess your mail server does not support STARTTLS and PLAIN, would you please remove the setAuthMethods("PLAIN") in your code to let the vertx-mail-client negotiate with the mail server to use the authentication method supported by both sides?

"mail_config": {
"log_activity": true,
"tcp_keep_alive": true,
"ssl": false,
"use_alpn": false,
"trust_all": true,
"metrics_name": "TEST_MAIL_CLIENT",
"hostname": "{local ip}",
"port": 25,
"starttls": "DISABLED",
"login": "REQUIRED",
"auth_methods": null,
"username": "{username}",
"password": "{password}",
"keep_alive": true
}

I tried with this configuration, I get the same thread block and this error:

DEBUG [2020-10-19 14:37:37,472] io.vertx.ext.mail.impl.SMTPStarter: SMTPAuthentication
DEBUG [2020-10-19 14:37:37,473] io.vertx.ext.mail.impl.SMTPStarter: handleError:io.vertx.core.impl.NoStackTraceThrowable: login is required, but no allowed AUTH methods available. You may need to do STARTTLS
DEBUG [2020-10-19 14:37:37,473] io.vertx.ext.mail.impl.SMTPConnection: setting connection to broken
DEBUG [2020-10-19 14:37:37,473] io.vertx.ext.mail.impl.SMTPConnection: closing connection
DEBUG [2020-10-19 14:37:37,474] io.vertx.ext.mail.impl.SMTPConnectionPool: connection is broken, closing
DEBUG [2020-10-19 14:37:37,475] io.vertx.ext.mail.impl.MailClientImpl: handleError
! io.vertx.core.impl.NoStackTraceThrowable: login is required, but no allowed AUTH methods available. You may need to do STARTTLS

Answer 4 · 2020-10-19T18:52:40.000Z

On the STARTTLS capability, please also check if you configure the SSL options correctly by MailConfig.setKeyStoreOptions() or related ssl set up.

The server to which I'm connecting to has no SSL configuration

Answer 5 · 2020-10-20T03:38:04.000Z

@yazalulloa would you please also check the logs starting with: EHLO result: ? there should be something like:

09:44:17.002 [vert.x-eventloop-thread-0] [DEBUG] io.vertx.ext.mail.impl.SMTPInitialDialogue - EHLO result: 250-localhost
250-8BITMIME
250-AUTH LOGIN PLAIN
250 Ok

where we can know what the mail server supports. I am asking because I am wondering if your mail server enable authentication or not. The only possibility to see the logs login is required, but no allowed AUTH methods available. You may need to do STARTTLS is that there is no allowed authentication methods found.

For the thread block part, it looks like a DNS issue, I don't have any input on that regard so far. Maybe you can try to specify -Djava.net.preferIPv4Stack=true to bypass it.

Answer 6 · 2020-10-20T06:43:17.000Z

I tested with this config:

"config": {
"log_activity": true,
"tcp_keep_alive": true,
"ssl": false,
"use_alpn": false,
"trust_all": true,
"metrics_name": "TEST_MAIL_CLIENT",
"hostname": "{smtp_server_ip}",
"port": 25,
"starttls": "OPTIONAL",
"login": "REQUIRED",
"auth_methods": null,
"username": "{username}",
"password": "{password}",
"keep_alive": true
}

DEBUG [2020-10-20 02:37:58,648] io.netty.channel.DefaultChannelId: -Dio.netty.processId: 1 (auto-detected)
DEBUG [2020-10-20 02:37:58,655] io.netty.channel.DefaultChannelId: -Dio.netty.machineId: 00:50:56:ff:fe:94:94:9f (auto-detected)
DEBUG [2020-10-20 02:37:58,690] io.netty.buffer.ByteBufUtil: -Dio.netty.allocator.type: pooled
DEBUG [2020-10-20 02:37:58,690] io.netty.buffer.ByteBufUtil: -Dio.netty.threadLocalDirectBufferSize: 0
DEBUG [2020-10-20 02:37:58,690] io.netty.buffer.ByteBufUtil: -Dio.netty.maxThreadLocalCharBufferSize: 16384
DEBUG [2020-10-20 02:37:58,812] javax.management.mbeanserver: ObjectName = metrics:name=vertx.net.clients.open-connections.{smtp_server_ip},type=counters
DEBUG [2020-10-20 02:37:58,812] javax.management.mbeanserver: name = metrics:name=vertx.net.clients.open-connections.{smtp_server_ip},type=counters
DEBUG [2020-10-20 02:37:58,812] javax.management.mbeanserver: Send create notification of object metrics:name=vertx.net.clients.open-connections.{smtp_server_ip},type=counters
DEBUG [2020-10-20 02:37:58,812] javax.management.mbeanserver: JMX.mbean.registered metrics:name=vertx.net.clients.open-connections.{smtp_server_ip},type=counters
DEBUG [2020-10-20 02:37:58,837] io.netty.util.Recycler: -Dio.netty.recycler.maxCapacityPerThread: 4096
DEBUG [2020-10-20 02:37:58,837] io.netty.util.Recycler: -Dio.netty.recycler.maxSharedCapacityFactor: 2
DEBUG [2020-10-20 02:37:58,837] io.netty.util.Recycler: -Dio.netty.recycler.linkCapacity: 16
DEBUG [2020-10-20 02:37:58,837] io.netty.util.Recycler: -Dio.netty.recycler.ratio: 8
DEBUG [2020-10-20 02:37:58,882] io.vertx.ext.mail.impl.MultilineParser: setting crlf line mode
DEBUG [2020-10-20 02:37:58,882] io.vertx.ext.mail.impl.SMTPStarter: SMTPInitialDialogue
DEBUG [2020-10-20 02:37:58,883] io.vertx.ext.mail.impl.SMTPInitialDialogue: server greeting: 220 *****************************************************************************************************
DEBUG [2020-10-20 02:37:58,892] io.vertx.ext.mail.impl.SMTPConnection: command: EHLO localhost
DEBUG [2020-10-20 02:37:58,910] io.vertx.ext.mail.impl.SMTPInitialDialogue: EHLO result: 250-SRV-VCCS-TRAN1.{internal_domain} Hello [{client_ip}]
250-SIZE
250-PIPELINING
250-DSN
250-ENHANCEDSTATUSCODES
250-XXXXXXXXXXXXXA
250-AUTH NTLM
250-XXXXXXXXXXXXXXXXXB
250-8BITMIME
250-BINARYMIME
250-XXXXXXXC
250-XXXXXXD
250-XXXXE
250 XXXXXXF
DEBUG [2020-10-20 02:37:58,913] io.vertx.ext.mail.impl.SMTPStarter: SMTPAuthentication
DEBUG [2020-10-20 02:37:58,914] io.vertx.ext.mail.impl.SMTPStarter: handleError:io.vertx.core.impl.NoStackTraceThrowable: login is required, but no allowed AUTH methods available. You may need to do STARTTLS
DEBUG [2020-10-20 02:37:58,914] io.vertx.ext.mail.impl.SMTPConnection: setting connection to broken
DEBUG [2020-10-20 02:37:58,914] io.vertx.ext.mail.impl.SMTPConnection: closing connection
DEBUG [2020-10-20 02:37:58,915] io.vertx.ext.mail.impl.SMTPConnectionPool: connection is broken, closing
DEBUG [2020-10-20 02:37:58,916] io.vertx.ext.mail.impl.MailClientImpl: handleError ! io.vertx.core.impl.NoStackTraceThrowable: login is required, but no allowed AUTH methods available. You may need to do STARTTLS

Answer 7 · 2020-10-20T08:03:53.000Z

250-AUTH NTLM

OK, so your mail server requires NTLM for the authentication, vertx-mail-client does not support it currently, it supports the following authentication methods now:

    "XOAUTH2",
    "DIGEST-MD5",
    "CRAM-SHA256",
    "CRAM-SHA1",
    "CRAM-MD5",
    "LOGIN",
    "PLAIN"

Answer 8 · 2020-10-20T09:26:18.000Z

@yazalulloa I created #159 to track the enhancement to support NTLM.

Answer 9 · 2020-10-20T15:22:18.000Z

Ok, thanks for your help

Answer 10 · 2021-07-17T03:59:40.000Z

@yazalulloa vertx-mail-client supports NTLM from 4.1.1, I am closing this issue.