Merge pull request #1797 from private-octopus/code-coverage-202411

Improve coverage of logging functions
private-octopus · Dec 3, 2024 · 9d82d23 · 9d82d23
2 parents c930283 + f632ceb
commit 9d82d23
Show file tree

Hide file tree

Showing 21 changed files with 1,170 additions and 82 deletions.
diff --git a/CMakeLists.txt b/CMakeLists.txt
@@ -8,7 +8,7 @@ else()
 endif()
 
 project(picoquic
-        VERSION 1.1.28.8
+        VERSION 1.1.28.9
         DESCRIPTION "picoquic library"
         LANGUAGES C CXX)
 
@@ -164,15 +164,18 @@ set(PICOQUIC_TEST_LIBRARY_FILES
     picoquictest/l4s_test.c
     picoquictest/mbedtls_test.c
     picoquictest/mediatest.c
+    picoquictest/memlog_test.c
     picoquictest/minicrypto_test.c
     picoquictest/multipath_test.c
     picoquictest/netperf_test.c
     picoquictest/openssl_test.c
     picoquictest/p2p_test.c
     picoquictest/pacing_test.c
     picoquictest/parseheadertest.c
+    picoquictest/picolog_test.c
     picoquictest/picoquic_lb_test.c
     picoquictest/pn2pn64test.c
+    picoquictest/qlog_test.c
     picoquictest/quic_tester.c
     picoquictest/sacktest.c
     picoquictest/satellite_test.c

diff --git a/UnitTest1/unittest1.cpp b/UnitTest1/unittest1.cpp
@@ -48,6 +48,13 @@ namespace UnitTest1
             Assert::AreEqual(ret, 0);
         }
 
+        TEST_METHOD(picolog_basic)
+        {
+            int ret = picolog_basic_test();
+
+            Assert::AreEqual(ret, 0);
+        }
+
         TEST_METHOD(bytestream)
         {
             int ret = bytestream_test();
@@ -1555,6 +1562,13 @@ namespace UnitTest1
             Assert::AreEqual(ret, 0);
         }
 
+        TEST_METHOD(memlog)
+        {
+            int ret= memlog_test();
+
+            Assert::AreEqual(ret, 0);
+        }
+
         TEST_METHOD(migration)
         {
             int ret = migration_test();
@@ -1730,6 +1744,20 @@ namespace UnitTest1
             Assert::AreEqual(ret, 0);
         }
 
