search

eclipse-leshan / leshan

Java Library for LWM2M
https://www.eclipse.org/leshan/
BSD 3-Clause "New" or "Revised" License
649 stars 406 forks source link

sequans NBIOT module cant connect in secured mode #650

Closed kalyanjanaki closed 5 years ago

kalyanjanaki commented 5 years ago

Hello

We are working on NBIOT project. The sequans Module is able to connect to leshan test sandbox in both non-secured and secured mode. When we try to deploy the leshan server in our private cloud by compiling the leshan-server-demo it is able to connect with non-secured mode by not in secured mode. How can i debug the issue. I dont see any thing on console log when clinet submits request in secured mode.

Regards Kalyan

sbernard31 commented 5 years ago

Which credential type are you using (PSK, RPK, X509) ?

To find your issue you could :

  1. Look at leshan-server-demo logs (default are available in standard output), if this is not enough you could use a more verbose configuration : look at the FAQ.
  2. Use wireshark to see what happens at DTLS level.
  3. Search in your device log :grin:
kalyanjanaki commented 5 years ago

Thanks for the response. We are using PSK mode of DTLS. When i try to use test client program leshan-cleint-demo it works with DTLS but the real sequans module is able to work only in non-secure mode . I will try to change loglevel and use wireshark technique as suggested.

kalyanjanaki commented 5 years ago

Hello

Below is the logcapture while trying to establish DTLS session with PSK.

