diff --git a/trunk/src/app/srs_app_log.hpp b/trunk/src/app/srs_app_log.hpp index 70d58e2e5..5ae58059a 100644 --- a/trunk/src/app/srs_app_log.hpp +++ b/trunk/src/app/srs_app_log.hpp @@ -36,6 +36,7 @@ #define TAG_MAIN "MAIN" #define TAG_MAYBE "MAYBE" #define TAG_DTLS_ALERT "DTLS_ALERT" +#define TAG_DTLS_HANG "DTLS_HANG" #define TAG_RESOURCE_UNSUB "RESOURCE_UNSUB" // Use memory/disk cache and donot flush when write log. diff --git a/trunk/src/app/srs_app_rtc_dtls.cpp b/trunk/src/app/srs_app_rtc_dtls.cpp index 882ff58f9..65f06d981 100644 --- a/trunk/src/app/srs_app_rtc_dtls.cpp +++ b/trunk/src/app/srs_app_rtc_dtls.cpp @@ -378,12 +378,18 @@ SrsDtlsImpl::SrsDtlsImpl(ISrsDtlsCallback* callback) last_outgoing_packet_cache = new uint8_t[kRtpPacketSize]; nn_last_outgoing_packet = 0; + nn_arq_packets = 0; version_ = SrsDtlsVersionAuto; } SrsDtlsImpl::~SrsDtlsImpl() { + if (!handshake_done_for_us) { + srs_warn2(TAG_DTLS_HANG, "DTLS: Hang, done=%u, version=%d, arq=%u", handshake_done_for_us, + version_, nn_arq_packets); + } + if (dtls_ctx) { SSL_CTX_free(dtls_ctx); dtls_ctx = NULL; @@ -557,9 +563,9 @@ void SrsDtlsImpl::state_trace(uint8_t* data, int length, bool incoming, int r0, handshake_type = (uint8_t)data[13]; } - srs_trace("DTLS: %s %s, done=%u, cache=%u, arq=%u, r0=%d, r1=%d, len=%u, cnt=%u, size=%u, hs=%u", + srs_trace("DTLS: %s %s, done=%u, cache=%u, arq=%u/%u, r0=%d, r1=%d, len=%u, cnt=%u, size=%u, hs=%u", (is_dtls_client()? "Active":"Passive"), (incoming? "RECV":"SEND"), handshake_done_for_us, cache, arq, - r0, r1, length, content_type, size, handshake_type); + nn_arq_packets, r0, r1, length, content_type, size, handshake_type); } const int SRTP_MASTER_KEY_KEY_LEN = 16; @@ -608,8 +614,16 @@ SrsDtlsClientImpl::SrsDtlsClientImpl(ISrsDtlsCallback* callback) : SrsDtlsImpl(c { trd = NULL; state_ = SrsDtlsStateInit; - arq_first = 50 * SRS_UTIME_MILLISECONDS; - arq_interval = 100 * SRS_UTIME_MILLISECONDS; + + // The first wait and base interval for ARQ. + arq_interval = 10 * SRS_UTIME_MILLISECONDS; + + // Use step timeout for ARQ, the total timeout is sum(arq_to_ratios)*arq_interval. + // for example, if arq_interval is 10ms, arq_to_ratios is [3, 6, 9, 15, 20, 40, 80, 160], + // then total timeout is sum([3, 6, 9, 15, 20, 40, 80, 160]) * 10ms = 3330ms. + int ratios[] = {3, 6, 9, 15, 20, 40, 80, 160}; + srs_assert(sizeof(arq_to_ratios) == sizeof(ratios)); + memcpy(arq_to_ratios, ratios, sizeof(ratios)); } SrsDtlsClientImpl::~SrsDtlsClientImpl() @@ -742,12 +756,10 @@ srs_error_t SrsDtlsClientImpl::cycle() { srs_error_t err = srs_success; - // The first ARQ delay. - srs_usleep(arq_first); - // Limit the max retry for ARQ. - for (int arq_retry_left = 7; arq_retry_left > 0; arq_retry_left--) { - srs_info("arq cycle, state=%u, retry=%d", state_, arq_retry_left); + for (int i = 0; i < sizeof(arq_to_ratios) / sizeof(int); i++) { + srs_utime_t arq_to = arq_interval * arq_to_ratios[i]; + srs_usleep(arq_to); // We ignore any error for ARQ thread. if ((err = trd->pull()) != srs_success) { @@ -772,6 +784,7 @@ srs_error_t SrsDtlsClientImpl::cycle() if (size) { // Trace the detail of DTLS packet. state_trace((uint8_t*)data, size, false, 1, SSL_ERROR_NONE, true, true); + nn_arq_packets++; if ((err = callback_->write_dtls_data(data, size)) != srs_success) { return srs_error_wrap(err, "dtls send size=%u, data=[%s]", size, @@ -779,8 +792,8 @@ srs_error_t SrsDtlsClientImpl::cycle() } } - // TODO: Use ARQ step timeouts. - srs_usleep(arq_interval); + srs_info("arq cycle, done=%u, state=%u, retry=%d, interval=%dms, to=%dms, size=%d, nn=%d", handshake_done_for_us, + state_, i, srsu2msi(arq_interval), srsu2msi(arq_to), size, nn_arq_packets); } return err; @@ -820,6 +833,7 @@ void SrsDtlsServerImpl::on_ssl_out_data(uint8_t*& data, int& size, bool& cached) if (size <= 0 && nn_last_outgoing_packet) { size = nn_last_outgoing_packet; data = last_outgoing_packet_cache; + nn_arq_packets++; cached = true; } } diff --git a/trunk/src/app/srs_app_rtc_dtls.hpp b/trunk/src/app/srs_app_rtc_dtls.hpp index 089a42264..e6ddfaf3e 100644 --- a/trunk/src/app/srs_app_rtc_dtls.hpp +++ b/trunk/src/app/srs_app_rtc_dtls.hpp @@ -124,6 +124,8 @@ protected: // DTLS packet cache, only last out-going packet. uint8_t* last_outgoing_packet_cache; int nn_last_outgoing_packet; + // The stat for ARQ packets. + int nn_arq_packets; public: SrsDtlsImpl(ISrsDtlsCallback* callback); virtual ~SrsDtlsImpl(); @@ -154,8 +156,8 @@ private: // The DTLS-client state to drive the ARQ thread. SrsDtlsState state_; // The timeout for ARQ. - srs_utime_t arq_first; srs_utime_t arq_interval; + int arq_to_ratios[8]; public: SrsDtlsClientImpl(ISrsDtlsCallback* callback); virtual ~SrsDtlsClientImpl(); diff --git a/trunk/src/utest/srs_utest.hpp b/trunk/src/utest/srs_utest.hpp index b6bd666ed..551490127 100644 --- a/trunk/src/utest/srs_utest.hpp +++ b/trunk/src/utest/srs_utest.hpp @@ -77,7 +77,7 @@ extern srs_utime_t _srs_tmp_timeout; // For init array data. #define HELPER_ARRAY_INIT(buf, sz, val) \ - memset(buf, val, sz) + for (int _iii = 0; _iii < sz; _iii++) (buf)[_iii] = val // Dump simple stream to string. #define HELPER_BUFFER2STR(io) \ diff --git a/trunk/src/utest/srs_utest_rtc.cpp b/trunk/src/utest/srs_utest_rtc.cpp index 55b803e26..b8651ff8d 100644 --- a/trunk/src/utest/srs_utest_rtc.cpp +++ b/trunk/src/utest/srs_utest_rtc.cpp @@ -856,10 +856,10 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); - // Lost 10 packets, total packets should be 8(max to 8). + // Lost 10 packets, total packets should be 9(max to 9). // Note that only one server hello. cio.nn_client_hello_lost = 10; @@ -872,7 +872,7 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) EXPECT_FALSE(cio.done); EXPECT_FALSE(sio.done); - EXPECT_EQ(8, cio.nn_client_hello); + EXPECT_EQ(9, cio.nn_client_hello); EXPECT_EQ(0, sio.nn_server_hello); EXPECT_EQ(0, cio.nn_certificate); EXPECT_EQ(0, sio.nn_new_session); @@ -888,10 +888,10 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); - // Lost 10 packets, total packets should be 8(max to 8). + // Lost 10 packets, total packets should be 9(max to 9). // Note that only one server NewSessionTicket. cio.nn_certificate_lost = 10; @@ -906,7 +906,7 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) EXPECT_EQ(1, cio.nn_client_hello); EXPECT_EQ(1, sio.nn_server_hello); - EXPECT_EQ(8, cio.nn_certificate); + EXPECT_EQ(9, cio.nn_certificate); EXPECT_EQ(0, sio.nn_new_session); EXPECT_EQ(0, sio.nn_change_cipher); } @@ -920,10 +920,10 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); - // Lost 10 packets, total packets should be 8(max to 8). + // Lost 10 packets, total packets should be 9(max to 9). sio.nn_server_hello_lost = 10; HELPER_EXPECT_SUCCESS(client.start_active_handshake()); @@ -935,8 +935,8 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) EXPECT_FALSE(cio.done); EXPECT_FALSE(sio.done); - EXPECT_EQ(8, cio.nn_client_hello); - EXPECT_EQ(8, sio.nn_server_hello); + EXPECT_EQ(9, cio.nn_client_hello); + EXPECT_EQ(9, sio.nn_server_hello); EXPECT_EQ(0, cio.nn_certificate); EXPECT_EQ(0, sio.nn_new_session); EXPECT_EQ(0, sio.nn_change_cipher); @@ -951,10 +951,10 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); - // Lost 10 packets, total packets should be 8(max to 8). + // Lost 10 packets, total packets should be 9(max to 9). sio.nn_new_session_lost = 10; HELPER_EXPECT_SUCCESS(client.start_active_handshake()); @@ -969,8 +969,8 @@ VOID TEST(KernelRTCTest, DTLSARQLimitTest) EXPECT_EQ(1, cio.nn_client_hello); EXPECT_EQ(1, sio.nn_server_hello); - EXPECT_EQ(8, cio.nn_certificate); - EXPECT_EQ(8, sio.nn_new_session); + EXPECT_EQ(9, cio.nn_certificate); + EXPECT_EQ(9, sio.nn_new_session); EXPECT_EQ(0, sio.nn_change_cipher); } } @@ -1012,8 +1012,8 @@ VOID TEST(KernelRTCTest, DTLSClientARQTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); // Lost 2 packets, total packets should be 3. // Note that only one server hello. @@ -1044,8 +1044,8 @@ VOID TEST(KernelRTCTest, DTLSClientARQTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); // Lost 2 packets, total packets should be 3. // Note that only one server NewSessionTicket. @@ -1105,8 +1105,8 @@ VOID TEST(KernelRTCTest, DTLSServerARQTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); // Lost 2 packets, total packets should be 3. sio.nn_server_hello_lost = 2; @@ -1136,8 +1136,8 @@ VOID TEST(KernelRTCTest, DTLSServerARQTest) HELPER_EXPECT_SUCCESS(server.initialize("passive", "dtls1.0")); // Use very short interval for utest. - dynamic_cast(client.impl)->arq_first = 1 * SRS_UTIME_MILLISECONDS; dynamic_cast(client.impl)->arq_interval = 1 * SRS_UTIME_MILLISECONDS; + HELPER_ARRAY_INIT(dynamic_cast(client.impl)->arq_to_ratios, 8, 1); // Lost 2 packets, total packets should be 3. sio.nn_new_session_lost = 2;