Emit Windows events from libiothsm (Azure#1651)

With this change, all libiothsm logs are also emitted as Windows events
in addition to being written to stdout, unless iotedged is running in
console mode.

This also changes the default log level of libiothsm to "information"
to match iotedged's setting.

edgelet/hsm-sys/azure-iot-hsm-c/src/edge_hsm_client_crypto.c

@@ -32,6 +32,9 @@ int hsm_client_crypto_init(void)
         int status;
         const HSM_CLIENT_STORE_INTERFACE* store_if;
         const HSM_CLIENT_KEY_INTERFACE* key_if;
+
+        log_init(LVL_INFO);
+
         if ((store_if = hsm_client_store_interface()) == NULL)
         {
             LOG_ERROR("HSM store interface not available");

edgelet/hsm-sys/azure-iot-hsm-c/src/edge_hsm_client_x509.c

@@ -36,6 +36,8 @@ int hsm_client_x509_init()
 
     if (!g_is_x509_initialized)
     {
+        log_init(LVL_INFO);
+
         result = hsm_client_crypto_init();
         if (result == 0)
         {

edgelet/hsm-sys/azure-iot-hsm-c/src/hsm_client_tpm_device.c

@@ -591,6 +591,8 @@ static void hsm_client_tpm_free_buffer(void* buffer)
 
 int hsm_client_tpm_device_init(void)
 {
+    log_init(LVL_INFO);
+
     return 0;
 }
 

edgelet/hsm-sys/azure-iot-hsm-c/src/hsm_client_tpm_in_mem.c

@@ -30,6 +30,9 @@ int hsm_client_tpm_store_init(void)
     {
         const HSM_CLIENT_STORE_INTERFACE* store_if;
         const HSM_CLIENT_KEY_INTERFACE* key_if;
+
+        log_init(LVL_INFO);
+
         if ((store_if = hsm_client_store_interface()) == NULL)
         {
             LOG_ERROR("HSM store interface not available");

edgelet/hsm-sys/azure-iot-hsm-c/src/hsm_log.c

@@ -1,16 +1,44 @@
 #include <stdarg.h>
+#include <stdbool.h>
 #include <stdio.h>
 #include <time.h>
 
 #include "hsm_log.h"
+
+#if defined __WINDOWS__ || defined _WIN32 || defined _WIN64 || defined _Windows
+#include <Windows.h>
+#endif
+
 #define MAX_LOG_SIZE 256
 
-static int log_level = LVL_ERROR;
+static bool g_is_log_initialized = false;
 
-void set_log_level(int level)
-{
-    if ((LVL_DEBUG <= level) && (level <= LVL_ERROR)) {
-        log_level = level;
+static int log_level = LVL_INFO;
+
+#if defined __WINDOWS__ || defined _WIN32 || defined _WIN64 || defined _Windows
+static HANDLE event_log_handle = NULL;
+#endif
+
+void log_init(int level) {
+    if (!g_is_log_initialized) {
+        if ((LVL_DEBUG <= level) && (level <= LVL_ERROR)) {
+            log_level = level;
+        }
+
+#if defined __WINDOWS__ || defined _WIN32 || defined _WIN64 || defined _Windows
+        // Emit logs as events if running as a service, ie not running in console mode
+        if (GetEnvironmentVariable("IOTEDGE_RUN_AS_CONSOLE", NULL, 0) == 0) {
+            if (GetLastError() == ERROR_ENVVAR_NOT_FOUND) {
+                event_log_handle = RegisterEventSourceA(NULL, "iotedged");
+
+                // Ignore errors. It just means event_log_handle will remain NULL, so logs will not be emitted as Windows events.
+            }
+        }
+#endif
+
+        g_is_log_initialized = true;
+
+        LOG_INFO("Initialized logging");
     }
 }
 
@@ -19,6 +47,14 @@ void log_msg(int level, const char* file, const char* function, int line, const
     static char levels[3][5] = {"DBUG", "INFO", "ERR!"};
     static int  syslog_levels[3] = { 7, 6, 3 };
 
+#if defined __WINDOWS__ || defined _WIN32 || defined _WIN64 || defined _Windows
+    static WORD event_log_levels[3] = { EVENTLOG_SUCCESS, EVENTLOG_INFORMATION_TYPE, EVENTLOG_ERROR_TYPE };
+
+    // The values returned here must match the event message IDs specified
+    // in the event_messages.mc file.
+    static DWORD event_log_ids[3] = { 4, 3, 1 };
+#endif
+
     if (level >= log_level) {
         time_t now;
         char buffer[MAX_LOG_SIZE];
@@ -30,5 +66,31 @@ void log_msg(int level, const char* file, const char* function, int line, const
         vsnprintf(buffer, MAX_LOG_SIZE, fmt_str, args);
         printf("<%d>%s [%s] (%s:%s:%d) %s\r\n", syslog_levels[level], time_buf, levels[level], file, function, line, buffer);
         va_end (args);
+
+#if defined __WINDOWS__ || defined _WIN32 || defined _WIN64 || defined _Windows
+        if (event_log_handle != NULL) {
+            size_t log_length = strlen(file) + strlen(function) + strlen(buffer);
+            log_length += 50; // Extra bytes for prefix, punctuation and whitespace
+            char* event_log_buffer = malloc(log_length);
+
+            if (snprintf(event_log_buffer, log_length, "libiothsm -- (%s:%s:%d) %s", file, function, line, buffer) > 0) {
+                char* event_log_strings[] = { NULL };
+                event_log_strings[0] = event_log_buffer;
+                ReportEventA(
+                    event_log_handle,
+                    event_log_levels[level],
+                    0,
+                    event_log_ids[level],
+                    NULL,
+                    1,
+                    0,
+                    event_log_strings,
+                    NULL
+                );
+            }
+
+            free(event_log_buffer);
+        }
+#endif
     }
 }

edgelet/hsm-sys/azure-iot-hsm-c/src/hsm_log.h

@@ -9,7 +9,7 @@
 #define LOG_DEBUG(fmt, ...) log_msg(LVL_DEBUG, __FILE__, __func__, __LINE__, fmt, ##__VA_ARGS__)
 #define LOG_INFO(fmt, ...)  log_msg(LVL_INFO, __FILE__, __func__, __LINE__, fmt, ##__VA_ARGS__)
 
-extern void set_log_level(int level);
+extern void log_init(int level);
 extern void log_msg(int level, const char* file, const char* function, int line, const char* fmt_str, ...)
 #if defined(__GNUC__) || defined(__clang__)
     __attribute__ ((format (printf, 5, 6)));