Почему HAProxy закрывает соединение с клиентом HiveMQ MQTT в конце рукопожатия TLS? - PullRequest
Новая
       89

Почему HAProxy закрывает соединение с клиентом HiveMQ MQTT в конце рукопожатия TLS?

2 голосов
/ 15 октября 2019

Я пытаюсь установить соединение TLS с брокером MQTT за экземпляром HAProxy. В конце рукопожатия (данные приложения TLS 1.2 были отправлены) сервер неожиданно закрывает соединение.

Я использую самозаверяющие сертификаты в форме хранилища ключей и хранилища доверенных сертификатов. Keystore и Truststore тестируются на сервере, например, с MQTTFx и с клиентом MQTT3 Paho.

Поскольку мне приходится использовать общие подписки, я решил переключиться на асинхронный клиент HiveMQ MQTT5.

Следующий код иллюстрирует построение клиента и подключение к серверу.

Переменная connectionProperties содержит информацию о посреднике и используемых хранилищах ключей. 

public class MqttConnector {

    Logger logger = LoggerFactory.getLogger(MqttConnector.class);

    private ConnectionListener connectionListener;
    private Properties connectionProperties;

    private Mqtt5AsyncClient client;

    public MqttConnector() throws SSLException {
        this.connectionListener = new ConnectionListener();
        this.connectionProperties = ConnectionProperties.get();
        this.client = this.buildMqtt5AsyncClient(this.connectionProperties, this.connectionListener);
    }

    public MqttConnector(ConnectionListener connectionListener, Properties connectionProperties) throws SSLException {
        this.connectionListener = connectionListener;
        this.connectionProperties = connectionProperties;
        this.client = this.buildMqtt5AsyncClient(this.connectionProperties, this.connectionListener);
    }

    private Mqtt5AsyncClient buildMqtt5AsyncClient(
            Properties connectionProperties, 
            ConnectionListener connectionListener) throws SSLException {

        return MqttClient.builder()
                .identifier(connectionProperties.getProperty("clientId"))
                .serverHost(connectionProperties.getProperty("host"))
                .serverPort(Integer.valueOf(connectionProperties.getProperty("port")))
                .addConnectedListener(connectionListener)
                .addDisconnectedListener(connectionListener)
                .sslConfig()
                .keyManagerFactory(KeystoreUtil.keyManagerFromKeystore(
                        new File(connectionProperties.getProperty("keystore_file")), 
                        connectionProperties.getProperty("keystore_pass"), 
                        connectionProperties.getProperty("keystore_pass")))
                .trustManagerFactory(KeystoreUtil.trustManagerFromKeystore(
                        new File(connectionProperties.getProperty("truststore_file")), 
                        connectionProperties.getProperty("truststore_pass")))
                .applySslConfig()
                .automaticReconnectWithDefaultConfig()
                .useMqttVersion5()
                .buildAsync();
    }

    public void connect() {
        this.client.connect().whenComplete((connack, throwable) -> {
            if (throwable != null) {
                logger.error("connection exception", throwable);
            } else {
                logger.info(connack.toString());
            }
        });

    }

