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