search

eclipse-californium / californium

CoAP/DTLS Java Implementation
https://www.eclipse.org/californium/
Other
722 stars 364 forks source link

Cant Establish DTLS Session #871

Closed kalyanjanaki closed 5 years ago

kalyanjanaki commented 5 years ago

Please providing basic issue information

Issues may be answered much faster, if you provide more details ahead!

kalyanjanaki commented 5 years ago

Hello

Am working on NBIOT project. We are trying to https://github.com/eclipse/leshan for device management. leshan is based on californium. the server we built works fine with non DTLS but when we enable PSK based DTLS the session handshake fails. Below is the log message. Please helps us

    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]
boaks commented 5 years ago

Which implementation did you use on the device side?

May be the hint in issue #858 helps. Leshan uses the PSK secret encoded in hex. Depending on the device implementation, this requires the secret to be converted in that encoding.

kalyanjanaki commented 5 years ago

We use AT command set like below

AT+SQNOMADMACC="201","coaps://hostname:5684",0,"351c80a6c9948545a22d554daeacbeb0812cc607","8446865eece91cd245831dbcc9717cd0da743590ad15a82182b43327f40313e0","180","1",,,"bs"

boaks commented 5 years ago

ServerHandshaker - Negotiated cipher suite [TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256]

Your "AT command" device doesn't use PSK ... it's using ECDSA. It requires a wireshark capture to see, which cipher suited the device includes in its CLIENT_HELLO. Or a higher logging level for the DTLSConnector, but I would prefer a wireshark capture.

Or may be the manufacturer of your device can help you.

To check DTLS, its also possible to use openssl for the handshake. (openssl openssl s_server -dtls1_2 ..., please consider the openssl docu for the required details)

boaks commented 5 years ago

https://github.com/eclipse/leshan/issues/650#issuecomment-461251944

According your comment, you have a wireshark capture :-). If you want help, provide it. You may select just the packages from your device client and export them. Without that capture, please ask the device manufacturer or use the openssl s_server.

kalyanjanaki commented 5 years ago

captureFile.pcap.zip

Uploaded the wireshark file captured server side.

boaks commented 5 years ago

Thanks!