    public void disconnect() {
        if (this.client != null && this.client.getState().isConnected()) {
            this.client.disconnect();
        }
    }

Это часть отладкиlog (отлажен с дополнительным -Djavax.net.debug=all, чтобы увидеть вывод SSL). Я удалил большую часть необработанных данных и информацию о сертификате.

В конце рукопожатия соединение закрывается сервером. Я понятия не имею, почему это происходит с проверенными и проверенными сертификатами. 

javax.net.ssl|DEBUG|01|main|2019-10-15 15:40:50.356 CEST|X509TrustManagerImpl.java:79|adding as trusted certificates (
  "certificate" : {
    "version"            : "v3",
    "serial number"      : "02 41 2E 94 57 70 85 FC DF CB 6E F1 24 79 E0 C3 53 2C 41 7A",
    "signature algorithm": "SHA256withRSA",
    "issuer"             : "CN=ca.dev-broker.your-server.de",
    "not before"         : "2019-07-31 16:05:54.000 CEST",
    "not  after"         : "2029-07-28 16:05:54.000 CEST",
    "subject"            : "CN=dev-broker.your-server.de",
    "subject public key" : "RSA",
    "extensions"         : [
      {
        ObjectId: 2.5.29.19 Criticality=false
        BasicConstraints:[
          CA:false
          PathLen: undefined
        ]
      },
      {
        ObjectId: 2.5.29.15 Criticality=false
        KeyUsage [
          DigitalSignature
          Non_repudiation
          Key_Encipherment
        ]
      },
      {
        ObjectId: 2.5.29.17 Criticality=false
        SubjectAlternativeName [
          DNSName: dev-broker.your-server.de
          DNSName: *.dev-broker.your-server.de
        ]
      }
    ]}
)

15:44:31.015 [main] DEBUG io.netty.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
15:44:32.601 [main] DEBUG io.netty.util.internal.PlatformDependent0 - -Dio.netty.noUnsafe: false
15:44:32.603 [main] DEBUG io.netty.util.internal.PlatformDependent0 - Java version: 11
15:44:32.651 [main] DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.theUnsafe: available
15:44:32.669 [main] DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.copyMemory: available
15:44:32.687 [main] DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Buffer.address: available
15:44:32.708 [main] DEBUG io.netty.util.internal.PlatformDependent0 - direct buffer constructor: unavailable
15:44:33.245 [main] DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Bits.unaligned: available, true
15:44:33.272 [main] DEBUG io.netty.util.internal.PlatformDependent0 - jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable

5:44:50.873 [epollEventLoopGroup-2-1] DEBUG io.netty.handler.ssl.JdkSslContext - Default protocols (JDK): [TLSv1.2, TLSv1.1, TLSv1] 
15:44:50.876 [epollEventLoopGroup-2-1] DEBUG io.netty.handler.ssl.JdkSslContext - Default cipher suites (JDK): [TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_AES_128_GCM_SHA256, TLS_AES_256_GCM_SHA384]
javax.net.ssl|ALL|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.877 CEST|SSLContextImpl.java:115|trigger seeding of SecureRandom
javax.net.ssl|ALL|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.877 CEST|SSLContextImpl.java:119|done seeding of SecureRandom
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.962 CEST|HandshakeContext.java:290|Ignore unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384 for TLS11
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.963 CEST|HandshakeContext.java:290|Ignore unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256 for TLS11
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.964 CEST|HandshakeContext.java:290|Ignore unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 for TLS11
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.964 CEST|HandshakeContext.java:290|Ignore unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384 for TLS10
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.967 CEST|HandshakeContext.java:290|Ignore unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256 for TLS10
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:50.968 CEST|HandshakeContext.java:290|Ignore unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 for TLS10
javax.net.ssl|WARNING|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.002 CEST|ServerNameExtension.java:255|Unable to indicate server name
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.003 CEST|SSLExtensions.java:256|Ignore, context unavailable extension: server_name
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.009 CEST|SupportedGroupsExtension.java:841|Ignore inactive or disabled named group: ffdhe2048
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.012 CEST|SupportedGroupsExtension.java:841|Ignore inactive or disabled named group: ffdhe3072
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.013 CEST|SupportedGroupsExtension.java:841|Ignore inactive or disabled named group: ffdhe4096
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.014 CEST|SupportedGroupsExtension.java:841|Ignore inactive or disabled named group: ffdhe6144
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.014 CEST|SupportedGroupsExtension.java:841|Ignore inactive or disabled named group: ffdhe8192
javax.net.ssl|WARNING|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.026 CEST|SignatureScheme.java:282|Signature algorithm, ed25519, is not supported by the underlying providers
javax.net.ssl|WARNING|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.027 CEST|SignatureScheme.java:282|Signature algorithm, ed448, is not supported by the underlying providers
javax.net.ssl|ALL|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.043 CEST|SignatureScheme.java:358|Ignore disabled signature sheme: rsa_md5
javax.net.ssl|INFO|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.046 CEST|AlpnExtension.java:161|No available application protocols
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.047 CEST|SSLExtensions.java:256|Ignore, context unavailable extension: application_layer_protocol_negotiation
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.053 CEST|ClientHello.java:651|Produced ClientHello handshake message (
"ClientHello": {
  "client version"      : "TLSv1.2",
  "random"              : "4D 37 59 83 17 36 AD CD 4E D5 4F DB EF 60 88 66 23 B2 ED FA DC 13 81 EF 5D 19 9E DC 9E FA 41 57",
  "session id"          : "",
  "cipher suites"       : "[TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384(0xC02C), TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256(0xC02B), TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256(0xC02F), TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA(0xC013), TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA(0xC014), TLS_RSA_WITH_AES_128_GCM_SHA256(0x009C), TLS_RSA_WITH_AES_128_CBC_SHA(0x002F), TLS_RSA_WITH_AES_256_CBC_SHA(0x0035)]",
  "compression methods" : "00",
  "extensions"          : [

  ]
}
)
15:44:51.076 [epollEventLoopGroup-2-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.maxCapacityPerThread: 4096
15:44:51.077 [epollEventLoopGroup-2-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.maxSharedCapacityFactor: 2
15:44:51.078 [epollEventLoopGroup-2-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.linkCapacity: 16
15:44:51.078 [epollEventLoopGroup-2-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.ratio: 8
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.135 CEST|SSLEngineOutputRecord.java:507|WRITE: TLS12 handshake, length = 223
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.136 CEST|SSLEngineOutputRecord.java:525|Raw write (...)

javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.176 CEST|SSLEngineInputRecord.java:177|Raw read (...)

javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.177 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 handshake, length = 93
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.184 CEST|ServerHello.java:866|Consuming ServerHello handshake message (
"ServerHello": {
  "server version"      : "TLSv1.2",
  "random"              : "EC 44 2C 42 7F C7 DD 1F C5 F8 C2 E1 13 4B C1 94 71 41 AF EF 96 E1 8D F3 E8 B4 7B 11 D7 74 A1 3F",
  "session id"          : "37 23 36 B1 49 8B A1 97 C5 2C F0 3A BC 25 D4 BF 13 3D 25 35 A9 31 C0 3E AB DA CE 81 E2 39 4D FF",
  "cipher suite"        : "TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256(0xC02F)",
  "compression methods" : "00",
  "extensions"          : [
    "renegotiation_info (65,281)": {
      "renegotiated connection": [<no renegotiated connection>]
    },
    "ec_point_formats (11)": {
      "formats": [uncompressed, ansiX962_compressed_prime, ansiX962_compressed_char2]
    },
    "extended_master_secret (23)": {
      <empty>
    }
  ]
}
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.185 CEST|SSLExtensions.java:169|Ignore unavailable extension: supported_versions
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.186 CEST|ServerHello.java:962|Negotiated protocol version: TLSv1.2
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.187 CEST|SSLExtensions.java:188|Consumed extension: renegotiation_info
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.188 CEST|SSLExtensions.java:169|Ignore unavailable extension: server_name
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.189 CEST|SSLExtensions.java:169|Ignore unavailable extension: max_fragment_length
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.189 CEST|SSLExtensions.java:169|Ignore unavailable extension: status_request
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.191 CEST|SSLExtensions.java:188|Consumed extension: ec_point_formats
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.194 CEST|SSLExtensions.java:169|Ignore unavailable extension: status_request_v2
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.194 CEST|SSLExtensions.java:188|Consumed extension: extended_master_secret
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.195 CEST|SSLExtensions.java:188|Consumed extension: renegotiation_info
javax.net.ssl|ALL|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.195 CEST|SSLSessionImpl.java:209|Session initialized:  Session(1571147091195|TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.196 CEST|SSLExtensions.java:203|Ignore unavailable extension: server_name
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.196 CEST|SSLExtensions.java:203|Ignore unavailable extension: max_fragment_length
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.196 CEST|SSLExtensions.java:203|Ignore unavailable extension: status_request
javax.net.ssl|WARNING|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.197 CEST|SSLExtensions.java:211|Ignore impact of unsupported extension: ec_point_formats
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.197 CEST|SSLExtensions.java:203|Ignore unavailable extension: application_layer_protocol_negotiation
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.197 CEST|SSLExtensions.java:203|Ignore unavailable extension: status_request_v2
javax.net.ssl|WARNING|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.197 CEST|SSLExtensions.java:211|Ignore impact of unsupported extension: extended_master_secret
javax.net.ssl|WARNING|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.198 CEST|SSLExtensions.java:211|Ignore impact of unsupported extension: renegotiation_info
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.209 CEST|SSLEngineInputRecord.java:177|Raw read (...)

javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.215 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 handshake, length = 2517
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.240 CEST|CertificateMessage.java:358|Consuming server Certificate handshake message (
"Certificates": [...]

javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.760 CEST|X509TrustManagerImpl.java:300|Found trusted certificate (
  "certificate" : {...}
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.766 CEST|SSLEngineInputRecord.java:177|Raw read (...)

javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.767 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 handshake, length = 333
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.778 CEST|ECDHServerKeyExchange.java:538|Consuming ECDH ServerKeyExchange handshake message (
"ECDH ServerKeyExchange": {
  "parameters": {
    "named group": "secp256r1"
    "ecdh public": {...},
  },
  "digital signature":  {
    "signature algorithm": "rsa_pss_rsae_sha256"
    "signature": {...},
  }
}
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.780 CEST|SSLEngineInputRecord.java:177|Raw read (...)

javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.782 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 handshake, length = 131
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.788 CEST|CertificateRequest.java:651|Consuming CertificateRequest handshake message (
"CertificateRequest": {
  "certificate types": [rsa_sign, dss_sign, ecdsa_sign]
  "supported signature algorithms": [ecdsa_secp256r1_sha256, ecdsa_secp384r1_sha384, ecdsa_secp512r1_sha512, ed25519, ed448, rsa_pss_pss_sha256, rsa_pss_pss_sha384, rsa_pss_pss_sha512, rsa_pss_rsae_sha256, rsa_pss_rsae_sha384, rsa_pss_rsae_sha512, rsa_pkcs1_sha256, rsa_pkcs1_sha384, rsa_pkcs1_sha512, ecdsa_sha224, ecdsa_sha1, rsa_sha224, rsa_pkcs1_sha1, dsa_sha224, dsa_sha1, dsa_sha256, dsa_sha384, dsa_sha512]
  "certificate authorities": [CN=ca.your-server.de, CN=ca.dev-broker.your-server.de]
}
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:51.812 CEST|X509KeyManagerImpl.java:389|KeyMgr: choosing key: 1 (verified: OK)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.131 CEST|SSLEngineInputRecord.java:177|Raw read (
  0000: 16 03 03 00 04 0E 00 00   00                       .........
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.131 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 handshake, length = 4
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.132 CEST|ServerHelloDone.java:142|Consuming ServerHelloDone handshake message (
<empty>
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.141 CEST|CertificateMessage.java:322|Produced client Certificate handshake message (
"Certificates": [
  "certificate" : {...}
]
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.150 CEST|ECDHClientKeyExchange.java:401|Produced ECDHE ClientKeyExchange handshake message (
"ECDH ClientKeyExchange": {
  "ecdh public": {...},
}
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.387 CEST|CertificateVerify.java:743|Produced CertificateVerify handshake message (
"CertificateVerify": {
  "signature algorithm": rsa_pss_rsae_sha256
  "signature": {...}
}
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.418 CEST|ChangeCipherSpec.java:109|Produced ChangeCipherSpec message
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.419 CEST|Finished.java:395|Produced client Finished handshake message (
"Finished": {
  "verify data": {
    ...
  }'}
)

avax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.422 CEST|SSLEngineOutputRecord.java:507|WRITE: TLS12 handshake, length = 2855
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.427 CEST|SSLEngineOutputRecord.java:525|Raw write (...)

javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.430 CEST|SSLEngineOutputRecord.java:507|WRITE: TLS12 change_cipher_spec, length = 1
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.431 CEST|SSLEngineOutputRecord.java:525|Raw write (
  0000: 14 03 03 00 01 01                                  ......
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.432 CEST|SSLEngineOutputRecord.java:507|WRITE: TLS12 handshake, length = 16
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.483 CEST|SSLCipher.java:1727|Plaintext before ENCRYPTION (
  0000: 14 00 00 0C 91 F1 79 2C   A0 3C A8 61 58 45 99 AF  ......y,.<.aXE..
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.487 CEST|SSLEngineOutputRecord.java:525|Raw write (
  0000: 16 03 03 00 28 00 00 00   00 00 00 00 00 09 AE 57  ....(..........W
  0010: EC 20 A9 DD 8F 44 DE 34   3D BE F8 44 F8 D9 7D F0  . ...D.4=..D....
  0020: 3F C1 62 92 97 40 2C BD   44 38 E0 8A 7E           ?.b..@,.D8...
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.504 CEST|SSLEngineInputRecord.java:177|Raw read (
  0000: 14 03 03 00 01 01                                  ......
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.505 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 change_cipher_spec, length = 1
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.505 CEST|ChangeCipherSpec.java:143|Consuming ChangeCipherSpec message
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.509 CEST|SSLEngineInputRecord.java:177|Raw read (
  0000: 16 03 03 00 28 FF 2B 4B   EC 5F F7 5C BA 8C 2F 34  ....(.+K._.\../4
  0010: 2A C1 FE 1C 6F 92 22 BC   B2 B4 E8 93 3C F2 20 48  *...o.".....<. H
  0020: 8E FE E2 60 93 7A 3D EA   B3 FA 66 05 F2           ...`.z=...f..
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.510 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 handshake, length = 40
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.514 CEST|SSLCipher.java:1629|Plaintext after DECRYPTION (
  0000: 14 00 00 0C AB A5 7E 92   19 0D F5 96 FA E2 D5 A4  ................
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.547 CEST|Finished.java:532|Consuming server Finished handshake message (
"Finished": {
  "verify data": {
    0000: AB A5 7E 92 19 0D F5 96   FA E2 D5 A4 
  }'}
)
15:44:52.586 [epollEventLoopGroup-2-1] DEBUG io.netty.handler.ssl.SslHandler - [id: 0xf55e3747, L:/10.156.123.175:40054 - R:dev-broker.your-server.de/185.201.147.157:8883] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.591 CEST|SSLEngineOutputRecord.java:267|WRITE: TLS12 application_data, length = 30
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.592 CEST|SSLCipher.java:1727|Plaintext before ENCRYPTION (
  0000: 10 1C 00 04 4D 51 54 54   05 02 00 3C 00 00 0F 63  ....MQTT...<...c
  0010: 6F 6E 6E 65 63 74 69 6F   6E 2D 74 65 73 74        onnection-test
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.595 CEST|SSLEngineOutputRecord.java:283|Raw write (
  0000: 17 03 03 00 36 00 00 00   00 00 00 00 01 F8 AA 69  ....6..........i
  0010: 92 64 CE 34 D2 5D 5A D1   4F 4D D3 34 D8 05 5A F2  .d.4.]Z.OM.4..Z.
  0020: C0 8E 63 8B 5A 51 E6 4A   4A A5 B0 E7 61 62 E5 69  ..c.ZQ.JJ...ab.i
  0030: 67 84 31 16 09 59 C5 6A   76 4C E1                 g.1..Y.jvL.
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.596 CEST|SSLEngineInputRecord.java:177|Raw read (
  0000: 15 03 03 00 1A FF 2B 4B   EC 5F F7 5C BB 9D 2E 7B  ......+K._.\....
  0010: FC DB 74 D3 A3 62 BF 86   66 8B 9C 03 04 55 93     ..t..b..f....U.
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.596 CEST|SSLEngineInputRecord.java:214|READ: TLSv1.2 alert, length = 26
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.598 CEST|SSLCipher.java:1629|Plaintext after DECRYPTION (
  0000: 01 00                                              ..
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.600 CEST|Alert.java:232|Received alert message (
"Alert": {
  "level"      : "warning",
  "description": "close_notify"
}
)
javax.net.ssl|WARNING|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.602 CEST|SSLEngineOutputRecord.java:168|outbound has closed, ignore outbound application data
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.603 CEST|SSLEngineOutputRecord.java:507|WRITE: TLS12 alert, length = 2
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.604 CEST|SSLCipher.java:1727|Plaintext before ENCRYPTION (
  0000: 01 00                                              ..
)
javax.net.ssl|DEBUG|19|epollEventLoopGroup-2-1|2019-10-15 15:44:52.609 CEST|SSLEngineOutputRecord.java:525|Raw write (
  0000: 15 03 03 00 1A 00 00 00   00 00 00 00 02 30 1D 82  .............0..
  0010: 69 FE 1A 9E BE 35 47 37   9E 67 DF 85 5A F4 E5     i....5G7.g..Z..
)
15:44:52.631 [epollEventLoopGroup-2-1] INFO  com.you.mqtt.ConnectionListener - Disconnected from MQTT broker.
15:44:52.641 [epollEventLoopGroup-2-1] ERROR com.you.mqtt.ConnectionListener - Server closed connection without DISCONNECT. Will try to reconnect.
15:44:52.666 [RxComputationThreadPool-1] ERROR com.you.mqtt.MqttConnector - connection exception
com.hivemq.client.mqtt.exceptions.ConnectionClosedException: Server closed connection without DISCONNECT.

Я использую Java 11 с клиентом HiveMQ MQTT версии 1.1.2 (последняя в репозитории maven).

Сервер - HAProxy, порт - 8883.

Я был бы очень благодарен, если у кого-то есть подсказка или подсказка о том, что здесь происходит и почему клиент не подключается к брокеру MQTT за HAProxy.

HAProxy Config

Следующий фрагмент является частью конфигурации haproxy, связанной с TCP-соединением. Конфигурация соответствует рекомендациям для брокера VerneMQ. 

global
        daemon
        user haproxy
        group haproxy
        chroot /var/empty
        maxconn 20000
        #log gi18hd.stackhero-network.com:514 local1 debug
        log /dev/log local0 debug
        #ssl
        tune.ssl.default-dh-param 2048
        #ssl-default-bind-options no-sslv3 no-tls-tickets force-tlsv12
        #ssl-default-bind-ciphers EECDH+AESGCM:EDH+AESGCM:AES256+EECDH:AES256+EDH

defaults
        log global
        #option httplog
        option tcplog
        timeout connect 5s
        timeout client 30s
        timeout client-fin 30s
        timeout server 300s
        timeout tunnel 1h

frontend front_tcp
        mode tcp
        option clitcpka # For TCP keep-alive

        log global
        option tcplog

        bind *:8883 ssl crt-list /etc/haproxy/server-dev-test-crt-list.txt

        use_backend sub_dev-broker if { ssl_fc_sni -i dev-broker.your-server.de }

backend sub_dev-broker
        mode tcp
        option redispatch
        balance leastconn
        server manager1 10.1.2.51:1883 check fall 1
        server manager2 10.1.2.52:1883 check fall 1
        server manager3 10.1.2.53:1883 check fall 1

VerneMQ Config

Наш брокер является кластерным (!) Брокером VerneMQ MQTT (https://vernemq.com/) в Docker Swarm. Протокол MQTT 5 включается через переменную env DOCKER_VERNEMQ_LISTENER__TCP__ALLOWED_PROTOCOL_VERSIONS=3,4,5. Мы используем внутренний прослушиватель на порту 18883, который отображается вне контейнера на 1883. Опять же: эта настройка работает с такими инструментами, как MQTTFx и другими MQTT3 на основе Pahoклиенты .

Соответствующая конфигурация docker-compose: 

version: '3.7'

services:
  mqttbroker0:
    image: erlio/docker-vernemq
    networks:
      - your-backend
    environment:
      - DOCKER_VERNEMQ_SWARM=1
      - DOCKER_VERNEMQ_ALLOW_ANONYMOUS=on
      - DOCKER_VERNEMQ_LOG__CONSOLE__LEVEL=debug

  mqttbroker:
    image: erlio/docker-vernemq
    depends_on:
      - mqttbroker0
    networks:
      - your-backend
    environment:
      - DOCKER_VERNEMQ_SWARM=1
      - DOCKER_VERNEMQ_DISCOVERY_NODE=mqttbroker0
      - DOCKER_VERNEMQ_ALLOW_ANONYMOUS=on
      - DOCKER_NET_INTERFACE=eth1
      - DOCKER_VERNEMQ_LOG__CONSOLE__LEVEL=debug
      - DOCKER_VERNEMQ_LISTENER__TCP__SERVER = 0.0.0.0:18883
      - DOCKER_VERNEMQ_LISTENER__TCP__ALLOWED_PROTOCOL_VERSIONS=3,4,5
    ports:
      - "1883:18883"
    deploy:
      replicas: 2

networks:
  your-backend:
    external: true

Обновление: рукопожатие TLS в порядке, haproxy не может найти сервер

Соединениезакрывается после установления связи между клиентом и сервером. Журналы HAProxy 

front_tcp~ front_tcp/<NOSRV> -1/-1/965 0 SC 2/1/0/0/0 0/0

В нашей конфигурации haproxy есть условие: use_backend sub_dev-broker if { ssl_fc_sni -i dev-broker.your-server.de }. Это позволяет нам использовать только один экземпляр haproxy и переключаться между различными конечными точками (Серверы DEV и TEST в нашем случае).

Запрос, поступающий от клиента после рукопожатия, не может быть перенаправлен на внутренний сервер. HAProxy реагируетс NOSRV. Похоже, что запрос не содержит имя хоста сервера, поэтому условие if не выполняется.

Обновление: клиент HiveMQ 1.1.2 не использует SNI

Клиент HiveMQ 1.1.2Milestone 1.1.3 не использует расширение Server Name Indication TLS. Мы используем информацию SNI для коммутатора в нашей конфигурации HAProxy. Поскольку в настоящий момент я не вижу обходного пути, и эта функциональность не является критической для подписчика MQTT, я буду ждать следующего выпуска клиента HiveMQ.

Спасибо всем участникам за мысли и подсказки!

1 Ответ

2 голосов
/ 16 октября 2019

Как я понимаю из предоставленного журнала, похоже, нет ничего плохого в рукопожатии TLS.

После того, как рукопожатие закончено, клиент отправляет пакет MQTT CONNECT. Поскольку вы используете клиент HiveMQ с MQTT 5 в качестве версии протокола, он будет содержать флаг, что ожидается MQTT 5. Теперь, если используемый брокер не может справиться с этим, он закроет соединение (ошибка протокола).

Это также объясняет, почему вам удалось соединить

с MQTTFx ис MQTT3 Paho.

В качестве альтернативы вы можете изменить создание клиента MQTT на: 

return MqttClient.builder()
            ...
            .useMqttVersion3()
            .buildAsync();

Но поскольку вашей первоначальной целью было использование общих подписок, изменение / обновление брокера может привести квсе еще необходимо.

Не могли бы вы предоставить больше информации об используемом брокере?

...