1From 5ba65051fea0513db0d997f0ab7cafb9826ed74a Mon Sep 17 00:00:00 2001 2From: William Lyu <William.Lyu@windriver.com> 3Date: Fri, 20 Oct 2023 16:22:37 -0400 4Subject: [PATCH] Added handshake history reporting when test fails 5 6Upstream-Status: Submitted [https://github.com/openssl/openssl/pull/22481] 7 8Signed-off-by: William Lyu <William.Lyu@windriver.com> 9--- 10 test/helpers/handshake.c | 137 +++++++++++++++++++++++++++++---------- 11 test/helpers/handshake.h | 70 +++++++++++++++++++- 12 test/ssl_test.c | 44 +++++++++++++ 13 3 files changed, 217 insertions(+), 34 deletions(-) 14 15diff --git a/test/helpers/handshake.c b/test/helpers/handshake.c 16index f611b3a..5703b48 100644 17--- a/test/helpers/handshake.c 18+++ b/test/helpers/handshake.c 19@@ -25,6 +25,102 @@ 20 #include <netinet/sctp.h> 21 #endif 22 23+/* Shamelessly copied from test/helpers/ssl_test_ctx.c */ 24+/* Maps string names to various enumeration type */ 25+typedef struct { 26+ const char *name; 27+ int value; 28+} enum_name_map; 29+ 30+static const enum_name_map connect_phase_names[] = { 31+ {"Handshake", HANDSHAKE}, 32+ {"RenegAppData", RENEG_APPLICATION_DATA}, 33+ {"RenegSetup", RENEG_SETUP}, 34+ {"RenegHandshake", RENEG_HANDSHAKE}, 35+ {"AppData", APPLICATION_DATA}, 36+ {"Shutdown", SHUTDOWN}, 37+ {"ConnectionDone", CONNECTION_DONE} 38+}; 39+ 40+static const enum_name_map peer_status_names[] = { 41+ {"PeerSuccess", PEER_SUCCESS}, 42+ {"PeerRetry", PEER_RETRY}, 43+ {"PeerError", PEER_ERROR}, 44+ {"PeerWaiting", PEER_WAITING}, 45+ {"PeerTestFail", PEER_TEST_FAILURE} 46+}; 47+ 48+static const enum_name_map handshake_status_names[] = { 49+ {"HandshakeSuccess", HANDSHAKE_SUCCESS}, 50+ {"ClientError", CLIENT_ERROR}, 51+ {"ServerError", SERVER_ERROR}, 52+ {"InternalError", INTERNAL_ERROR}, 53+ {"HandshakeRetry", HANDSHAKE_RETRY} 54+}; 55+ 56+/* Shamelessly copied from test/helpers/ssl_test_ctx.c */ 57+static const char *enum_name(const enum_name_map *enums, size_t num_enums, 58+ int value) 59+{ 60+ size_t i; 61+ for (i = 0; i < num_enums; i++) { 62+ if (enums[i].value == value) { 63+ return enums[i].name; 64+ } 65+ } 66+ return "InvalidValue"; 67+} 68+ 69+const char *handshake_connect_phase_name(connect_phase_t phase) 70+{ 71+ return enum_name(connect_phase_names, OSSL_NELEM(connect_phase_names), 72+ (int)phase); 73+} 74+ 75+const char *handshake_status_name(handshake_status_t handshake_status) 76+{ 77+ return enum_name(handshake_status_names, OSSL_NELEM(handshake_status_names), 78+ (int)handshake_status); 79+} 80+ 81+const char *handshake_peer_status_name(peer_status_t peer_status) 82+{ 83+ return enum_name(peer_status_names, OSSL_NELEM(peer_status_names), 84+ (int)peer_status); 85+} 86+ 87+static void save_loop_history(HANDSHAKE_HISTORY *history, 88+ connect_phase_t phase, 89+ handshake_status_t handshake_status, 90+ peer_status_t server_status, 91+ peer_status_t client_status, 92+ int client_turn_count, 93+ int is_client_turn) 94+{ 95+ HANDSHAKE_HISTORY_ENTRY *new_entry = NULL; 96+ 97+ /* 98+ * Create a new history entry for a handshake loop with statuses given in 99+ * the arguments. Potentially evicting the oldest entry when the 100+ * ring buffer is full. 101+ */ 102+ ++(history->last_idx); 103+ history->last_idx &= MAX_HANDSHAKE_HISTORY_ENTRY_IDX_MASK; 104+ 105+ new_entry = &((history->entries)[history->last_idx]); 106+ new_entry->phase = phase; 107+ new_entry->handshake_status = handshake_status; 108+ new_entry->server_status = server_status; 109+ new_entry->client_status = client_status; 110+ new_entry->client_turn_count = client_turn_count; 111+ new_entry->is_client_turn = is_client_turn; 112+ 113+ /* Evict the oldest handshake loop entry when the ring buffer is full. */ 114+ if (history->entry_count < MAX_HANDSHAKE_HISTORY_ENTRY) { 115+ ++(history->entry_count); 116+ } 117+} 118+ 119 HANDSHAKE_RESULT *HANDSHAKE_RESULT_new(void) 120 { 121 HANDSHAKE_RESULT *ret; 122@@ -726,15 +822,6 @@ static void configure_handshake_ssl(SSL *server, SSL *client, 123 SSL_set_post_handshake_auth(client, 1); 124 } 125 126-/* The status for each connection phase. */ 127-typedef enum { 128- PEER_SUCCESS, 129- PEER_RETRY, 130- PEER_ERROR, 131- PEER_WAITING, 132- PEER_TEST_FAILURE 133-} peer_status_t; 134- 135 /* An SSL object and associated read-write buffers. */ 136 typedef struct peer_st { 137 SSL *ssl; 138@@ -1081,17 +1168,6 @@ static void do_shutdown_step(PEER *peer) 139 } 140 } 141 142-typedef enum { 143- HANDSHAKE, 144- RENEG_APPLICATION_DATA, 145- RENEG_SETUP, 146- RENEG_HANDSHAKE, 147- APPLICATION_DATA, 148- SHUTDOWN, 149- CONNECTION_DONE 150-} connect_phase_t; 151- 152- 153 static int renegotiate_op(const SSL_TEST_CTX *test_ctx) 154 { 155 switch (test_ctx->handshake_mode) { 156@@ -1169,19 +1245,6 @@ static void do_connect_step(const SSL_TEST_CTX *test_ctx, PEER *peer, 157 } 158 } 159 160-typedef enum { 161- /* Both parties succeeded. */ 162- HANDSHAKE_SUCCESS, 163- /* Client errored. */ 164- CLIENT_ERROR, 165- /* Server errored. */ 166- SERVER_ERROR, 167- /* Peers are in inconsistent state. */ 168- INTERNAL_ERROR, 169- /* One or both peers not done. */ 170- HANDSHAKE_RETRY 171-} handshake_status_t; 172- 173 /* 174 * Determine the handshake outcome. 175 * last_status: the status of the peer to have acted last. 176@@ -1546,6 +1609,10 @@ static HANDSHAKE_RESULT *do_handshake_internal( 177 178 start = time(NULL); 179 180+ save_loop_history(&(ret->history), 181+ phase, status, server.status, client.status, 182+ client_turn_count, client_turn); 183+ 184 /* 185 * Half-duplex handshake loop. 186 * Client and server speak to each other synchronously in the same process. 187@@ -1567,6 +1634,10 @@ static HANDSHAKE_RESULT *do_handshake_internal( 188 0 /* server went last */); 189 } 190 191+ save_loop_history(&(ret->history), 192+ phase, status, server.status, client.status, 193+ client_turn_count, client_turn); 194+ 195 switch (status) { 196 case HANDSHAKE_SUCCESS: 197 client_turn_count = 0; 198diff --git a/test/helpers/handshake.h b/test/helpers/handshake.h 199index 78b03f9..b9967c2 100644 200--- a/test/helpers/handshake.h 201+++ b/test/helpers/handshake.h 202@@ -1,5 +1,5 @@ 203 /* 204- * Copyright 2016-2021 The OpenSSL Project Authors. All Rights Reserved. 205+ * Copyright 2016-2023 The OpenSSL Project Authors. All Rights Reserved. 206 * 207 * Licensed under the Apache License 2.0 (the "License"). You may not use 208 * this file except in compliance with the License. You can obtain a copy 209@@ -12,6 +12,11 @@ 210 211 #include "ssl_test_ctx.h" 212 213+#define MAX_HANDSHAKE_HISTORY_ENTRY_BIT 4 214+#define MAX_HANDSHAKE_HISTORY_ENTRY (1 << MAX_HANDSHAKE_HISTORY_ENTRY_BIT) 215+#define MAX_HANDSHAKE_HISTORY_ENTRY_IDX_MASK \ 216+ ((1 << MAX_HANDSHAKE_HISTORY_ENTRY_BIT) - 1) 217+ 218 typedef struct ctx_data_st { 219 unsigned char *npn_protocols; 220 size_t npn_protocols_len; 221@@ -22,6 +27,63 @@ typedef struct ctx_data_st { 222 char *session_ticket_app_data; 223 } CTX_DATA; 224 225+typedef enum { 226+ HANDSHAKE, 227+ RENEG_APPLICATION_DATA, 228+ RENEG_SETUP, 229+ RENEG_HANDSHAKE, 230+ APPLICATION_DATA, 231+ SHUTDOWN, 232+ CONNECTION_DONE 233+} connect_phase_t; 234+ 235+/* The status for each connection phase. */ 236+typedef enum { 237+ PEER_SUCCESS, 238+ PEER_RETRY, 239+ PEER_ERROR, 240+ PEER_WAITING, 241+ PEER_TEST_FAILURE 242+} peer_status_t; 243+ 244+typedef enum { 245+ /* Both parties succeeded. */ 246+ HANDSHAKE_SUCCESS, 247+ /* Client errored. */ 248+ CLIENT_ERROR, 249+ /* Server errored. */ 250+ SERVER_ERROR, 251+ /* Peers are in inconsistent state. */ 252+ INTERNAL_ERROR, 253+ /* One or both peers not done. */ 254+ HANDSHAKE_RETRY 255+} handshake_status_t; 256+ 257+/* Stores the various status information in a handshake loop. */ 258+typedef struct handshake_history_entry_st { 259+ connect_phase_t phase; 260+ handshake_status_t handshake_status; 261+ peer_status_t server_status; 262+ peer_status_t client_status; 263+ int client_turn_count; 264+ int is_client_turn; 265+} HANDSHAKE_HISTORY_ENTRY; 266+ 267+typedef struct handshake_history_st { 268+ /* Implemented using ring buffer. */ 269+ /* 270+ * The valid entries are |entries[last_idx]|, |entries[last_idx-1]|, 271+ * ..., etc., going up to |entry_count| number of entries. Note that when 272+ * the index into the array |entries| becomes < 0, we wrap around to 273+ * the end of |entries|. 274+ */ 275+ HANDSHAKE_HISTORY_ENTRY entries[MAX_HANDSHAKE_HISTORY_ENTRY]; 276+ /* The number of valid entries in |entries| array. */ 277+ size_t entry_count; 278+ /* The index of the last valid entry in the |entries| array. */ 279+ size_t last_idx; 280+} HANDSHAKE_HISTORY; 281+ 282 typedef struct handshake_result { 283 ssl_test_result_t result; 284 /* These alerts are in the 2-byte format returned by the info_callback. */ 285@@ -77,6 +139,8 @@ typedef struct handshake_result { 286 char *cipher; 287 /* session ticket application data */ 288 char *result_session_ticket_app_data; 289+ /* handshake loop history */ 290+ HANDSHAKE_HISTORY history; 291 } HANDSHAKE_RESULT; 292 293 HANDSHAKE_RESULT *HANDSHAKE_RESULT_new(void); 294@@ -95,4 +159,8 @@ int configure_handshake_ctx_for_srp(SSL_CTX *server_ctx, SSL_CTX *server2_ctx, 295 CTX_DATA *server2_ctx_data, 296 CTX_DATA *client_ctx_data); 297 298+const char *handshake_connect_phase_name(connect_phase_t phase); 299+const char *handshake_status_name(handshake_status_t handshake_status); 300+const char *handshake_peer_status_name(peer_status_t peer_status); 301+ 302 #endif /* OSSL_TEST_HANDSHAKE_HELPER_H */ 303diff --git a/test/ssl_test.c b/test/ssl_test.c 304index ea60851..9d6b093 100644 305--- a/test/ssl_test.c 306+++ b/test/ssl_test.c 307@@ -26,6 +26,44 @@ static OSSL_LIB_CTX *libctx = NULL; 308 /* Currently the section names are of the form test-<number>, e.g. test-15. */ 309 #define MAX_TESTCASE_NAME_LENGTH 100 310 311+static void print_handshake_history(const HANDSHAKE_HISTORY *history) 312+{ 313+ size_t first_idx; 314+ size_t i; 315+ size_t cur_idx; 316+ const HANDSHAKE_HISTORY_ENTRY *cur_entry; 317+ const char header_template[] = "|%14s|%16s|%16s|%16s|%17s|%14s|"; 318+ const char body_template[] = "|%14s|%16s|%16s|%16s|%17d|%14s|"; 319+ 320+ TEST_info("The following is the server/client state " 321+ "in the most recent %d handshake loops.", 322+ MAX_HANDSHAKE_HISTORY_ENTRY); 323+ 324+ TEST_note("==================================================" 325+ "=================================================="); 326+ TEST_note(header_template, 327+ "phase", "handshake status", "server status", 328+ "client status", "client turn count", "is client turn"); 329+ TEST_note("+--------------+----------------+----------------" 330+ "+----------------+-----------------+--------------+"); 331+ 332+ first_idx = (history->last_idx - history->entry_count + 1) & 333+ MAX_HANDSHAKE_HISTORY_ENTRY_IDX_MASK; 334+ for (i = 0; i < history->entry_count; ++i) { 335+ cur_idx = (first_idx + i) & MAX_HANDSHAKE_HISTORY_ENTRY_IDX_MASK; 336+ cur_entry = &(history->entries)[cur_idx]; 337+ TEST_note(body_template, 338+ handshake_connect_phase_name(cur_entry->phase), 339+ handshake_status_name(cur_entry->handshake_status), 340+ handshake_peer_status_name(cur_entry->server_status), 341+ handshake_peer_status_name(cur_entry->client_status), 342+ cur_entry->client_turn_count, 343+ cur_entry->is_client_turn ? "true" : "false"); 344+ } 345+ TEST_note("==================================================" 346+ "=================================================="); 347+} 348+ 349 static const char *print_alert(int alert) 350 { 351 return alert ? SSL_alert_desc_string_long(alert) : "no alert"; 352@@ -388,6 +426,12 @@ static int check_test(HANDSHAKE_RESULT *result, SSL_TEST_CTX *test_ctx) 353 ret &= check_client_sign_type(result, test_ctx); 354 ret &= check_client_ca_names(result, test_ctx); 355 } 356+ 357+ /* Print handshake loop history if any check fails. */ 358+ if (!ret) { 359+ print_handshake_history(&(result->history)); 360+ } 361+ 362 return ret; 363 } 364 365-- 3662.25.1 367 368