2019-02-06 22:47:59,001 DEBUG SecurityServlet - New security info for end-point 359738090029648: SecurityInfo [endpoint=359738090029648, identity=6a78897b8812af476f02070518f96fffde73b15e, rawPublicKey=null, useX509Cert=false]
2019-02-06 22:51:07,663 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:07,665 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:07,667 DEBUG Record - Parsing message without a session
2019-02-06 22:51:07,667 DEBUG Record - Parsing HANDSHAKE message plaintext [null]
2019-02-06 22:51:07,674 DEBUG HelloExtensions - Peer included an unknown extension type code [13] in its Hello message
2019-02-06 22:51:07,675 DEBUG HelloExtensions - Peer included an unknown extension type code [23] in its Hello message
2019-02-06 22:51:07,676 DEBUG DTLSConnector - Processing CLIENT_HELLO from peer [/192.168.131.43:42302]
2019-02-06 22:51:07,714 DEBUG DTLSConnector - Verifying client IP address [/192.168.131.43:42302] using HELLO_VERIFY_REQUEST
2019-02-06 22:51:09,281 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:09,283 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:09,286 DEBUG Record - Parsing message without a session
2019-02-06 22:51:09,286 DEBUG Record - Parsing HANDSHAKE message plaintext [null]
2019-02-06 22:51:09,287 DEBUG HelloExtensions - Peer included an unknown extension type code [13] in its Hello message
2019-02-06 22:51:09,287 DEBUG HelloExtensions - Peer included an unknown extension type code [23] in its Hello message
2019-02-06 22:51:09,287 DEBUG DTLSConnector - Processing CLIENT_HELLO from peer [/192.168.131.43:42302]
2019-02-06 22:51:09,289 DEBUG InMemoryConnectionStore - connection: add /192.168.131.43:42302
2019-02-06 22:51:09,294 DEBUG DTLSSession - Setting MTU for peer [/192.168.131.43:42302] to 9001 bytes
2019-02-06 22:51:09,295 DEBUG DTLSSession - Setting maximum fragment length for peer [/192.168.131.43:42302] to 8912 bytes
2019-02-06 22:51:09,297 DEBUG DTLSSession - Checking sequence no [1] using bit mask [10] against received records [0] with lower boundary [0]
2019-02-06 22:51:09,299 DEBUG ServerHandshaker - Processing Handshake (22) message from peer [/192.168.131.43:42302]
2019-02-06 22:51:09,299 DEBUG Connection - Handshake with [/192.168.131.43:42302] has been started
2019-02-06 22:51:09,310 DEBUG ECDHECryptography$SupportedGroup - Group [secp192k1] is not supported by JRE
2019-02-06 22:51:09,311 DEBUG ECDHECryptography$SupportedGroup - Group [secp192r1] is not supported by JRE
2019-02-06 22:51:09,311 DEBUG ECDHECryptography$SupportedGroup - Group [secp224k1] is not supported by JRE
2019-02-06 22:51:09,317 DEBUG ECDHECryptography$SupportedGroup - Group [secp224r1] is not supported by JRE
2019-02-06 22:51:09,318 DEBUG ECDHECryptography$SupportedGroup - Group [secp256k1] is not supported by JRE
2019-02-06 22:51:09,319 DEBUG ECDHECryptography$SupportedGroup - Group [brainpoolP256r1] is not supported by JRE
2019-02-06 22:51:09,320 DEBUG ECDHECryptography$SupportedGroup - Group [brainpoolP384r1] is not supported by JRE
2019-02-06 22:51:09,320 DEBUG ECDHECryptography$SupportedGroup - Group [brainpoolP512r1] is not supported by JRE
2019-02-06 22:51:09,321 DEBUG ServerHandshaker - Negotiated cipher suite [TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256] with peer [/192.168.131.43:42302]
2019-02-06 22:51:09,326 DEBUG X509CertPath - Current Subject DN: CN=Leshan Server Demo
2019-02-06 22:51:09,339 DEBUG DTLSConnector - Sending flight of 5 message(s) to peer [/192.168.131.43:42302] using 1 datagram(s) of max. 9001 bytes
2019-02-06 22:51:09,340 DEBUG ServerHandshaker - Processed CLIENT_HELLO (1) message with message sequence no [1] from peer [/192.168.131.43:42302]
2019-02-06 22:51:09,340 DEBUG DTLSSession - Updated receive window with sequence number [1]: new upper boundary [63], new bit vector [10]
2019-02-06 22:51:09,480 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:09,482 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:09,483 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:51:09,483 DEBUG HelloExtensions - Peer included an unknown extension type code [13] in its Hello message
2019-02-06 22:51:09,484 DEBUG HelloExtensions - Peer included an unknown extension type code [23] in its Hello message
2019-02-06 22:51:09,484 DEBUG DTLSConnector - Processing CLIENT_HELLO from peer [/192.168.131.43:42302]
2019-02-06 22:51:09,485 DEBUG DTLSSession - Checking sequence no [2] using bit mask [100] against received records [10] with lower boundary [0]
2019-02-06 22:51:09,485 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [1] < next_receive_seq [2]
2019-02-06 22:51:09,485 DEBUG DTLSSession - Updated receive window with sequence number [2]: new upper boundary [63], new bit vector [110]
2019-02-06 22:51:10,340 DEBUG DTLSConnector - Re-transmitting flight for [/192.168.131.43:42302], [3] retransmissions left
2019-02-06 22:51:10,341 DEBUG DTLSConnector - Sending flight of 5 message(s) to peer [/192.168.131.43:42302] using 1 datagram(s) of max. 9001 bytes
2019-02-06 22:51:10,990 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:10,991 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:10,991 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:51:10,991 DEBUG DTLSSession - Checking sequence no [3] using bit mask [1000] against received records [110] with lower boundary [0]
2019-02-06 22:51:10,992 DEBUG ServerHandshaker - Processing Handshake (22) message from peer [/192.168.131.43:42302]
2019-02-06 22:51:10,999 DEBUG ServerHandshaker - Processed CLIENT_KEY_EXCHANGE (16) message with message sequence no [2] from peer [/192.168.131.43:42302]
2019-02-06 22:51:10,999 DEBUG DTLSSession - Updated receive window with sequence number [3]: new upper boundary [63], new bit vector [1110]
2019-02-06 22:51:11,020 DEBUG DTLSConnector - Received 2 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:11,020 DEBUG DTLSSession - Checking sequence no [4] using bit mask [10000] against received records [1110] with lower boundary [0]
2019-02-06 22:51:11,021 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:51:11,021 DEBUG DTLSSession - Updated receive window with sequence number [4]: new upper boundary [63], new bit vector [11110]
2019-02-06 22:51:11,022 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:11,022 DEBUG DTLSSession - Checking sequence no [0] using bit mask [1] against received records [11110] with lower boundary [0]
2019-02-06 22:51:11,022 DEBUG Handshaker$InboundMessageBuffer - Queueing HANDSHAKE message from future epoch [1] > current epoch [0]
2019-02-06 22:51:11,041 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:11,041 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:11,041 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:51:11,041 DEBUG DTLSSession - Checking sequence no [4] using bit mask [10000] against received records [11110] with lower boundary [0]
2019-02-06 22:51:11,042 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:11,042 DEBUG DTLSSession - Checking sequence no [5] using bit mask [100000] against received records [11110] with lower boundary [0]
2019-02-06 22:51:11,042 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:51:11,042 DEBUG DTLSSession - Updated receive window with sequence number [5]: new upper boundary [63], new bit vector [111110]
2019-02-06 22:51:11,080 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:11,080 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:11,081 DEBUG DTLSSession - Checking sequence no [1] using bit mask [10] against received records [111110] with lower boundary [0]
2019-02-06 22:51:12,831 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:12,831 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:12,831 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:51:12,831 DEBUG DTLSSession - Checking sequence no [6] using bit mask [1000000] against received records [111110] with lower boundary [0]
2019-02-06 22:51:12,831 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:51:12,831 DEBUG DTLSSession - Updated receive window with sequence number [6]: new upper boundary [63], new bit vector [1111110]
2019-02-06 22:51:12,832 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:12,832 DEBUG DTLSSession - Checking sequence no [7] using bit mask [10000000] against received records [1111110] with lower boundary [0]
2019-02-06 22:51:12,832 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:51:12,832 DEBUG DTLSSession - Updated receive window with sequence number [7]: new upper boundary [63], new bit vector [11111110]
2019-02-06 22:51:12,832 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:12,833 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:12,833 DEBUG DTLSSession - Checking sequence no [2] using bit mask [100] against received records [11111110] with lower boundary [0]
2019-02-06 22:51:14,920 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:14,921 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:14,921 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:51:14,921 DEBUG DTLSSession - Checking sequence no [8] using bit mask [100000000] against received records [11111110] with lower boundary [0]
2019-02-06 22:51:14,921 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:51:14,921 DEBUG DTLSSession - Updated receive window with sequence number [8]: new upper boundary [63], new bit vector [111111110]
2019-02-06 22:51:14,922 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:14,922 DEBUG DTLSSession - Checking sequence no [9] using bit mask [1000000000] against received records [111111110] with lower boundary [0]
2019-02-06 22:51:14,923 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:51:14,923 DEBUG DTLSSession - Updated receive window with sequence number [9]: new upper boundary [63], new bit vector [1111111110]
2019-02-06 22:51:14,950 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:14,950 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:14,951 DEBUG DTLSSession - Checking sequence no [3] using bit mask [1000] against received records [1111111110] with lower boundary [0]
2019-02-06 22:51:19,490 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:19,491 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:19,491 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:51:19,491 DEBUG DTLSSession - Checking sequence no [10] using bit mask [10000000000] against received records [1111111110] with lower boundary [0]
2019-02-06 22:51:19,491 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:51:19,491 DEBUG DTLSSession - Updated receive window with sequence number [10]: new upper boundary [63], new bit vector [11111111110]
2019-02-06 22:51:19,491 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:19,492 DEBUG DTLSSession - Checking sequence no [11] using bit mask [100000000000] against received records [11111111110] with lower boundary [0]
2019-02-06 22:51:19,492 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:51:19,492 DEBUG DTLSSession - Updated receive window with sequence number [11]: new upper boundary [63], new bit vector [111111111110]
2019-02-06 22:51:19,504 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:19,504 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:19,504 DEBUG DTLSSession - Checking sequence no [4] using bit mask [10000] against received records [111111111110] with lower boundary [0]
2019-02-06 22:51:27,110 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:27,111 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:27,111 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:27,111 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:51:27,111 DEBUG DTLSSession - Checking sequence no [12] using bit mask [1000000000000] against received records [111111111110] with lower boundary [0]
2019-02-06 22:51:27,111 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:51:27,111 DEBUG DTLSSession - Updated receive window with sequence number [12]: new upper boundary [63], new bit vector [1111111111110]
2019-02-06 22:51:27,111 DEBUG DTLSSession - Checking sequence no [13] using bit mask [10000000000000] against received records [1111111111110] with lower boundary [0]
2019-02-06 22:51:27,112 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:51:27,112 DEBUG DTLSSession - Updated receive window with sequence number [13]: new upper boundary [63], new bit vector [11111111111110]
2019-02-06 22:51:27,140 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:51:27,140 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:51:27,140 DEBUG DTLSSession - Checking sequence no [5] using bit mask [100000] against received records [11111111111110] with lower boundary [0]
2019-02-06 22:52:15,447 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:52:15,448 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.43:42302]
2019-02-06 22:52:15,448 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:52:15,448 DEBUG DTLSSession - Checking sequence no [16] using bit mask [10000000000000000] against received records [11111111111110] with lower boundary [0]
2019-02-06 22:52:15,448 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:52:15,448 DEBUG DTLSSession - Updated receive window with sequence number [16]: new upper boundary [63], new bit vector [10011111111111110]
2019-02-06 22:52:15,688 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:52:15,689 DEBUG DTLSSession - Checking sequence no [17] using bit mask [100000000000000000] against received records [10011111111111110] with lower boundary [0]
2019-02-06 22:52:15,689 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:52:15,689 DEBUG DTLSSession - Updated receive window with sequence number [17]: new upper boundary [63], new bit vector [110011111111111110]
2019-02-06 22:54:38,687 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:38,687 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:38,687 DEBUG Record - Parsing message without a session
2019-02-06 22:54:38,687 DEBUG Record - Parsing HANDSHAKE message plaintext [null]
2019-02-06 22:54:38,687 DEBUG HelloExtensions - Peer included an unknown extension type code [13] in its Hello message
2019-02-06 22:54:38,687 DEBUG HelloExtensions - Peer included an unknown extension type code [23] in its Hello message
2019-02-06 22:54:38,688 DEBUG DTLSConnector - Processing CLIENT_HELLO from peer [/192.168.131.5:36024]
2019-02-06 22:54:38,688 DEBUG DTLSConnector - Verifying client IP address [/192.168.131.5:36024] using HELLO_VERIFY_REQUEST
2019-02-06 22:54:39,046 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:39,046 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:39,046 DEBUG Record - Parsing message without a session
2019-02-06 22:54:39,046 DEBUG Record - Parsing HANDSHAKE message plaintext [null]
2019-02-06 22:54:39,047 DEBUG HelloExtensions - Peer included an unknown extension type code [13] in its Hello message
2019-02-06 22:54:39,047 DEBUG HelloExtensions - Peer included an unknown extension type code [23] in its Hello message
2019-02-06 22:54:39,047 DEBUG DTLSConnector - Processing CLIENT_HELLO from peer [/192.168.131.5:36024]
2019-02-06 22:54:39,047 DEBUG InMemoryConnectionStore - connection: add /192.168.131.5:36024
2019-02-06 22:54:39,047 DEBUG DTLSSession - Setting MTU for peer [/192.168.131.5:36024] to 9001 bytes
2019-02-06 22:54:39,047 DEBUG DTLSSession - Setting maximum fragment length for peer [/192.168.131.5:36024] to 8912 bytes
2019-02-06 22:54:39,047 DEBUG DTLSSession - Checking sequence no [1] using bit mask [10] against received records [0] with lower boundary [0]
2019-02-06 22:54:39,047 DEBUG ServerHandshaker - Processing Handshake (22) message from peer [/192.168.131.5:36024]
2019-02-06 22:54:39,048 DEBUG Connection - Handshake with [/192.168.131.5:36024] has been started
2019-02-06 22:54:39,048 DEBUG ServerHandshaker - Negotiated cipher suite [TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256] with peer [/192.168.131.5:36024]
2019-02-06 22:54:39,048 DEBUG X509CertPath - Current Subject DN: CN=Leshan Server Demo
2019-02-06 22:54:39,053 DEBUG DTLSConnector - Sending flight of 5 message(s) to peer [/192.168.131.5:36024] using 1 datagram(s) of max. 9001 bytes
2019-02-06 22:54:39,053 DEBUG ServerHandshaker - Processed CLIENT_HELLO (1) message with message sequence no [1] from peer [/192.168.131.5:36024]
2019-02-06 22:54:39,053 DEBUG DTLSSession - Updated receive window with sequence number [1]: new upper boundary [63], new bit vector [10]
2019-02-06 22:54:40,053 DEBUG DTLSConnector - Re-transmitting flight for [/192.168.131.5:36024], [3] retransmissions left
2019-02-06 22:54:40,053 DEBUG DTLSConnector - Sending flight of 5 message(s) to peer [/192.168.131.5:36024] using 1 datagram(s) of max. 9001 bytes
2019-02-06 22:54:41,096 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:41,096 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:41,096 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:54:41,096 DEBUG DTLSSession - Checking sequence no [2] using bit mask [100] against received records [10] with lower boundary [0]
2019-02-06 22:54:41,097 DEBUG ServerHandshaker - Processing Handshake (22) message from peer [/192.168.131.5:36024]
2019-02-06 22:54:41,099 DEBUG ServerHandshaker - Processed CLIENT_KEY_EXCHANGE (16) message with message sequence no [2] from peer [/192.168.131.5:36024]
2019-02-06 22:54:41,099 DEBUG DTLSSession - Updated receive window with sequence number [2]: new upper boundary [63], new bit vector [110]
2019-02-06 22:54:41,103 DEBUG DTLSConnector - Received 2 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:41,103 DEBUG DTLSSession - Checking sequence no [3] using bit mask [1000] against received records [110] with lower boundary [0]
2019-02-06 22:54:41,103 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:54:41,103 DEBUG DTLSSession - Updated receive window with sequence number [3]: new upper boundary [63], new bit vector [1110]
2019-02-06 22:54:41,103 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:41,103 DEBUG DTLSSession - Checking sequence no [0] using bit mask [1] against received records [1110] with lower boundary [0]
2019-02-06 22:54:41,106 DEBUG Handshaker$InboundMessageBuffer - Queueing HANDSHAKE message from future epoch [1] > current epoch [0]
2019-02-06 22:54:41,137 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:41,137 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:41,137 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:41,137 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:54:41,137 DEBUG DTLSSession - Checking sequence no [3] using bit mask [1000] against received records [1110] with lower boundary [0]
2019-02-06 22:54:41,137 DEBUG DTLSSession - Checking sequence no [4] using bit mask [10000] against received records [1110] with lower boundary [0]
2019-02-06 22:54:41,138 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:54:41,138 DEBUG DTLSSession - Updated receive window with sequence number [4]: new upper boundary [63], new bit vector [11110]
2019-02-06 22:54:41,176 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:41,176 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:41,176 DEBUG DTLSSession - Checking sequence no [1] using bit mask [10] against received records [11110] with lower boundary [0]
2019-02-06 22:54:42,126 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:42,126 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:42,126 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:42,127 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:42,127 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:54:42,127 DEBUG DTLSSession - Checking sequence no [5] using bit mask [100000] against received records [11110] with lower boundary [0]
2019-02-06 22:54:42,127 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:54:42,127 DEBUG DTLSSession - Updated receive window with sequence number [5]: new upper boundary [63], new bit vector [111110]
2019-02-06 22:54:42,127 DEBUG DTLSSession - Checking sequence no [6] using bit mask [1000000] against received records [111110] with lower boundary [0]
2019-02-06 22:54:42,127 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:54:42,127 DEBUG DTLSSession - Updated receive window with sequence number [6]: new upper boundary [63], new bit vector [1111110]
2019-02-06 22:54:42,127 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:42,128 DEBUG DTLSSession - Checking sequence no [2] using bit mask [100] against received records [1111110] with lower boundary [0]
2019-02-06 22:54:44,046 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:44,047 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:44,047 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:54:44,047 DEBUG DTLSSession - Checking sequence no [7] using bit mask [10000000] against received records [1111110] with lower boundary [0]
2019-02-06 22:54:44,047 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:54:44,047 DEBUG DTLSSession - Updated receive window with sequence number [7]: new upper boundary [63], new bit vector [11111110]
2019-02-06 22:54:44,047 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:44,047 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:44,047 DEBUG DTLSSession - Checking sequence no [8] using bit mask [100000000] against received records [11111110] with lower boundary [0]
2019-02-06 22:54:44,048 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:54:44,048 DEBUG DTLSSession - Updated receive window with sequence number [8]: new upper boundary [63], new bit vector [111111110]
2019-02-06 22:54:44,048 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:44,048 DEBUG DTLSSession - Checking sequence no [3] using bit mask [1000] against received records [111111110] with lower boundary [0]
2019-02-06 22:54:48,126 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:48,126 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:48,127 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:54:48,127 DEBUG DTLSSession - Checking sequence no [9] using bit mask [1000000000] against received records [111111110] with lower boundary [0]
2019-02-06 22:54:48,127 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:54:48,127 DEBUG DTLSSession - Updated receive window with sequence number [9]: new upper boundary [63], new bit vector [1111111110]
2019-02-06 22:54:48,127 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:48,127 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:48,127 DEBUG DTLSSession - Checking sequence no [10] using bit mask [10000000000] against received records [1111111110] with lower boundary [0]
2019-02-06 22:54:48,127 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:54:48,127 DEBUG DTLSSession - Updated receive window with sequence number [10]: new upper boundary [63], new bit vector [11111111110]
2019-02-06 22:54:48,128 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:48,128 DEBUG DTLSSession - Checking sequence no [4] using bit mask [10000] against received records [11111111110] with lower boundary [0]
2019-02-06 22:54:56,446 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:56,446 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:56,446 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:54:56,446 DEBUG DTLSSession - Checking sequence no [11] using bit mask [100000000000] against received records [11111111110] with lower boundary [0]
2019-02-06 22:54:56,447 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:54:56,447 DEBUG DTLSSession - Updated receive window with sequence number [11]: new upper boundary [63], new bit vector [111111111110]
2019-02-06 22:54:56,447 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:56,447 DEBUG DTLSSession - Checking sequence no [12] using bit mask [1000000000000] against received records [111111111110] with lower boundary [0]
2019-02-06 22:54:56,447 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:54:56,447 DEBUG DTLSSession - Updated receive window with sequence number [12]: new upper boundary [63], new bit vector [1111111111110]
2019-02-06 22:54:56,465 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:54:56,465 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:54:56,465 DEBUG DTLSSession - Checking sequence no [5] using bit mask [100000] against received records [1111111111110] with lower boundary [0]
2019-02-06 22:55:18,059 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:55:18,059 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:55:18,059 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:55:18,059 DEBUG DTLSSession - Checking sequence no [13] using bit mask [10000000000000] against received records [1111111111110] with lower boundary [0]
2019-02-06 22:55:18,059 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:55:18,060 DEBUG DTLSSession - Updated receive window with sequence number [13]: new upper boundary [63], new bit vector [11111111111110]
2019-02-06 22:55:18,279 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:55:18,279 DEBUG DTLSSession - Checking sequence no [14] using bit mask [100000000000000] against received records [11111111111110] with lower boundary [0]
2019-02-06 22:55:18,279 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:55:18,279 DEBUG DTLSSession - Updated receive window with sequence number [14]: new upper boundary [63], new bit vector [111111111111110]
2019-02-06 22:55:44,529 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:55:44,529 DEBUG DTLSConnector - Received Handshake (22) record from peer [/192.168.131.5:36024]
2019-02-06 22:55:44,529 DEBUG Record - Parsing HANDSHAKE message plaintext [KeyExgAl=EC_DIFFIE_HELLMAN, x.509]
2019-02-06 22:55:44,529 DEBUG DTLSSession - Checking sequence no [15] using bit mask [1000000000000000] against received records [111111111111110] with lower boundary [0]
2019-02-06 22:55:44,529 DEBUG Handshaker$InboundMessageBuffer - Discarding old message, message_seq [2] < next_receive_seq [3]
2019-02-06 22:55:44,530 DEBUG DTLSSession - Updated receive window with sequence number [15]: new upper boundary [63], new bit vector [1111111111111110]
2019-02-06 22:55:45,079 DEBUG DTLSConnector - Received 1 DTLS records using a 16474 byte datagram buffer
2019-02-06 22:55:45,079 DEBUG DTLSSession - Checking sequence no [16] using bit mask [10000000000000000] against received records [1111111111111110] with lower boundary [0]
2019-02-06 22:55:45,079 DEBUG Handshaker$InboundMessageBuffer - Change Cipher Spec is not expected and therefore kept for later processing!
2019-02-06 22:55:45,079 DEBUG DTLSSession - Updated receive window with sequence number [16]: new upper boundary [63], new bit vector [11111111111111110]