The device sends a CLIENT_HELLO with 59 cipher suites.

            Cipher Suites (59 suites)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384 (0xc02c)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256 (0xc02b)
                Cipher Suite: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (0xc030)
                Cipher Suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (0xc02f)
                Cipher Suite: TLS_DHE_RSA_WITH_AES_256_GCM_SHA384 (0x009f)
                Cipher Suite: TLS_DHE_RSA_WITH_AES_128_GCM_SHA256 (0x009e)
                Cipher Suite: TLS_RSA_WITH_AES_256_GCM_SHA384 (0x009d)
                Cipher Suite: TLS_RSA_WITH_AES_128_GCM_SHA256 (0x009c)
                Cipher Suite: TLS_DHE_PSK_WITH_AES_256_GCM_SHA384 (0x00ab)
                Cipher Suite: TLS_DHE_PSK_WITH_AES_128_GCM_SHA256 (0x00aa)
                Cipher Suite: TLS_PSK_WITH_AES_256_GCM_SHA384 (0x00a9)
                Cipher Suite: TLS_PSK_WITH_AES_128_GCM_SHA256 (0x00a8)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256 (0xcca9)
                Cipher Suite: TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256 (0xcca8)
                Cipher Suite: TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256 (0xccaa)
                Cipher Suite: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256 (0xc027)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256 (0xc023)
                Cipher Suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384 (0xc028)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384 (0xc024)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA (0xc00a)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA (0xc009)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA (0xc008)
                Cipher Suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA (0xc014)
                Cipher Suite: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA (0xc013)
                Cipher Suite: TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA (0xc012)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_128_CCM (0xc0ac)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8 (0xc0ae)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8 (0xc0af)
                Cipher Suite: TLS_RSA_WITH_AES_128_CCM_8 (0xc0a0)
                Cipher Suite: TLS_RSA_WITH_AES_256_CCM_8 (0xc0a1)
                Cipher Suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256 (0x006b)
                Cipher Suite: TLS_DHE_RSA_WITH_AES_128_CBC_SHA256 (0x0067)
                Cipher Suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA (0x0039)
                Cipher Suite: TLS_DHE_RSA_WITH_AES_128_CBC_SHA (0x0033)
                Cipher Suite: TLS_DHE_RSA_WITH_3DES_EDE_CBC_SHA (0x0016)
                Cipher Suite: TLS_RSA_WITH_AES_256_CBC_SHA256 (0x003d)
                Cipher Suite: TLS_RSA_WITH_AES_128_CBC_SHA256 (0x003c)
                Cipher Suite: TLS_RSA_WITH_AES_256_CBC_SHA (0x0035)
                Cipher Suite: TLS_RSA_WITH_AES_128_CBC_SHA (0x002f)
                Cipher Suite: TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256 (0xcc14)
                Cipher Suite: TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256 (0xcc13)
                Cipher Suite: TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256 (0xcc15)
                Cipher Suite: TLS_PSK_WITH_AES_256_CBC_SHA (0x008d)
                Cipher Suite: TLS_DHE_PSK_WITH_AES_256_CBC_SHA384 (0x00b3)
                Cipher Suite: TLS_PSK_WITH_AES_256_CBC_SHA384 (0x00af)
                Cipher Suite: TLS_DHE_PSK_WITH_AES_128_CBC_SHA256 (0x00b2)
                Cipher Suite: TLS_PSK_WITH_AES_128_CBC_SHA256 (0x00ae)
                Cipher Suite: TLS_PSK_WITH_AES_128_CBC_SHA (0x008c)
                Cipher Suite: TLS_DHE_PSK_WITH_AES_128_CCM (0xc0a6)
                Cipher Suite: TLS_DHE_PSK_WITH_AES_256_CCM (0xc0a7)
                Cipher Suite: TLS_PSK_WITH_CHACHA20_POLY1305_SHA256 (0xccab)
                Cipher Suite: TLS_ECDHE_PSK_WITH_CHACHA20_POLY1305_SHA256 (0xccac)
                Cipher Suite: TLS_DHE_PSK_WITH_CHACHA20_POLY1305_SHA256 (0xccad)
                Cipher Suite: TLS_ECDHE_PSK_WITH_AES_128_CBC_SHA256 (0xc037)
                Cipher Suite: TLS_PSK_WITH_AES_128_CCM (0xc0a4)
                Cipher Suite: TLS_PSK_WITH_AES_256_CCM (0xc0a5)
                Cipher Suite: TLS_PSK_WITH_AES_128_CCM_8 (0xc0a8)
                Cipher Suite: TLS_PSK_WITH_AES_256_CCM_8 (0xc0a9)
                Cipher Suite: TLS_RSA_WITH_3DES_EDE_CBC_SHA (0x000a)

If you want to use TLS_PSK_WITH_AES_128_CCM_8 (0xc0a8) with that client, you may configure the server to use only that cipher suite (this will force all clients to use that). So, which version of leshan do you use?

Generally, I would recommend, to inform the device manufacturer to include a "select cipher suites". The large list smells for "all, what openssl can do". You waste about 100 bytes in the CLIENT_HELLO and you sent that CLIENT_HELLO at least twice.

sbernard31 commented 5 years ago

If you want to use TLS_PSK_WITH_AES_128_CCM_8 (0xc0a8) with that client, you may configure the server to use only that cipher suite (this will force all clients to use that).

I would have said this is the client which should be configured ? :thinking: I mean generally server handle several kinds of cipher suites and so if a client want to use PSK, it's up to him to come with only PSK cipher suite ?

Configured it at Leshan side is possible but does it look like a workaround ?

kalyanjanaki commented 5 years ago

But same AT command set worked fine for us when connecting to leshan sandbox server. When we runt he leshan-demo-server in our priavte network we are getting this issue.

boaks commented 5 years ago

But same AT command set worked fine for us when connecting to leshan sandbox server.

That's interesting. May be @sbernard31 knows, why.

When we runt he leshan-demo-server in our priavte network we are getting this issue.

May be different versions? Or different configured?

boaks commented 5 years ago

I would have said this is the client which should be configured ?

Therefore

Generally, I would recommend, to inform the device manufacturer to include a "select cipher suites".

boaks commented 5 years ago

@kalyanjanaki

Did you succeed in contacting the device manufacturer?

Or do you need help for the work-around configuring the server to use the PSK cipher-suite only? If so, please provide the leshan version you use.

boaks commented 5 years ago

I guess, it's closed with https://github.com/eclipse/leshan/issues/650.

So just to mention it: Instead of removing code or comment it out, a call to one of the 

dtlsConfigBuilder.setSupportedCipherSuites(...)

would have done it also.