More robust online rotation.

Try to differentiate between fatal and non-fatal I/O errors.  Give up on
logging only as a last resort.  Clean up logger data properly.  Report
when a file was rotated.

diff --git a/io.cpp b/io.cpp
index cc85673..0fbc4e4 100644 (file)
--- a/io.cpp
+++ b/io.cpp
@@ -1,15 +1,23 @@
 #include "nssm.h"\r
 \r
+#define COMPLAINED_READ (1 << 0)\r
+#define COMPLAINED_WRITE (1 << 1)\r
+#define COMPLAINED_ROTATE (1 << 2)\r
+\r
 static HANDLE create_logging_thread(logger_t *logger) {\r
   HANDLE thread_handle = CreateThread(NULL, 0, log_and_rotate, (void *) logger, 0, logger->tid_ptr);\r
   if (! thread_handle) log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_CREATETHREAD_FAILED, error_string(GetLastError()), 0);\r
   return thread_handle;\r
 }\r
 \r
-static inline void write_bom(logger_t *logger) {\r
+static inline unsigned long guess_charsize(void *address, unsigned long bufsize) {\r
+  if (IsTextUnicode(address, bufsize, 0)) return (unsigned long) sizeof(wchar_t);\r
+  else return (unsigned long) sizeof(char);\r
+}\r
+\r
+static inline void write_bom(logger_t *logger, unsigned long *out) {\r
   wchar_t bom = L'\ufeff';\r
-  unsigned long out;\r
-  if (! WriteFile(logger->write_handle, (void *) &bom, sizeof(bom), &out, 0)) {\r
+  if (! WriteFile(logger->write_handle, (void *) &bom, sizeof(bom), out, 0)) {\r
     log_event(EVENTLOG_WARNING_TYPE, NSSM_EVENT_SOMEBODY_SET_UP_US_THE_BOM, logger->service_name, logger->path, error_string(GetLastError()), 0);\r
   }\r
 }\r
@@ -180,9 +188,13 @@ void rotate_file(TCHAR *service_name, TCHAR *path, unsigned long seconds, unsign
   rotated_filename(path, rotated, _countof(rotated), &st);\r
 \r
   /* Rotate. */\r
-  if (MoveFile(path, rotated)) return;\r
+  if (MoveFile(path, rotated)) {\r
+    log_event(EVENTLOG_INFORMATION_TYPE, NSSM_EVENT_ROTATED, service_name, path, rotated, 0);\r
+    return;\r
+  }\r
   error = GetLastError();\r
 \r
+  if (error == ERROR_FILE_NOT_FOUND) return;\r
   log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_ROTATE_FILE_FAILED, service_name, path, _T("MoveFile()"), rotated, error_string(error), 0);\r
   return;\r
 }\r
@@ -378,6 +390,91 @@ void close_output_handles(STARTUPINFO *si) {
   return close_output_handles(si, true, true);\r
 }\r
 \r
+/*\r
+  Try multiple times to read from a file.\r
+  Returns:  0 on success.\r
+            1 on non-fatal error.\r
+           -1 on fatal error.\r
+*/\r
+static int try_read(logger_t *logger, void *address, unsigned long bufsize, unsigned long *in, int *complained) {\r
+  int ret = 1;\r
+  unsigned long error;\r
+  for (int tries = 0; tries < 5; tries++) {\r
+    if (ReadFile(logger->read_handle, address, bufsize, in, 0)) return 0;\r
+\r
+    error = GetLastError();\r
+    switch (error) {\r
+      /* Other end closed the pipe. */\r
+      case ERROR_BROKEN_PIPE:\r
+        ret = -1;\r
+        goto complain_read;\r
+\r
+      /* Couldn't lock the buffer. */\r
+      case ERROR_NOT_ENOUGH_QUOTA:\r
+        Sleep(2000 + tries * 3000);\r
+        ret = 1;\r
+        continue;\r
+\r
+      /* Write was cancelled by the other end. */\r
+      case ERROR_OPERATION_ABORTED:\r
+        ret = 1;\r
+        goto complain_read;\r
+\r
+      default:\r
+        ret = -1;\r
+    }\r
+  }\r
+\r
+complain_read:\r
+  if (! (*complained & COMPLAINED_READ)) log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_READFILE_FAILED, logger->service_name, logger->path, error_string(error), 0);\r
+  *complained |= COMPLAINED_READ;\r
+  return ret;\r
+}\r
+\r
+/*\r
+  Try multiple times to write to a file.\r
+  Returns:  0 on success.\r
+            1 on non-fatal error.\r
+           -1 on fatal error.\r
+*/\r
+static int try_write(logger_t *logger, void *address, unsigned long bufsize, unsigned long *out, int *complained) {\r
+  int ret = 1;\r
+  unsigned long error;\r
+  for (int tries = 0; tries < 5; tries++) {\r
+    if (WriteFile(logger->write_handle, address, bufsize, out, 0)) return 0;\r
+\r
+    error = GetLastError();\r
+    if (error == ERROR_IO_PENDING) {\r
+      /* Operation was successful pending flush to disk. */\r
+      return 0;\r
+    }\r
+\r
+    switch (error) {\r
+      /* Other end closed the pipe. */\r
+      case ERROR_BROKEN_PIPE:\r
+        ret = -1;\r
+        goto complain_write;\r
+\r
+      /* Couldn't lock the buffer. */\r
+      case ERROR_NOT_ENOUGH_QUOTA:\r
+      /* Out of disk space. */\r
+      case ERROR_DISK_FULL:\r
+        Sleep(2000 + tries * 3000);\r
+        ret = 1;\r
+        continue;\r
+\r
+      default:\r
+        /* We'll lose this line but try to read and write subsequent ones. */\r
+        ret = 1;\r
+    }\r
+  }\r
+\r
+complain_write:\r
+  if (! (*complained & COMPLAINED_WRITE)) log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_WRITEFILE_FAILED, logger->service_name, logger->path, error_string(error), 0);\r
+  *complained |= COMPLAINED_WRITE;\r
+  return ret;\r
+}\r
+\r
 /* Wrapper to be called in a new thread for logging. */\r
 unsigned long WINAPI log_and_rotate(void *arg) {\r
   logger_t *logger = (logger_t *) arg;\r
@@ -398,28 +495,36 @@ unsigned long WINAPI log_and_rotate(void *arg) {
   char buffer[1024];\r
   void *address;\r
   unsigned long in, out;\r
+  unsigned long charsize = 0;\r
+  unsigned long error;\r
+  int ret;\r
+  int complained = 0;\r
+\r
   while (true) {\r
     /* Read data from the pipe. */\r
     address = &buffer;\r
-    if (! ReadFile(logger->read_handle, address, sizeof(buffer), &in, 0)) {\r
-      log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_READFILE_FAILED, logger->service_name, logger->path, error_string(GetLastError()), 0);\r
+    ret = try_read(logger, address, sizeof(buffer), &in, &complained);\r
+    if (ret < 0) {\r
+      HeapFree(GetProcessHeap(), 0, logger);\r
       return 2;\r
     }\r
+    else if (ret) continue;\r
 \r
     if (size + (__int64) in >= logger->size) {\r
       /* Look for newline. */\r
       unsigned long i;\r
       for (i = 0; i < in; i++) {\r
         if (buffer[i] == '\n') {\r
-          unsigned char unicode = IsTextUnicode(address, sizeof(buffer), 0);\r
-          if (unicode) i += sizeof(wchar_t);\r
-          else i += sizeof(char);\r
+          if (! charsize) charsize = guess_charsize(address, in);\r
+          i += charsize;\r
 \r
           /* Write up to the newline. */\r
-          if (! WriteFile(logger->write_handle, address, i, &out, 0)) {\r
-            log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_WRITEFILE_FAILED, logger->service_name, logger->path, error_string(GetLastError()), 0);\r
+          ret = try_write(logger, address, i, &out, &complained);\r
+          if (ret < 0) {\r
+            HeapFree(GetProcessHeap(), 0, logger);\r
             return 3;\r
           }\r
+          size += (__int64) out;\r
 \r
           /* Rotate. */\r
           TCHAR rotated[MAX_PATH];\r
@@ -431,10 +536,15 @@ unsigned long WINAPI log_and_rotate(void *arg) {
             risk losing everything.\r
           */\r
           CloseHandle(logger->write_handle);\r
-          if (! MoveFile(logger->path, rotated)) {\r
-            unsigned long error = GetLastError();\r
+          if (MoveFile(logger->path, rotated)) {\r
+            log_event(EVENTLOG_INFORMATION_TYPE, NSSM_EVENT_ROTATED, logger->service_name, logger->path, rotated, 0);\r
+            size = 0LL;\r
+          }\r
+          else {\r
+            error = GetLastError();\r
             if (error != ERROR_FILE_NOT_FOUND) {\r
-              log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_ROTATE_FILE_FAILED, logger->service_name, logger->path, _T("MoveFile()"), rotated, error_string(error), 0);\r
+              if (! (complained & COMPLAINED_ROTATE)) log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_ROTATE_FILE_FAILED, logger->service_name, logger->path, _T("MoveFile()"), rotated, error_string(error), 0);\r
+              complained |= COMPLAINED_ROTATE;\r
               /* We can at least try to re-open the existing file. */\r
               logger->disposition = OPEN_ALWAYS;\r
             }\r
@@ -443,36 +553,38 @@ unsigned long WINAPI log_and_rotate(void *arg) {
           /* Reopen. */\r
           logger->write_handle = append_to_file(logger->path, logger->sharing, 0, logger->disposition, logger->flags);\r
           if (! logger->write_handle) {\r
-            log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_CREATEFILE_FAILED, logger->path, error_string(GetLastError()), 0);\r
+            error = GetLastError();\r
+            log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_CREATEFILE_FAILED, logger->path, error_string(error), 0);\r
             /* Oh dear.  Now we can't log anything further. */\r
+            HeapFree(GetProcessHeap(), 0, logger);\r
             return 4;\r
           }\r
 \r
-          /* Unicode files need a new BOM. */\r
-          if (unicode) write_bom(logger);\r
-\r
           /* Resume writing after the newline. */\r
-          size = 0LL;\r
           address = (void *) ((char *) address + i);\r
           in -= i;\r
-\r
-          break;\r
         }\r
       }\r
     }\r
-    else if (! size) {\r
+\r
+    if (! size) {\r
       /* Write a BOM to the new file. */\r
-      if (IsTextUnicode(address, sizeof(buffer), 0)) write_bom(logger);\r
+      if (! charsize) charsize = guess_charsize(address, in);\r
+      if (charsize == sizeof(wchar_t)) write_bom(logger, &out);\r
+      size += (__int64) out;\r
     }\r
 \r
-    /* Write the data. */\r
-    if (! WriteFile(logger->write_handle, address, in, &out, 0)) {\r
-      log_event(EVENTLOG_ERROR_TYPE, NSSM_EVENT_WRITEFILE_FAILED, logger->service_name, logger->path, error_string(GetLastError()), 0);\r
-      return 3;\r
-    }\r
+    /* Write the data, if any. */\r
+    if (! in) continue;\r
 \r
+    ret = try_write(logger, address, in, &out, &complained);\r
     size += (__int64) out;\r
+    if (ret < 0) {\r
+      HeapFree(GetProcessHeap(), 0, logger);\r
+      return 3;\r
+    }\r
   }\r
 \r
+  HeapFree(GetProcessHeap(), 0, logger);\r
   return 0;\r
 }\r

diff --git a/messages.mc b/messages.mc
index ca6bbcf..68b5289 100644 (file)
Binary files a/messages.mc and b/messages.mc differ