Please help us with

kalyanjanaki commented 5 years ago

From wireshark we see that server is using non PSK chiper suite as below.

TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256

we are expecting below chiter suite for PSK mode

TLS_PSK_WITH_AES_128_CBC_SHA256

sbernard31 commented 5 years ago

Just to explain how DTLS works.

Client initiate a handshake and give to the server a list of all the cipher suites it supports. Then server search which ones are compatible with the ones it supports, then from this subset select the one it prefers.

I look at the code quickly and leshan-server-demo support those cipher suite : 

// Most preferred  to less preferred
TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8
TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256
TLS_PSK_WITH_AES_128_CCM_8
TLS_PSK_WITH_AES_128_CBC_SHA256
TLS_ECDHE_PSK_WITH_AES_128_CBC_SHA256

So I suspect that your device says it supports several cipher suite but among others there is TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256 and so leshan-server-demo choose it. If your device want to connect only with PSK it must propose only PSK cipher suites. (if it says that it supports other one it must not be surprised if server select it)

But If you want to be sure a wireshark capture is the better way.

kalyanjanaki commented 5 years ago

captureFile.pcap.zip

Attached the wireshark capture.

kalyanjanaki commented 5 years ago

The issue is resolved. I have commented the below piece of code from leshan-server-demo and started the server the device is able to connect over DTLS PSK mode.

