leshan: DTLS Full Handshake failure

I’m testing client/server DTLS communication with leshan-server-demo and leshan-client-demo v1.3.0 (californium 2.6.0). Leshan client fails to keep connecting with Leshan server after a period of time due to an error of DTLS Full Handshake initiated by client : FAILED (Received ‘fatal alert/HANDSHAKE_FAILURE’). Leshan server restart is required to allow the client to connect again. Please advise on how to solve this issue.

client log

2021-01-27 07:30:21.143 [RegistrationEngine#0] INFO  o.e.l.c.e.DefaultRegistrationEngine - Trying to update registration to coaps://219.x.x.x:5684 (response timeout 120000ms)...
2021-01-27 07:30:21.143 [RegistrationEngine#0] INFO  o.e.l.c.c.CaliforniumEndpointsManager - Clear DTLS session for server coaps://219.x.x.x:5684
2021-01-27 07:30:21.144 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.l.client.demo.LeshanClientDemo - DTLS Full Handshake initiated by client : STARTED ...
2021-01-27 07:30:21.144 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 1, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:30:21.144 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:30:21.147 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 3, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:30:21.148 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:30:21.154 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.l.client.demo.LeshanClientDemo - DTLS Full Handshake initiated by client : FAILED (Received 'fatal alert/HANDSHAKE_FAILURE')
2021-01-27 07:30:21.155 [RegistrationEngine#0] INFO  o.e.l.c.e.DefaultRegistrationEngine - Unable to send update request : Received 'fatal alert/HANDSHAKE_FAILURE'
2021-01-27 07:30:21.155 [RegistrationEngine#0] INFO  o.e.l.c.e.DefaultRegistrationEngine - Trying to register to coaps://219.x.x.x:5684 ...
2021-01-27 07:30:21.156 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.l.client.demo.LeshanClientDemo - DTLS Full Handshake initiated by client : STARTED ...
2021-01-27 07:30:21.156 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 1, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:30:21.156 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:30:21.160 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 3, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:30:21.160 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:30:21.165 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.l.client.demo.LeshanClientDemo - DTLS Full Handshake initiated by client : FAILED (Received 'fatal alert/HANDSHAKE_FAILURE')
2021-01-27 07:30:21.165 [RegistrationEngine#0] INFO  o.e.l.c.e.DefaultRegistrationEngine - Unable to send register request : Received 'fatal alert/HANDSHAKE_FAILURE'
2021-01-27 07:30:21.165 [RegistrationEngine#0] INFO  o.e.l.c.e.DefaultRegistrationEngine - Try to register to coaps://219.x.x.x:5684 again in 600s...
2021-01-27 07:30:31.125 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] INFO  o.e.l.client.demo.LeshanClientDemo - DTLS Full Handshake initiated by server : STARTED ...
2021-01-27 07:30:31.133 [DTLS-Timer-0.0.0.0/0.0.0.0:58070#1] WARN  o.e.c.scandium.dtls.ServerHandshaker - Cannot process handshake message from peer [/219.x.x.x:5684] due to [null]
java.lang.NullPointerException: null
	at org.eclipse.californium.scandium.dtls.CertificateRequest.addCerticiateAuthorities(CertificateRequest.java:421)
	at org.eclipse.californium.scandium.dtls.ServerHandshaker.createCertificateRequest(ServerHandshaker.java:576)
	at org.eclipse.californium.scandium.dtls.ServerHandshaker.receivedClientHello(ServerHandshaker.java:449)
	at org.eclipse.californium.scandium.dtls.ServerHandshaker.doProcessMessage(ServerHandshaker.java:225)
	at org.eclipse.californium.scandium.dtls.Handshaker.processNextHandshakeMessages(Handshaker.java:854)
	at org.eclipse.californium.scandium.dtls.Handshaker.processNextMessages(Handshaker.java:702)
	at org.eclipse.californium.scandium.dtls.Handshaker.processMessage(Handshaker.java:660)
	at org.eclipse.californium.scandium.DTLSConnector.startNewHandshake(DTLSConnector.java:2098)
	at org.eclipse.californium.scandium.DTLSConnector.processClientHello(DTLSConnector.java:1989)
	at org.eclipse.californium.scandium.DTLSConnector.access$1200(DTLSConnector.java:231)
	at org.eclipse.californium.scandium.DTLSConnector$14.run(DTLSConnector.java:1929)
	at org.eclipse.californium.elements.util.SerialExecutor$1.run(SerialExecutor.java:289)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
	at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)

server log

2021-01-27 07:29:28.137 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#20] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:29:28.141 [CoapServer(main)#4] INFO  o.e.l.server.demo.LeshanServerDemo - Accepted registration from endpoint payphonekioskPg001 at /218.x.x.x:58070
2021-01-27 07:30:31.116 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#21] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 1, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:30:31.116 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#21] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:30:31.122 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#16] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 3, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:30:31.122 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#16] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:30:31.138 [qtp1003693033-32] WARN  o.e.l.s.demo.servlet.ClientServlet - Unexpected exception
org.eclipse.leshan.core.request.exception.SendFailedException: Request CON-GET    MID=17697, Token=8C5BA5578EC0D4A7, OptionSet={"Uri-Path":["26241","0"]}, Received 'fatal alert/INTERNAL_ERROR' no payload cannot be sent
        at org.eclipse.leshan.core.californium.CoapSyncRequestObserver.onSendError(CoapSyncRequestObserver.java:106)
        at org.eclipse.californium.core.coap.Message.setSendError(Message.java:1063)
        at org.eclipse.californium.core.coap.Request.setSendError(Request.java:1132)
        at org.eclipse.californium.core.network.CoapEndpoint$SendingCallback.onError(CoapEndpoint.java:1531)
        at org.eclipse.californium.elements.RawData.onError(RawData.java:303)
        at org.eclipse.californium.scandium.DTLSConnector$2.handshakeFailed(DTLSConnector.java:521)
        at org.eclipse.californium.scandium.dtls.Handshaker.handshakeFailed(Handshaker.java:1882)
        at org.eclipse.californium.scandium.DTLSConnector.processAlertRecord(DTLSConnector.java:1732)
        at org.eclipse.californium.scandium.DTLSConnector.processRecord(DTLSConnector.java:1503)
        at org.eclipse.californium.scandium.DTLSConnector$12.run(DTLSConnector.java:1365)
        at org.eclipse.californium.elements.util.SerialExecutor$1.run(SerialExecutor.java:289)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: org.eclipse.californium.scandium.dtls.HandshakeException: Received 'fatal alert/INTERNAL_ERROR'
        at org.eclipse.californium.scandium.DTLSConnector.processAlertRecord(DTLSConnector.java:1722)
        ... 6 common frames omitted
2021-01-27 07:31:31.111 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#23] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 1, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:31:31.111 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#23] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436
2021-01-27 07:31:31.114 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#14] INFO  o.e.c.scandium.dtls.DTLSFlight - Prepare flight 3, using max. datagram size 1436, max. fragment size 16384 [mhm=false, mr=true]
2021-01-27 07:31:31.114 [DTLS-Worker-0.0.0.0/0.0.0.0:5684#14] INFO  o.e.c.scandium.dtls.DTLSFlight - Effective max. datagram size 1436

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 29 (13 by maintainers)

Commits related to this issue

Most upvoted comments

@francopo : release 1.3.1 is out.

+1
sbernard31 on Feb 5, 2021

No, I wasn’t faced by such issues. It depends heavily on the exact dtls-configuration, so I’m not sure, what caused it. For the future, I add a detailed logging for the client and server hello in that case (for Californium 3.0).

+1
boaks on Jan 29, 2021

I didn’t read the whole thread too carefully … I just jumped to the first and the last. If the null is fixed, great.

Which detail caused the handshake in the last example fails, is for me unclear and requires either a ip-capture or extended logging messages.

+1
boaks on Jan 29, 2021
Read more comments on GitHub
← leshan: DDFFileParser does not handle resource without a data type ("none")
leshan: Problem of sending msg to client on Linux Platform →