Log TLS and HTTP statistics on exit.

These stats measure how efficiently TLS and HTTP are reusing connections (i.e. pipelining).

src/Makefile.in

@@ -270,7 +270,7 @@ common/error.o: common/error.c build.auto.h common/error.auto.c common/error.aut
 common/exec.o: common/exec.c build.auto.h common/assert.h common/debug.h common/error.auto.h common/error.h common/exec.h common/io/filter/filter.h common/io/filter/group.h common/io/handleRead.h common/io/handleWrite.h common/io/io.h common/io/read.h common/io/read.intern.h common/io/write.h common/io/write.intern.h common/log.h common/logLevel.h common/macro.h common/memContext.h common/object.h common/stackTrace.h common/time.h common/type/buffer.h common/type/convert.h common/type/keyValue.h common/type/string.h common/type/variant.h common/type/variantList.h common/wait.h
 	$(CC) $(CFLAGS) $(CMAKE) -c common/exec.c -o common/exec.o
 
-common/exit.o: common/exit.c build.auto.h command/command.h common/assert.h common/debug.h common/error.auto.h common/error.h common/exit.h common/io/filter/filter.h common/io/filter/group.h common/io/read.h common/io/write.h common/lock.h common/log.h common/logLevel.h common/memContext.h common/stackTrace.h common/time.h common/type/buffer.h common/type/convert.h common/type/keyValue.h common/type/string.h common/type/stringList.h common/type/variant.h common/type/variantList.h config/config.auto.h config/config.h config/define.auto.h config/define.h perl/exec.h protocol/client.h protocol/command.h protocol/helper.h
+common/exit.o: common/exit.c build.auto.h command/command.h common/assert.h common/debug.h common/error.auto.h common/error.h common/exit.h common/io/filter/filter.h common/io/filter/group.h common/io/http/client.h common/io/http/header.h common/io/http/query.h common/io/read.h common/io/tls/client.h common/io/write.h common/lock.h common/log.h common/logLevel.h common/memContext.h common/stackTrace.h common/time.h common/type/buffer.h common/type/convert.h common/type/keyValue.h common/type/string.h common/type/stringList.h common/type/variant.h common/type/variantList.h config/config.auto.h config/config.h config/define.auto.h config/define.h perl/exec.h protocol/client.h protocol/command.h protocol/helper.h
 	$(CC) $(CFLAGS) $(CMAKE) -c common/exit.c -o common/exit.o
 
 common/fork.o: common/fork.c build.auto.h common/assert.h common/debug.h common/error.auto.h common/error.h common/log.h common/logLevel.h common/stackTrace.h common/type/convert.h

src/common/exit.c

@@ -10,6 +10,8 @@ Exit Routines
 #include "common/debug.h"
 #include "common/error.h"
 #include "common/exit.h"
+#include "common/io/http/client.h"
+#include "common/io/tls/client.h"
 #include "common/lock.h"
 #include "common/log.h"
 #include "config/config.h"
@@ -152,6 +154,18 @@ exitSafe(int result, bool error, SignalType signalType)
     TRY_END();
 #endif
 
