{"action":"created","issue":{"url":"https://api.github.com/repos/openthread/openthread/issues/2176","repository_url":"https://api.github.com/repos/openthread/openthread","labels_url":"https://api.github.com/repos/openthread/openthread/issues/2176/labels{/name}","comments_url":"https://api.github.com/repos/openthread/openthread/issues/2176/comments","events_url":"https://api.github.com/repos/openthread/openthread/issues/2176/events","html_url":"https://github.com/openthread/openthread/issues/2176","id":255883042,"number":2176,"title":"MbedTls failure during commissioning on slow platforms.","user":{"login":"erja-gp","id":14219401,"avatar_url":"https://avatars3.githubusercontent.com/u/14219401?v=4","gravatar_id":"","url":"https://api.github.com/users/erja-gp","html_url":"https://github.com/erja-gp","followers_url":"https://api.github.com/users/erja-gp/followers","following_url":"https://api.github.com/users/erja-gp/following{/other_user}","gists_url":"https://api.github.com/users/erja-gp/gists{/gist_id}","starred_url":"https://api.github.com/users/erja-gp/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/erja-gp/subscriptions","organizations_url":"https://api.github.com/users/erja-gp/orgs","repos_url":"https://api.github.com/users/erja-gp/repos","events_url":"https://api.github.com/users/erja-gp/events{/privacy}","received_events_url":"https://api.github.com/users/erja-gp/received_events","type":"User","site_admin":false},"labels":[{"id":355043113,"url":"https://api.github.com/repos/openthread/openthread/labels/enhancement","name":"enhancement","color":"84b6eb","default":true}],"state":"open","locked":false,"assignee":{"login":"erja-gp","id":14219401,"avatar_url":"https://avatars3.githubusercontent.com/u/14219401?v=4","gravatar_id":"","url":"https://api.github.com/users/erja-gp","html_url":"https://github.com/erja-gp","followers_url":"https://api.github.com/users/erja-gp/followers","following_url":"https://api.github.com/users/erja-gp/following{/other_user}","gists_url":"https://api.github.com/users/erja-gp/gists{/gist_id}","starred_url":"https://api.github.com/users/erja-gp/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/erja-gp/subscriptions","organizations_url":"https://api.github.com/users/erja-gp/orgs","repos_url":"https://api.github.com/users/erja-gp/repos","events_url":"https://api.github.com/users/erja-gp/events{/privacy}","received_events_url":"https://api.github.com/users/erja-gp/received_events","type":"User","site_admin":false},"assignees":[{"login":"erja-gp","id":14219401,"avatar_url":"https://avatars3.githubusercontent.com/u/14219401?v=4","gravatar_id":"","url":"https://api.github.com/users/erja-gp","html_url":"https://github.com/erja-gp","followers_url":"https://api.github.com/users/erja-gp/followers","following_url":"https://api.github.com/users/erja-gp/following{/other_user}","gists_url":"https://api.github.com/users/erja-gp/gists{/gist_id}","starred_url":"https://api.github.com/users/erja-gp/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/erja-gp/subscriptions","organizations_url":"https://api.github.com/users/erja-gp/orgs","repos_url":"https://api.github.com/users/erja-gp/repos","events_url":"https://api.github.com/users/erja-gp/events{/privacy}","received_events_url":"https://api.github.com/users/erja-gp/received_events","type":"User","site_admin":false}],"milestone":null,"comments":19,"created_at":"2017-09-07T10:02:03Z","updated_at":"2017-10-11T16:18:16Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"We're seeing issues when running the OpenThread stack on an older platform, where the crypto computations are done on the CPU and are not fast enough to avoid DTLS timeouts on the other side.\r\n\r\nThe issues are similar to, but not the same as, what is reported in: https://github.com/openthread/openthread/pull/1207\r\n\r\nIn our case the code (including the fix \"0001-Fix-commissioning-problem-with-retransmissions.patch\") behaves as follows: \r\n\r\nNote that in my setup the Joiner is the slow platform which takes more than 8 seconds to perform it’s computations, whereas the Commissioner is on a faster platform (therefor there are no repeats of the 'Client Hello' messages).\r\n\r\n```\r\n   Joiner                               Commissioner\r\n(1)  |              Client Hello              |\r\n     |--------------------------------------->|\r\n     |                                        |\r\n(2)  |          Hello Verify Request          |\r\n     |<---------------------------------------|\r\n     |                                        |\r\n(3)  |         Client Hello + cookie          |\r\n     |--------------------------------------->|\r\n     |                                        |\r\n(4)  |              Server Hello              |\r\n     |          Server Key Exchange           |\r\n     |           Server Hello Done            |\r\n     |<---------------------------------------|\r\n     |                                        | |\r\n(5)  |              Server Hello              | |  DTLS timeout\r\n     |          Server Key Exchange           | |\r\n     |           Server Hello Done            | v\r\n     |<---------------------------------------| \r\n     |                                        |\r\n(6)  |          Client Key Exchange           |\r\n     |           Change Cipher Spec           |\r\n     |      Encrypted Handshake Message       |\r\n     |        Client Key Exchange (DUP)       |\r\n     |        Change Cipher Spec (DUP)        |\r\n     |   Encrypted Handshake Message (DUP)    |\r\n     |--------------------------------------->|\r\n     |                                        |\r\n(7)  |           Change Cipher Spec           |\r\n     |      Encrypted Handshake Message       |\r\n     |<---------------------------------------|\r\n     |                                        |\r\n(8)  |            Application Data            |\r\n     |--------------------------------------->|\r\n     |                                        |\r\n(9)  |        Change Cipher Spec (DUP)        |\r\n     |   Encrypted Handshake Message (DUP)    |\r\n     |         Application Data (DUP)         |\r\n     |<---------------------------------------|\r\n     |                                        |\r\n\r\n```\r\n\r\nBecause the Joiner takes a long time to compute the data for (6), one sees that on the Commissioner side the 8s timeout gets triggered, and the previous message (4) is retransmitted as (5).\r\n\r\nAfter creating the data for (6) the TLS code notices that there are repeat messages,\r\nand decides (as per spec) to reply to both (4) and (5). In our case both replies end up in the same message (6) !\r\n\r\nNow, the Commissioner replies with (7), but only removes the first half of (6) out of its rx queue.\r\n\r\nWhen the Commissioner receives (8), it notices the remaining part of (6) is still in its rx queue, and replies to this first with the \"Change Cipher Spec (DUP)\". Additionally,  it also replies to the recently received Application Data (8). Both replies end up in (9).\r\n\r\nAt this point, the Joiner code has moved to a state where it's looking for \"Application Data\", but there is unexpected data (Change Cipher Spec (DUP)) in front of it.\r\nThe current DTLS code doesn't handle this situation: it sees an incorrect record and discards the complete UDP packet (and not only the offending record).\r\n\r\n\r\nThat's the current situation. It is clear that the current patch does only fixes a single variation of the problem (again, see PR1207), and not the bigger problem of the DTLS state machine ending up in an incorrect state.\r\n\r\nThere are multiple paths to fix the underlying problem:\r\n* one could adapt the code to also handle the \"Change Cipher Spec\" by trplying to it (I've tried it and it works). But this requires again multiple fixes, and I don't think this is the correct way forward: in fact it's like handling multiple parallel handshakes. The sniffer logs end up looking very messy with all those (unnecessary) retransmission. Also, it spins out of control, with multiple retransmissions on both sides when two older platforms start a DTLS session between one another.\r\n\r\n* we should reconsider sending the initial retransmit of the \"Client Key Exchange\".\r\nThe spec clearly states it should be done:\r\n\r\n>     \"2. The implementation reads a retransmitted flight from the peer: the\r\n>       implementation transitions to the SENDING state, where it\r\n>       retransmits the flight, resets the retransmit timer, and returns\r\n>       to the WAITING state.  The rationale here is that the receipt of a\r\n>       duplicate message is the likely result of timer expiry on the peer\r\n>       and therefore suggests that part of one's previous flight was\r\n>       lost.\"\r\n> \r\n\r\nBut, it also mentions that the reasoning behind this rule is to retransmit a flight that was previously lost. In the outlined case there is no previous flight. When one runs a slow platform, it's obvious that the retransmits are NOT caused by a lost previous flight, so why send multiple replies in that case ?\r\n\r\n\r\nThe code that triggers this type of retransmit is located in third_party/mbedtls/repo/library/ssl_tls.c:\r\n\r\n```\r\nint mbedtls_ssl_prepare_handshake_record( mbedtls_ssl_context *ssl ) {\r\n...\r\n            if( recv_msg_seq == ssl->handshake->in_flight_start_seq - 1 &&\r\n                ssl->in_msg[0] != MBEDTLS_SSL_HS_HELLO_VERIFY_REQUEST )\r\n\r\n```\r\nTo still benefit from the speed improvements, it is probably not required to entirely remove this retransmission mechanism. Only remove the retransmissions \r\n* @ compile time: only for slow platforms\r\n* @ run time: only for the state(s) with known long computational delays.\r\n\r\nNote: disabling this code will not create issues in case were a message really gets lost, because there is always the local timer which will timeout when no reply is received. This, in turn will (locally) trigger a retransmit.\r\n"},"comment":{"url":"https://api.github.com/repos/openthread/openthread/issues/comments/335864822","html_url":"https://github.com/openthread/openthread/issues/2176#issuecomment-335864822","issue_url":"https://api.github.com/repos/openthread/openthread/issues/2176","id":335864822,"user":{"login":"jwhui","id":16142208,"avatar_url":"https://avatars3.githubusercontent.com/u/16142208?v=4","gravatar_id":"","url":"https://api.github.com/users/jwhui","html_url":"https://github.com/jwhui","followers_url":"https://api.github.com/users/jwhui/followers","following_url":"https://api.github.com/users/jwhui/following{/other_user}","gists_url":"https://api.github.com/users/jwhui/gists{/gist_id}","starred_url":"https://api.github.com/users/jwhui/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jwhui/subscriptions","organizations_url":"https://api.github.com/users/jwhui/orgs","repos_url":"https://api.github.com/users/jwhui/repos","events_url":"https://api.github.com/users/jwhui/events{/privacy}","received_events_url":"https://api.github.com/users/jwhui/received_events","type":"User","site_admin":false},"created_at":"2017-10-11T16:18:16Z","updated_at":"2017-10-11T16:18:16Z","author_association":"OWNER","body":"@hanno-arm, thanks for working with us to address this issue.\r\n\r\nApplication data is only sent in response to calling `mbedtls_ssl_handshake()` and the ssl context `state` member is set to `MBEDTLS_SSL_HANDSHAKE_OVER` after the call.  The corresponding code is here: https://github.com/openthread/openthread/blob/master/src/core/meshcop/dtls.cpp#L402"}}
{"actor":{"display_login":"jwhui"}}