+        TEST_METHOD(qlog_auto)
+        {
+            int ret = qlog_auto_test();
+
+            Assert::AreEqual(ret, 0);
+        }
+
+        TEST_METHOD(qlog_error)
+        {
+            int ret = qlog_error_test();
+
+            Assert::AreEqual(ret, 0);
+        }
+
         TEST_METHOD(qlog_trace)
         {
             int ret = qlog_trace_test();

diff --git a/loglib/autoqlog.c b/loglib/autoqlog.c
@@ -46,45 +46,38 @@ int autoqlog(picoquic_cnx_t* cnx)
     else {
         char filename[512];
         char cid_name[2 * PICOQUIC_CONNECTION_ID_MAX_SIZE + 1];
+        int sprintf_ret = -1;
 
-        if (picoquic_print_connection_id_hexa(cid_name, sizeof(cid_name), &cnx->initial_cnxid) != 0) {
-            DBG_PRINTF("Cannot convert connection id for %s", cnx->binlog_file_name);
-            error_code = 2;
-            ret = -1;
+        (void)picoquic_print_connection_id_hexa(cid_name, sizeof(cid_name), &cnx->initial_cnxid);
+        if (cnx->quic->use_unique_log_names) {
+            sprintf_ret = picoquic_sprintf(filename, sizeof(filename), NULL, "%s%s%s.%x.%s.%s",
+                cnx->quic->qlog_dir, PICOQUIC_FILE_SEPARATOR, cid_name, cnx->log_unique,
+                (cnx->client_mode) ? "client" : "server", "qlog");
+        }
+        else {
+            sprintf_ret = picoquic_sprintf(filename, sizeof(filename), NULL, "%s%s%s.%s.%s",
+                cnx->quic->qlog_dir, PICOQUIC_FILE_SEPARATOR, cid_name,
+                (cnx->client_mode) ? "client" : "server", "qlog");
         }
-        else
-        {
-            int sprintf_ret = -1;
-            if (cnx->quic->use_unique_log_names) {
-                sprintf_ret = picoquic_sprintf(filename, sizeof(filename), NULL, "%s%s%s.%x.%s.%s",
-                    cnx->quic->qlog_dir, PICOQUIC_FILE_SEPARATOR, cid_name, cnx->log_unique,
-                    (cnx->client_mode) ? "client" : "server", "qlog");
-            }
-            else {
-                sprintf_ret = picoquic_sprintf(filename, sizeof(filename), NULL, "%s%s%s.%s.%s",
-                    cnx->quic->qlog_dir, PICOQUIC_FILE_SEPARATOR, cid_name,
-                    (cnx->client_mode) ? "client" : "server", "qlog");
-            }
 
-            if (sprintf_ret != 0) {
-                DBG_PRINTF("Cannot format file name for connection %s in file %s", cid_name, cnx->binlog_file_name);
-                ret = -1;
-                error_code = 3;
+        if (sprintf_ret != 0) {
+            DBG_PRINTF("Cannot format file name for connection %s in file %s", cid_name, cnx->binlog_file_name);
+            ret = -1;
+            error_code = 3;
+        }
+        else {
+            ret = qlog_convert(&cnx->initial_cnxid, f_binlog, cnx->binlog_file_name, filename, cnx->quic->qlog_dir, flags);
+            picoquic_file_close(f_binlog);
+            if (ret != 0) {
+                DBG_PRINTF("Cannot convert file %s to qlog, err = %d.\n", cnx->binlog_file_name, ret);
+                error_code = 4;
             }
             else {
-                ret = qlog_convert(&cnx->initial_cnxid, f_binlog, cnx->binlog_file_name, filename, cnx->quic->qlog_dir, flags);
-                picoquic_file_close(f_binlog);
-                if (ret != 0) {
-                    DBG_PRINTF("Cannot convert file %s to qlog, err = %d.\n", cnx->binlog_file_name, ret);
-                    error_code = 4;
-                }
-                else {
-                    if (cnx->quic->binlog_dir == NULL) {
-                        int last_err = 0;
-                        if ((ret = picoquic_file_delete(cnx->binlog_file_name, &last_err)) != 0) {
-                            DBG_PRINTF("Cannot delete file %s to qlog, err = %d.\n", cnx->binlog_file_name, last_err);
-                            error_code = 5;
-                        }
+                if (cnx->quic->binlog_dir == NULL) {
+                    int last_err = 0;
+                    if ((ret = picoquic_file_delete(cnx->binlog_file_name, &last_err)) != 0) {
+                        DBG_PRINTF("Cannot delete file %s to qlog, err = %d.\n", cnx->binlog_file_name, last_err);
+                        error_code = 5;
                     }
                 }
             }
@@ -94,10 +87,7 @@ int autoqlog(picoquic_cnx_t* cnx)
         FILE* F_err = NULL;
         char err_file_name[512];
         size_t name_len = strlen(cnx->binlog_file_name);
-        if (name_len > 500) {
-            name_len = 500;
-        }
-        memcpy(err_file_name, cnx->binlog_file_name, name_len);
+        memcpy(err_file_name, cnx->binlog_file_name, (name_len>500)?500:name_len);
         memcpy(err_file_name + name_len, ".errlog", 7);
         err_file_name[name_len + 0] = 0;
         F_err = picoquic_file_open(err_file_name, "wt");

diff --git a/loglib/loglib.vcxproj.filters b/loglib/loglib.vcxproj.filters
@@ -27,6 +27,8 @@
     <ClCompile Include="autoqlog.c">
       <Filter>Source</Filter>
     </ClCompile>
-    <ClCompile Include="memory_log.c" />
+    <ClCompile Include="memory_log.c">
+      <Filter>Source</Filter>
+    </ClCompile>
   </ItemGroup>
 </Project>
diff --git a/loglib/memory_log.c b/loglib/memory_log.c
@@ -231,10 +231,9 @@ void memlog_call_back(picoquic_cnx_t* cnx, picoquic_path_t* path, void* v_memlog
         }
         else
         {
-#ifdef PICOQUIC_MEMORY_LOG
             cnx->memlog_call_back = NULL;
             cnx->memlog_ctx = NULL;
-#endif
+
             /* This is the close callback */
             if (memlog->F != NULL) {
                 memlog_print_header(memlog->F);
@@ -279,10 +278,8 @@ int memlog_init(picoquic_cnx_t* cnx, size_t nb_lines, const char * memlog_file)
             free(memlog);
         }
         else {
-#ifdef PICOQUIC_MEMORY_LOG
             cnx->memlog_call_back = memlog_call_back;
             cnx->memlog_ctx = memlog;
-#endif
         }
     }
     return(ret);

diff --git a/loglib/qlog.c b/loglib/qlog.c
@@ -215,60 +215,75 @@ void qlog_preferred_address(FILE* f, bytestream* s, uint64_t len)
 void qlog_tp_version_negotiation(FILE* f, bytestream* s, uint64_t len)
 {
     size_t old_size = s->size;
+    size_t ptr_max = s->ptr + (size_t)len;
 
-    s->size = s->ptr + (size_t)len;
-    fprintf(f, "{ ");
-    if ((len & 3) != 0 || len == 0) {
-        fprintf(f, "\"bad_length\": \"%" PRIu64, len);
-    } else {
-        fprintf(f, "\"chosen\": \"");
-        for (int i = 0; i < 4 && s->ptr < s->size; i++, s->ptr++) {
-            fprintf(f, "%02x", s->data[s->ptr]);
+    if (ptr_max > s->size) {
+        fprintf(f, ",\n    \"vnego_parameter_length\": %zu", (size_t)len);
+        fprintf(f, ",\n    \"bytes_available\": %zu", s->size - s->ptr);
+    }
+    else {
+        s->size = s->ptr + (size_t)len;
+        fprintf(f, "{ ");
+        if ((len & 3) != 0 || len == 0) {
+            fprintf(f, "\"bad_length\": \"%" PRIu64, len);
         }
-        fprintf(f, "\"");
-        if (s->ptr < s->size) {
-            int is_first = 1;
-            fprintf(f, ", \"others\": [");
-            do {
-                fprintf(f, "%s", (is_first)?"\"":", \"");
-                is_first = 0;
-                for (int i = 0; i < 4 && s->ptr < s->size; i++, s->ptr++) {
-                    fprintf(f, "%02x", s->data[s->ptr]);
-                }
-                fprintf(f, "\"");
-            } while (s->ptr < s->size);
-            fprintf(f, "]");
+        else {
+            fprintf(f, "\"chosen\": \"");
+            for (int i = 0; i < 4 && s->ptr < s->size; i++, s->ptr++) {
+                fprintf(f, "%02x", s->data[s->ptr]);
+            }
+            fprintf(f, "\"");
+            if (s->ptr < s->size) {
+                int is_first = 1;
+                fprintf(f, ", \"others\": [");
+                do {
+                    fprintf(f, "%s", (is_first) ? "\"" : ", \"");
+                    is_first = 0;
+                    for (int i = 0; i < 4 && s->ptr < s->size; i++, s->ptr++) {
+                        fprintf(f, "%02x", s->data[s->ptr]);
+                    }
+                    fprintf(f, "\"");
+                } while (s->ptr < s->size);
+                fprintf(f, "]");
+            }
         }
+        fprintf(f, "}");
+        s->size = old_size;
     }
-    fprintf(f, "}");
-    s->size = old_size;
 }
 
 
-int qlog_transport_extensions(FILE* f, bytestream* s, size_t tp_length)
+int qlog_transport_extensions(FILE* f, bytestream* v, size_t tp_length)
 {
     int ret = 0;
-    size_t ptr_max = s->ptr + tp_length;
+    size_t ptr_max = v->ptr + tp_length;
 
-    if (ptr_max < s->size) {
+    if (ptr_max > v->size) {
         fprintf(f, ",\n    \"transport_parameter_length\": %zu", tp_length);
-        fprintf(f, ",\n    \"bytes_available\": %zu" PRIu64, s->size - s->ptr);
+        fprintf(f, ",\n    \"bytes_available\": %zu" PRIu64, v->size - v->ptr);
     } else {
+        bytestream bs = { 0 };
+        bytestream* s = &bs;
+        bs.data = v->data;
+        bs.size = v->ptr + tp_length;
+        bs.ptr = v->ptr;
+        v->size += tp_length;
+
         while (ret == 0 && s->ptr < ptr_max) {
             uint64_t extension_type = UINT64_MAX;
             uint64_t extension_length = 0;
             size_t current_ptr = s->ptr;
 
-
             ret |= byteread_vint(s, &extension_type);
             ret |= byteread_vint(s, &extension_length);
 
             fprintf(f, ",\n    ");
 
             if (ret != 0 || bytestream_remain(s) < extension_length) {
-                size_t len = bytestream_remain(s);
+                size_t len = 0;
                 ret = -1;
                 s->ptr = current_ptr;
+                len = bytestream_remain(s);
                 /* Print invalid parameter there */
                 fprintf(f, "\"Parameter_coding_error\": ");
                 qlog_string(f, s, len);

diff --git a/loglib/svg.c b/loglib/svg.c
@@ -215,10 +215,10 @@ int svg_convert(const picoquic_connection_id_t * cid, FILE * f_binlog, FILE * f_
     svg.start_time = 0;
     svg.packet_count = 0;
 
-    binlog_convert_cb_t ctx;
+    binlog_convert_cb_t ctx = { 0 };
     ctx.connection_start = svg_connection_start;
     ctx.connection_end = svg_connection_end;
-    ctx.param_update = svg_alpn_update;
+    ctx.alpn_update = svg_alpn_update;
     ctx.param_update = svg_param_update;
     ctx.pdu = svg_pdu;
     ctx.packet_start = svg_packet_start;
@@ -241,5 +241,9 @@ int svg_convert(const picoquic_connection_id_t * cid, FILE * f_binlog, FILE * f_
         }
     }
 
+    if (svg.f_txtlog != NULL) {
+        svg.f_txtlog = picoquic_file_close(svg.f_txtlog);
+    }
+
     return ret;
 }
diff --git a/picoquic/picoquic.h b/picoquic/picoquic.h
@@ -40,7 +40,7 @@
 extern "C" {
 #endif
 
-#define PICOQUIC_VERSION "1.1.28.8"
+#define PICOQUIC_VERSION "1.1.28.9"
 #define PICOQUIC_ERROR_CLASS 0x400
 #define PICOQUIC_ERROR_DUPLICATE (PICOQUIC_ERROR_CLASS + 1)
 #define PICOQUIC_ERROR_AEAD_CHECK (PICOQUIC_ERROR_CLASS + 3)

diff --git a/picoquic/picoquic_internal.h b/picoquic/picoquic_internal.h
@@ -1529,10 +1529,8 @@ typedef struct st_picoquic_cnx_t {
     uint16_t log_unique;
     FILE* f_binlog;
     char* binlog_file_name;
-#ifdef PICOQUIC_MEMORY_LOG
     void (*memlog_call_back)(picoquic_cnx_t* cnx, picoquic_path_t* path, void* v_memlog, int op_code, uint64_t current_time);
     void *memlog_ctx;
-#endif
 } picoquic_cnx_t;
 
 typedef struct st_picoquic_packet_data_t {

diff --git a/picoquic/quicctx.c b/picoquic/quicctx.c
@@ -4582,11 +4582,9 @@ void picoquic_delete_sooner_packets(picoquic_cnx_t* cnx)
 void picoquic_delete_cnx(picoquic_cnx_t* cnx)
 {
     if (cnx != NULL) {
-#ifdef PICOQUIC_MEMORY_LOG
         if (cnx->memlog_call_back != NULL) {
             cnx->memlog_call_back(cnx, NULL, cnx->memlog_ctx, 1, 0);
         }
-#endif
         if (cnx->quic->perflog_fn != NULL) {
             (void)(cnx->quic->perflog_fn)(cnx->quic, cnx, 0);
         }

diff --git a/picoquic/unified_log.c b/picoquic/unified_log.c
@@ -249,11 +249,9 @@ void picoquic_log_close_connection(picoquic_cnx_t* cnx)
 /* log congestion control parameters */
 void picoquic_log_cc_dump(picoquic_cnx_t* cnx, uint64_t current_time)
 {
-#ifdef PICOQUIC_MEMORY_LOG
     if (cnx->memlog_call_back != NULL) {
         cnx->memlog_call_back(cnx, cnx->path[0], cnx->memlog_ctx, 0, current_time);
     }
-#endif
     if (picoquic_cnx_is_still_logging(cnx)) {
         if (cnx->quic->F_log != NULL) {
             cnx->quic->text_log_fns->log_cc_dump(cnx, current_time);

diff --git a/picoquic_t/picoquic_t.c b/picoquic_t/picoquic_t.c
@@ -50,6 +50,7 @@ static const picoquic_test_def_t test_table[] = {
     { "threading", util_threading_test },
     { "picohash", picohash_test },
     { "picohash_embedded", picohash_embedded_test },
+    { "picolog_basic", picolog_basic_test },
     { "bytestream", bytestream_test },
     { "sockloop_basic", sockloop_basic_test },
     { "sockloop_eio", sockloop_eio_test },
@@ -262,6 +263,7 @@ static const picoquic_test_def_t test_table[] = {
     { "cnxid_transmit_r_disable", transmit_cnxid_retire_disable_test },
     { "cnxid_transmit_r_early", transmit_cnxid_retire_early_test },
     { "probe_api", probe_api_test },
+    { "memlog", memlog_test },
     { "migration" , migration_test },
     { "migration_long", migration_test_long },
     { "migration_with_loss", migration_test_loss },
@@ -289,6 +291,8 @@ static const picoquic_test_def_t test_table[] = {
     { "stream_id_max", stream_id_max_test },
     { "padding_test", padding_test },
     { "packet_trace", packet_trace_test },
+    { "qlog_auto", qlog_auto_test },
+    { "qlog_error", qlog_error_test },
     { "qlog_trace", qlog_trace_test },
     { "qlog_trace_auto", qlog_trace_auto_test },
     { "qlog_trace_only", qlog_trace_only_test },