+    // Log tls statistics
+    String *tlsClientStat = tlsClientStatStr();
+
+    if (tlsClientStat != NULL)
+        LOG_DETAIL(strPtr(tlsClientStat));
+
+    // Log http statistics
+    String *httpClientStat = httpClientStatStr();
+
+    if (httpClientStat != NULL)
+        LOG_INFO(strPtr(httpClientStat));
+
     // Log command end if a command is set
     if (cfgCommand() != cfgCmdNone)
     {

src/common/io/http/client.c

@@ -40,6 +40,11 @@ STRING_EXTERN(HTTP_HEADER_ETAG_STR,                                 HTTP_HEADER_
 // 5xx errors that should always be retried
 #define HTTP_RESPONSE_CODE_RETRY_CLASS                              5
 
+/***********************************************************************************************************************************
+Statistics
+***********************************************************************************************************************************/
+static HttpClientStat httpClientStatLocal;
+
 /***********************************************************************************************************************************
 Object type
 ***********************************************************************************************************************************/
@@ -192,6 +197,8 @@ httpClientNew(
 
         this->timeout = timeout;
         this->tls = tlsClientNew(host, port, timeout, verifyPeer, caFile, caPath);
+
+        httpClientStatLocal.object++;
     }
     MEM_CONTEXT_NEW_END();
 
@@ -253,7 +260,8 @@ httpClientRequest(
 
             TRY_BEGIN()
             {
-                tlsClientOpen(this->tls);
+                if (tlsClientOpen(this->tls))
+                    httpClientStatLocal.session++;
 
                 // Write the request
                 String *queryStr = httpQueryRender(query);
@@ -361,7 +369,10 @@ httpClientRequest(
                     // If the server notified of a closed connection then close the client connection after reading content.  This
                     // prevents doing a retry on the next request when using the closed connection.
                     if (strEq(headerKey, HTTP_HEADER_CONNECTION_STR) && strEq(headerValue, HTTP_VALUE_CONNECTION_CLOSE_STR))
+                    {
                         this->closeOnContentEof = true;
+                        httpClientStatLocal.close++;
+                    }
                 }
                 while (1);
 
@@ -425,6 +436,8 @@ httpClientRequest(
                 {
                     LOG_DEBUG("retry %s: %s", errorTypeName(errorType()), errorMessage());
                     retry = true;
+
+                    httpClientStatLocal.retry++;
                 }
 
                 tlsClientClose(this->tls);
@@ -438,12 +451,36 @@ httpClientRequest(
 
         // Move the result buffer (if any) to the parent context
         bufMove(result, MEM_CONTEXT_OLD());
+
+        httpClientStatLocal.request++;
     }
     MEM_CONTEXT_TEMP_END();
 
     FUNCTION_LOG_RETURN(BUFFER, result);
 }
 
+/***********************************************************************************************************************************
+Format statistics to a string
+***********************************************************************************************************************************/
+String *
+httpClientStatStr(void)
+{
+    FUNCTION_TEST_VOID();
+
+    String *result = NULL;
+
+    if (httpClientStatLocal.object > 0)
+    {
+        result = strNewFmt(
+            "http statistics: objects %" PRIu64 ", sessions %" PRIu64 ", requests %" PRIu64 ", retries %" PRIu64
+                ", closes %" PRIu64,
+            httpClientStatLocal.object, httpClientStatLocal.session, httpClientStatLocal.request, httpClientStatLocal.retry,
+            httpClientStatLocal.close);
+    }
+
+    FUNCTION_TEST_RETURN(result);
+}
+
 /***********************************************************************************************************************************
 Get read interface
 ***********************************************************************************************************************************/

src/common/io/http/client.h

@@ -47,6 +47,18 @@ HTTP Constants
 #define HTTP_RESPONSE_CODE_FORBIDDEN                                403
 #define HTTP_RESPONSE_CODE_NOT_FOUND                                404
 
+/***********************************************************************************************************************************
+Statistics
+***********************************************************************************************************************************/
+typedef struct HttpClientStat
+{
+    uint64_t object;                                                // Objects created
+    uint64_t session;                                               // TLS sessions created
+    uint64_t request;                                               // Requests (i.e. calls to httpClientRequest())
+    uint64_t retry;                                                 // Request retries
+    uint64_t close;                                                 // Closes forced by server
+} HttpClientStat;
+
 /***********************************************************************************************************************************
 Constructor
 ***********************************************************************************************************************************/
@@ -59,6 +71,7 @@ Functions
 Buffer *httpClientRequest(
     HttpClient *this, const String *verb, const String *uri, const HttpQuery *query, const HttpHeader *requestHeader,
     const Buffer *body, bool returnContent);
+String *httpClientStatStr(void);
 
 /***********************************************************************************************************************************
 Getters

src/common/io/tls/client.c

@@ -29,6 +29,11 @@ TLS Client
 #include "common/type/keyValue.h"
 #include "common/wait.h"
 
+/***********************************************************************************************************************************
+Statistics
+***********************************************************************************************************************************/
+static TlsClientStat tlsClientStatLocal;
+
 /***********************************************************************************************************************************
 Object type
 ***********************************************************************************************************************************/
@@ -126,6 +131,8 @@ tlsClientNew(
             else
                 cryptoError(SSL_CTX_set_default_verify_paths(this->context) != 1, "unable to set default CA certificate location");
         }
+
+        tlsClientStatLocal.object++;
     }
     MEM_CONTEXT_NEW_END();
 
@@ -411,7 +418,7 @@ tlsClientEof(THIS_VOID)
 /***********************************************************************************************************************************
 Open connection if this is a new client or if the connection was closed by the server
 ***********************************************************************************************************************************/
-void
+bool
 tlsClientOpen(TlsClient *this)
 {
     FUNCTION_LOG_BEGIN(logLevelTrace)
@@ -420,6 +427,8 @@ tlsClientOpen(TlsClient *this)
 
     ASSERT(this != NULL);
 
+    bool result = false;
+
     if (this->session == NULL)
     {
         // Free the read/write interfaces
@@ -522,6 +531,8 @@ tlsClientOpen(TlsClient *this)
                     {
                         LOG_DEBUG("retry %s: %s", errorTypeName(errorType()), errorMessage());
                         retry = true;
+
+                        tlsClientStatLocal.retry++;
                     }
 
                     tlsClientClose(this);
@@ -570,9 +581,34 @@ tlsClientOpen(TlsClient *this)
             ioReadOpen(this->read);
         }
         MEM_CONTEXT_END();
+
+        tlsClientStatLocal.session++;
+        result = true;
     }
 
-    FUNCTION_LOG_RETURN_VOID();
+    tlsClientStatLocal.request++;
+
+    FUNCTION_LOG_RETURN(BOOL, result);
+}
+
+/***********************************************************************************************************************************
+Format statistics to a string
+***********************************************************************************************************************************/
+String *
+tlsClientStatStr(void)
+{
+    FUNCTION_TEST_VOID();
+
+    String *result = NULL;
+
+    if (tlsClientStatLocal.object > 0)
+    {
+        result = strNewFmt(
+            "tls statistics: objects %" PRIu64 ", sessions %" PRIu64 ", requests %" PRIu64 ", retries %" PRIu64,
+            tlsClientStatLocal.object, tlsClientStatLocal.session, tlsClientStatLocal.request, tlsClientStatLocal.retry);
+    }
+
+    FUNCTION_TEST_RETURN(result);
 }
 
 /***********************************************************************************************************************************

src/common/io/tls/client.h

@@ -29,6 +29,17 @@ typedef struct TlsClient TlsClient;
 #include "common/time.h"
 #include "common/type/string.h"
 
+/***********************************************************************************************************************************
+Statistics
+***********************************************************************************************************************************/
+typedef struct TlsClientStat
+{
+    uint64_t object;                                                // Objects created
+    uint64_t session;                                               // Sessions created
+    uint64_t request;                                               // Requests (i.e. calls to tlsClientOpen())
+    uint64_t retry;                                                 // Connection retries
+} TlsClientStat;
+
 /***********************************************************************************************************************************
 Constructor
 ***********************************************************************************************************************************/
@@ -38,8 +49,9 @@ TlsClient *tlsClientNew(
 /***********************************************************************************************************************************
 Functions
 ***********************************************************************************************************************************/
-void tlsClientOpen(TlsClient *this);
+bool tlsClientOpen(TlsClient *this);
 void tlsClientClose(TlsClient *this);
+String *tlsClientStatStr(void);
 
 /***********************************************************************************************************************************
 Getters

test/src/module/common/exitTest.c

@@ -2,6 +2,7 @@
 Test Exit Routines
 ***********************************************************************************************************************************/
 #include "common/error.h"
+#include "common/io/tls/client.h"
 #include "common/log.h"
 #include "config/config.h"
 
@@ -126,9 +127,14 @@ testRun(void)
         harnessLogResult("P00   INFO: archive-push command end: terminated on signal from child process");
 
         // -------------------------------------------------------------------------------------------------------------------------
+        tlsClientNew(strNew("BOGUS"), 443, 1000, true, NULL, NULL);
+        httpClientNew(strNew("BOGUS"), 443, 1000, true, NULL, NULL);
+
         TEST_RESULT_INT(
             exitSafe(errorTypeCode(&TermError), false, signalTypeTerm), errorTypeCode(&TermError), "exit on term with SIGTERM");
-        harnessLogResult("P00   INFO: archive-push command end: terminated on signal [SIGTERM]");
+        harnessLogResult(
+            "P00   INFO: http statistics: objects 1, sessions 0, requests 0, retries 0, closes 0\n"
+            "P00   INFO: archive-push command end: terminated on signal [SIGTERM]");
     }
 
     FUNCTION_HARNESS_RESULT_VOID();

test/src/module/common/ioHttpTest.c

@@ -380,6 +380,10 @@ testRun(void)
         HttpClient *client = NULL;
         ioBufferSizeSet(35);
 
+        // Reset statistics
+        httpClientStatLocal = (HttpClientStat){0};
+        TEST_RESULT_STR(httpClientStatStr(), NULL, "no stats yet");
+
         TEST_ASSIGN(client, httpClientNew(strNew("localhost"), TLS_TEST_PORT, 500, true, NULL, NULL), "new client");
 
         TEST_ERROR(
@@ -510,6 +514,8 @@ testRun(void)
         TEST_RESULT_VOID(ioRead(httpClientIoRead(client), buffer),  "    read response");
         TEST_RESULT_STR(strPtr(strNewBuf(buffer)),  "01234567890123456789012345678901012", "    check response");
 
+        TEST_RESULT_BOOL(httpClientStatStr() != NULL, true, "check statistics exist");
+
         TEST_RESULT_VOID(httpClientFree(client), "free client");
     }
 

test/src/module/common/ioTlsTest.c

@@ -177,6 +177,10 @@ testRun(void)
     {
         TlsClient *client = NULL;
 
+        // Reset statistics
+        tlsClientStatLocal = (TlsClientStat){0};
+        TEST_RESULT_STR(tlsClientStatStr(), NULL, "no stats yet");
+
         testTlsServer();
         ioBufferSizeSet(12);
 
@@ -220,6 +224,8 @@ testRun(void)
         TEST_RESULT_INT(ioRead(tlsClientIoRead(client), output), 0, "read no output after eof");
         TEST_RESULT_BOOL(ioReadEof(tlsClientIoRead(client)), true, "    check eof = true");
 
+        TEST_RESULT_BOOL(tlsClientStatStr() != NULL, true, "check statistics exist");
+
         TEST_RESULT_VOID(tlsClientFree(client), "free client");
     }