`  // Set up X.509 mode
        if (keyStorePath != null) {
            try {
                KeyStore keyStore = KeyStore.getInstance(keyStoreType);
                try (FileInputStream fis = new FileInputStream(keyStorePath)) {
                    keyStore.load(fis, keyStorePass == null ? null : keyStorePass.toCharArray());
                    List<Certificate> trustedCertificates = new ArrayList<>();
                    for (Enumeration<String> aliases = keyStore.aliases(); aliases.hasMoreElements();) {
                        String alias = aliases.nextElement();
                        if (keyStore.isCertificateEntry(alias)) {
                            trustedCertificates.add(keyStore.getCertificate(alias));
                        } else if (keyStore.isKeyEntry(alias) && alias.equals(keyStoreAlias)) {
                            List<X509Certificate> x509CertificateChain = new ArrayList<>();
                            Certificate[] certificateChain = keyStore.getCertificateChain(alias);
                            if (certificateChain == null || certificateChain.length == 0) {
                                LOG.error("Keystore alias must have a non-empty chain of X509Certificates.");
                                System.exit(-1);
                            }

                            for (Certificate certificate : certificateChain) {
                                if (!(certificate instanceof X509Certificate)) {
                                    LOG.error("Non-X.509 certificate in alias chain is not supported: {}", certificate);
                                    System.exit(-1);
                                }
                                x509CertificateChain.add((X509Certificate) certificate);
                            }

                            Key key = keyStore.getKey(alias,
                                    keyStoreAliasPass == null ? new char[0] : keyStoreAliasPass.toCharArray());
                            if (!(key instanceof PrivateKey)) {
                                LOG.error("Keystore alias must have a PrivateKey entry, was {}",
                                        key == null ? null : key.getClass().getName());
                                System.exit(-1);
                            }
                            builder.setPrivateKey((PrivateKey) key);
                            serverCertificate = (X509Certificate) keyStore.getCertificate(alias);
                            builder.setCertificateChain(
                                    x509CertificateChain.toArray(new X509Certificate[x509CertificateChain.size()]));
                        }
                    }
                    builder.setTrustedCertificates(
                            trustedCertificates.toArray(new Certificate[trustedCertificates.size()]));
                }
            } catch (KeyStoreException | IOException e) {
                LOG.error("Unable to initialize X.509.", e);
                System.exit(-1);
            }
        }
        // Otherwise, set up RPK mode
        else {
            try {
                PrivateKey privateKey = SecurityUtil.privateKey.readFromResource("credentials/server_privkey.der");
                serverCertificate = SecurityUtil.certificate.readFromResource("credentials/server_cert.der");
                builder.setPrivateKey(privateKey);
                builder.setCertificateChain(new X509Certificate[] { serverCertificate });

                // Use a certificate verifier which trust all certificates by default.
                Builder dtlsConfigBuilder = new DtlsConnectorConfig.Builder();
                dtlsConfigBuilder.setCertificateVerifier(new CertificateVerifier() {
                    @Override
                    public void verifyCertificate(CertificateMessage message, DTLSSession session)
                            throws HandshakeException {
                        // trust all means never raise HandshakeException
                    }

                    @Override
                    public X509Certificate[] getAcceptedIssuers() {
                        return null;
                    }
                });
                builder.setDtlsConfig(dtlsConfigBuilder);

            } catch (Exception e) {
                LOG.error("Unable to load embedded X.509 certificate.", e);
                System.exit(-1);
            }
        }`
sbernard31 commented 5 years ago

OK I close this issue.

But I would like to insist that in my opinion : setting it at server side, is only a workaround . You should really find a way to set you ciphersuite at client side !