diff --git a/kotlin-mbedtls-metrics/src/main/kotlin/org/opencoap/ssl/transport/metrics/micrometer/DtlsServerMetricsCallbacks.kt b/kotlin-mbedtls-metrics/src/main/kotlin/org/opencoap/ssl/transport/metrics/micrometer/DtlsServerMetricsCallbacks.kt index fad4f6c2..3da9acf7 100644 --- a/kotlin-mbedtls-metrics/src/main/kotlin/org/opencoap/ssl/transport/metrics/micrometer/DtlsServerMetricsCallbacks.kt +++ b/kotlin-mbedtls-metrics/src/main/kotlin/org/opencoap/ssl/transport/metrics/micrometer/DtlsServerMetricsCallbacks.kt @@ -54,10 +54,10 @@ class DtlsServerMetricsCallbacks( handshakesInitiated.increment() } - override fun handshakeFinished(adr: InetSocketAddress, hanshakeStartTimestamp: Long, reason: DtlsSessionLifecycleCallbacks.Reason, throwable: Throwable?) = when { + override fun handshakeFinished(adr: InetSocketAddress, hanshakeStartTimestamp: Long, hanshakeFinishTimestamp: Long, reason: DtlsSessionLifecycleCallbacks.Reason, throwable: Throwable?) = when { throwable is HelloVerifyRequired -> {} // Skip HelloVerifyRequired handshake states reason == DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED -> - handshakesSucceeded.record(System.currentTimeMillis() - hanshakeStartTimestamp, TimeUnit.MILLISECONDS) + handshakesSucceeded.record(hanshakeFinishTimestamp - hanshakeStartTimestamp, TimeUnit.MILLISECONDS) reason == DtlsSessionLifecycleCallbacks.Reason.FAILED -> handshakesFailedBuilder.reasonTag(throwable).register(registry).increment() reason == DtlsSessionLifecycleCallbacks.Reason.EXPIRED -> diff --git a/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/SslContext.kt b/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/SslContext.kt index b1a5da5b..99ee7e82 100644 --- a/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/SslContext.kt +++ b/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/SslContext.kt @@ -68,6 +68,7 @@ class SslHandshakeContext internal constructor( ) : SslContext { private val logger = LoggerFactory.getLogger(javaClass) val startTimestamp: Long = System.currentTimeMillis() + var finishTimestamp: Long = 0 private var stepTimeout: Duration = Duration.ZERO fun step(send: (ByteBuffer) -> Unit): SslContext = step0(null, send) @@ -86,10 +87,12 @@ class SslHandshakeContext internal constructor( MbedtlsApi.MBEDTLS_ERR_SSL_WANT_READ -> return this MbedtlsApi.MBEDTLS_ERR_SSL_HELLO_VERIFY_REQUIRED -> throw HelloVerifyRequired 0 -> SslSession(conf, sslContext, cid).also { - logger.info("[{}] DTLS connected in {}ms {}", peerAdr, System.currentTimeMillis() - startTimestamp, it) + finishTimestamp = System.currentTimeMillis() + logger.info("[{}] DTLS connected in {}ms {}", peerAdr, finishTimestamp - startTimestamp, it) } else -> throw SslException.from(ret).also { + finishTimestamp = System.currentTimeMillis() logger.debug("[{}] DTLS failed handshake: {}", peerAdr, it.message) } } diff --git a/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsServer.kt b/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsServer.kt index 0c2a63fc..6e9ca3ad 100644 --- a/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsServer.kt +++ b/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsServer.kt @@ -172,8 +172,8 @@ class DtlsServer( } is SslSession -> { - reportHandshakeFinished(DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) sessions[peerAddress] = DtlsSession(newCtx, peerAddress) + reportHandshakeFinished(DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) } } } catch (ex: Exception) { @@ -185,16 +185,16 @@ class DtlsServer( else -> logger.error(ex.toString(), ex) } - reportHandshakeFinished(DtlsSessionLifecycleCallbacks.Reason.FAILED, ex) closeAndRemove() + reportHandshakeFinished(DtlsSessionLifecycleCallbacks.Reason.FAILED, ex) } return ReceiveResult.Handled } fun timeout() { - reportHandshakeFinished(DtlsSessionLifecycleCallbacks.Reason.EXPIRED) closeAndRemove() logger.warn("[{}] DTLS handshake expired", peerAddress) + reportHandshakeFinished(DtlsSessionLifecycleCallbacks.Reason.EXPIRED) } override fun storeAndClose0() = close() @@ -202,11 +202,11 @@ class DtlsServer( override fun close() = ctx.close() private fun reportHandshakeStarted() { - lifecycleCallbacks.handshakeStarted(peerAddress) + executor.supply { lifecycleCallbacks.handshakeStarted(peerAddress) } } private fun reportHandshakeFinished(reason: DtlsSessionLifecycleCallbacks.Reason, err: Throwable? = null) { - lifecycleCallbacks.handshakeFinished(peerAddress, ctx.startTimestamp, reason, err) + executor.supply { lifecycleCallbacks.handshakeFinished(peerAddress, ctx.startTimestamp, ctx.finishTimestamp, reason, err) } } } @@ -272,26 +272,26 @@ class DtlsServer( try { return ctx.encrypt(plainPacket) } catch (ex: SslException) { + closeAndRemove() logger.warn("[{}] DTLS failed: {}", peerAddress, ex.message) reportSessionFinished(DtlsSessionLifecycleCallbacks.Reason.FAILED, ex) - closeAndRemove() throw ex } } fun timeout() { - lifecycleCallbacks.sessionFinished(peerAddress, DtlsSessionLifecycleCallbacks.Reason.EXPIRED) sessions.remove(peerAddress, this) - logger.info("[{}] DTLS connection expired", peerAddress) storeAndClose() + logger.info("[{}] DTLS connection expired", peerAddress) + lifecycleCallbacks.sessionFinished(peerAddress, DtlsSessionLifecycleCallbacks.Reason.EXPIRED) } private fun reportSessionStarted() { - lifecycleCallbacks.sessionStarted(peerAddress, ctx.cipherSuite, ctx.reloaded) + executor.supply { lifecycleCallbacks.sessionStarted(peerAddress, ctx.cipherSuite, ctx.reloaded) } } private fun reportSessionFinished(reason: DtlsSessionLifecycleCallbacks.Reason, err: Throwable? = null) { - lifecycleCallbacks.sessionFinished(peerAddress, reason, err) + executor.supply { lifecycleCallbacks.sessionFinished(peerAddress, reason, err) } } } } diff --git a/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsSessionLifecycleCallbacks.kt b/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsSessionLifecycleCallbacks.kt index 565a2504..38de0e4c 100644 --- a/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsSessionLifecycleCallbacks.kt +++ b/kotlin-mbedtls/src/main/kotlin/org/opencoap/ssl/transport/DtlsSessionLifecycleCallbacks.kt @@ -23,7 +23,7 @@ interface DtlsSessionLifecycleCallbacks { SUCCEEDED, FAILED, CLOSED, EXPIRED } fun handshakeStarted(adr: InetSocketAddress) = Unit - fun handshakeFinished(adr: InetSocketAddress, hanshakeStartTimestamp: Long, reason: Reason, throwable: Throwable? = null) = Unit + fun handshakeFinished(adr: InetSocketAddress, hanshakeStartTimestamp: Long, hanshakeFinishTimestamp: Long, reason: Reason, throwable: Throwable? = null) = Unit fun sessionStarted(adr: InetSocketAddress, cipherSuite: String, reloaded: Boolean) = Unit fun sessionFinished(adr: InetSocketAddress, reason: Reason, throwable: Throwable? = null) = Unit } diff --git a/kotlin-mbedtls/src/test/kotlin/org/opencoap/ssl/transport/DtlsServerTransportTest.kt b/kotlin-mbedtls/src/test/kotlin/org/opencoap/ssl/transport/DtlsServerTransportTest.kt index 1c9a04f6..6fea7730 100644 --- a/kotlin-mbedtls/src/test/kotlin/org/opencoap/ssl/transport/DtlsServerTransportTest.kt +++ b/kotlin-mbedtls/src/test/kotlin/org/opencoap/ssl/transport/DtlsServerTransportTest.kt @@ -20,7 +20,6 @@ import io.mockk.clearMocks import io.mockk.confirmVerified import io.mockk.mockk import io.mockk.verify -import io.mockk.verifyOrder import org.awaitility.kotlin.await import org.junit.jupiter.api.AfterEach import org.junit.jupiter.api.Assertions.assertEquals @@ -113,11 +112,11 @@ class DtlsServerTransportTest { val clientAddress = client.localAddress() client.close() - verifyOrder { + verify { sslLifecycleCallbacks.handshakeStarted(clientAddress) - sslLifecycleCallbacks.handshakeFinished(clientAddress, any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) + sslLifecycleCallbacks.handshakeFinished(clientAddress, any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) sslLifecycleCallbacks.handshakeStarted(clientAddress) - sslLifecycleCallbacks.handshakeFinished(clientAddress, any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) + sslLifecycleCallbacks.handshakeFinished(clientAddress, any(), any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) sslLifecycleCallbacks.sessionStarted(clientAddress, any(), false) } @@ -165,11 +164,11 @@ class DtlsServerTransportTest { assertEquals(0, server.numberOfSessions()) } assertFalse(srvReceive.isDone) - verifyOrder { + verify { sslLifecycleCallbacks.handshakeStarted(any()) - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) sslLifecycleCallbacks.handshakeStarted(any()) - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(SslException::class)) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(SslException::class)) } verify(exactly = 0) { @@ -193,9 +192,9 @@ class DtlsServerTransportTest { client.close() - verifyOrder { + verify { sslLifecycleCallbacks.handshakeStarted(any()) - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) sslLifecycleCallbacks.sessionStarted(any(), any(), any()) } } @@ -237,11 +236,11 @@ class DtlsServerTransportTest { cliChannel.close() verify(atMost = 100) { - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(SslException::class)) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(SslException::class)) } verify(exactly = 0) { - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) } } @@ -286,7 +285,7 @@ class DtlsServerTransportTest { assertEquals(0, server.numberOfSessions()) } - verifyOrder { + verify { sslLifecycleCallbacks.sessionStarted(any(), any(), any()) sslLifecycleCallbacks.sessionFinished(any(), DtlsSessionLifecycleCallbacks.Reason.CLOSED) } @@ -308,12 +307,12 @@ class DtlsServerTransportTest { // No handshake failures other than HelloVerifyRequired verify(exactly = 0) { - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, not(ofType(HelloVerifyRequired::class))) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, not(ofType(HelloVerifyRequired::class))) } // One successful handshake must happen verify(exactly = 1) { - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) } } @@ -335,7 +334,7 @@ class DtlsServerTransportTest { cli.close() verify(exactly = 1) { - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, and(ofType(SslException::class), not(ofType(HelloVerifyRequired::class)))) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, and(ofType(SslException::class), not(ofType(HelloVerifyRequired::class)))) } } @@ -387,11 +386,11 @@ class DtlsServerTransportTest { } client.close() - verifyOrder() { + verify() { sslLifecycleCallbacks.handshakeStarted(any()) - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.FAILED, ofType(HelloVerifyRequired::class)) sslLifecycleCallbacks.handshakeStarted(any()) - sslLifecycleCallbacks.handshakeFinished(any(), any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) + sslLifecycleCallbacks.handshakeFinished(any(), any(), any(), DtlsSessionLifecycleCallbacks.Reason.SUCCEEDED) sslLifecycleCallbacks.sessionStarted(any(), any(), false) sslLifecycleCallbacks.sessionFinished(any(), DtlsSessionLifecycleCallbacks.Reason.EXPIRED) sslLifecycleCallbacks.sessionStarted(any(), any(), true)