From 02da8079ee6e2101f3ec725509298506f9451911 Mon Sep 17 00:00:00 2001 From: Mikhail Pridushchenko Date: Wed, 28 Jun 2017 16:22:53 +0300 Subject: [PATCH] UNIX services write logs to stdout To better adopt SoftEther VPN for execution in Docker container all services output logs to stdout if running in foreground. --- src/Cedar/Logging.c | 547 ++++++++++++++++++++++++------------------ src/Mayaqua/Mayaqua.c | 2 + src/Mayaqua/Mayaqua.h | 1 + src/Mayaqua/Unix.c | 17 ++ src/Mayaqua/Unix.h | 1 + 5 files changed, 331 insertions(+), 237 deletions(-) diff --git a/src/Cedar/Logging.c b/src/Cedar/Logging.c index 4414c10d..6f75e37f 100644 --- a/src/Cedar/Logging.c +++ b/src/Cedar/Logging.c @@ -133,6 +133,10 @@ static char *delete_targets[] = static UINT eraser_check_interval = DISK_FREE_CHECK_INTERVAL_DEFAULT; static UINT64 logger_max_log_size = MAX_LOG_SIZE_DEFAULT; +static bool LogThreadWriteGeneral(LOG *log_object, BUF *buffer, IO **io, bool *log_date_changed, char *current_logfile_datename, char *current_file_name); +static bool LogThreadWriteStdout(LOG *log_object, BUF *buffer, IO *io); +static IO *GetIO4Stdout(); + // Send with syslog void SendSysLog(SLOG *g, wchar_t *str) { @@ -2634,7 +2638,7 @@ void LogThread(THREAD *thread, void *param) g = (LOG *)param; - io = NULL; + io = g_foreground ? GetIO4Stdout() : NULL; b = NewBuf(); #ifdef OS_WIN32 @@ -2648,253 +2652,23 @@ void LogThread(THREAD *thread, void *param) while (true) { - RECORD *rec; UINT64 s = Tick64(); while (true) { - char file_name[MAX_SIZE]; - UINT num; - - // Retrieve a record from the head of the queue - LockQueue(g->RecordQueue); + if (g_foreground) { - rec = GetNext(g->RecordQueue); - num = g->RecordQueue->num_item; - } - UnlockQueue(g->RecordQueue); - -#ifdef OS_WIN32 - if (num >= LOG_ENGINE_SAVE_START_CACHE_COUNT) - { - // Raise the priority - if (last_priority_flag == false) + if (! LogThreadWriteStdout(g, b, io)) { - Debug("LOG_THREAD: MsSetThreadPriorityRealtime\n"); - MsSetThreadPriorityRealtime(); - last_priority_flag = true; - } - } - - if (num < (LOG_ENGINE_SAVE_START_CACHE_COUNT / 2)) - { - // Restore the priority - if (last_priority_flag) - { - Debug("LOG_THREAD: MsSetThreadPriorityIdle\n"); - MsSetThreadPriorityIdle(); - last_priority_flag = false; - } - } -#endif // OS_WIN32 - - if (b->Size > GetMaxLogSize()) - { - // Erase if the size of the buffer is larger than the maximum log file size - ClearBuf(b); - } - - if (b->Size >= LOG_ENGINE_BUFFER_CACHE_SIZE_MAX) - { - // Write the contents of the buffer to the file - if (io != NULL) - { - if ((g->CurrentFilePointer + (UINT64)b->Size) > GetMaxLogSize()) - { - if (g->log_number_incremented == false) - { - g->CurrentLogNumber++; - g->log_number_incremented = true; - } - } - else - { - if (FileWrite(io, b->Buf, b->Size) == false) - { - FileCloseEx(io, true); - // If it fails to write to the file, - // erase the buffer and give up - ClearBuf(b); - io = NULL; - } - else - { - g->CurrentFilePointer += (UINT64)b->Size; - ClearBuf(b); - } - } - } - } - - if (rec == NULL) - { - if (b->Size != 0) - { - // Write the contents of the buffer to the file - if (io != NULL) - { - if ((g->CurrentFilePointer + (UINT64)b->Size) > GetMaxLogSize()) - { - if (g->log_number_incremented == false) - { - g->CurrentLogNumber++; - g->log_number_incremented = true; - } - } - else - { - if (FileWrite(io, b->Buf, b->Size) == false) - { - FileCloseEx(io, true); - // If it fails to write to the file, - // erase the buffer and give up - ClearBuf(b); - io = NULL; - } - else - { - g->CurrentFilePointer += (UINT64)b->Size; - ClearBuf(b); - } - } - } - } - - Set(g->FlushEvent); - break; - } - - // Generate a log file name - LockLog(g); - { - log_date_changed = MakeLogFileName(g, file_name, sizeof(file_name), - g->DirName, g->Prefix, rec->Tick, g->SwitchType, g->CurrentLogNumber, current_logfile_datename); - - if (log_date_changed) - { - UINT i; - - g->CurrentLogNumber = 0; - MakeLogFileName(g, file_name, sizeof(file_name), - g->DirName, g->Prefix, rec->Tick, g->SwitchType, 0, current_logfile_datename); - for (i = 0;;i++) - { - char tmp[MAX_SIZE]; - MakeLogFileName(g, tmp, sizeof(tmp), - g->DirName, g->Prefix, rec->Tick, g->SwitchType, i, current_logfile_datename); - - if (IsFileExists(tmp) == false) - { - break; - } - StrCpy(file_name, sizeof(file_name), tmp); - g->CurrentLogNumber = i; - } - } - } - UnlockLog(g); - - if (io != NULL) - { - if (StrCmp(current_file_name, file_name) != 0) - { - // If a log file is currently opened and writing to another log - // file is needed for this time, write the contents of the - //buffer and close the log file. Write the contents of the buffer - if (io != NULL) - { - if (log_date_changed) - { - if ((g->CurrentFilePointer + (UINT64)b->Size) <= GetMaxLogSize()) - { - if (FileWrite(io, b->Buf, b->Size) == false) - { - FileCloseEx(io, true); - ClearBuf(b); - io = NULL; - } - else - { - g->CurrentFilePointer += (UINT64)b->Size; - ClearBuf(b); - } - } - } - // Close the file - FileCloseEx(io, true); - } - - g->log_number_incremented = false; - - // Open or create a new log file - StrCpy(current_file_name, sizeof(current_file_name), file_name); - io = FileOpen(file_name, true); - if (io == NULL) - { - // Create a log file - LockLog(g); - { - MakeDir(g->DirName); - -#ifdef OS_WIN32 - Win32SetFolderCompress(g->DirName, true); -#endif // OS_WIN32 - } - UnlockLog(g); - io = FileCreate(file_name); - g->CurrentFilePointer = 0; - } - else - { - // Seek to the end of the log file - g->CurrentFilePointer = FileSize64(io); - FileSeek(io, SEEK_END, 0); - } + break; } } else { - // Open or create a new log file - StrCpy(current_file_name, sizeof(current_file_name), file_name); - io = FileOpen(file_name, true); - if (io == NULL) + if (! LogThreadWriteGeneral(g, b, &io, &log_date_changed, current_logfile_datename, current_file_name)) { - // Create a log file - LockLog(g); - { - MakeDir(g->DirName); -#ifdef OS_WIN32 - Win32SetFolderCompress(g->DirName, true); -#endif // OS_WIN32 - } - UnlockLog(g); - io = FileCreate(file_name); - g->CurrentFilePointer = 0; - if (io == NULL) - { - //Debug("Logging.c: SleepThread(30);\n"); - SleepThread(30); - } + break; } - else - { - // Seek to the end of the log file - g->CurrentFilePointer = FileSize64(io); - FileSeek(io, SEEK_END, 0); - } - - g->log_number_incremented = false; - } - - // Write the contents of the log to the buffer - WriteRecordToBuffer(b, rec); - - // Release the memory of record - Free(rec); - - if (io == NULL) - { - break; } } @@ -2929,7 +2703,7 @@ void LogThread(THREAD *thread, void *param) } } - if (io != NULL) + if (io != NULL && !g_foreground) { FileCloseEx(io, true); } @@ -2937,6 +2711,305 @@ void LogThread(THREAD *thread, void *param) FreeBuf(b); } +static bool LogThreadWriteGeneral(LOG *log_object, BUF *buffer, IO **io, bool *log_date_changed, char *current_logfile_datename, char *current_file_name) +{ + RECORD *rec; + char file_name[MAX_SIZE]; + UINT num; + + // Retrieve a record from the head of the queue + LockQueue(log_object->RecordQueue); + { + rec = GetNext(log_object->RecordQueue); + num = log_object->RecordQueue->num_item; + } + UnlockQueue(log_object->RecordQueue); + +#ifdef OS_WIN32 + if (num >= LOG_ENGINE_SAVE_START_CACHE_COUNT) + { + // Raise the priority + if (last_priority_flag == false) + { + Debug("LOG_THREAD: MsSetThreadPriorityRealtime\n"); + MsSetThreadPriorityRealtime(); + last_priority_flag = true; + } + } + + if (num < (LOG_ENGINE_SAVE_START_CACHE_COUNT / 2)) + { + // Restore the priority + if (last_priority_flag) + { + Debug("LOG_THREAD: MsSetThreadPriorityIdle\n"); + MsSetThreadPriorityIdle(); + last_priority_flag = false; + } + } +#endif // OS_WIN32 + + if (buffer->Size > GetMaxLogSize()) + { + // Erase if the size of the buffer is larger than the maximum log file size + ClearBuf(buffer); + } + + if (buffer->Size >= LOG_ENGINE_BUFFER_CACHE_SIZE_MAX) + { + // Write the contents of the buffer to the file + if (*io != NULL) + { + if ((log_object->CurrentFilePointer + (UINT64)buffer->Size) > GetMaxLogSize()) + { + if (log_object->log_number_incremented == false) + { + log_object->CurrentLogNumber++; + log_object->log_number_incremented = true; + } + } + else + { + if (FileWrite(*io, buffer->Buf, buffer->Size) == false) + { + FileCloseEx(*io, true); + // If it fails to write to the file, + // erase the buffer and give up + ClearBuf(buffer); + *io = NULL; + } + else + { + log_object->CurrentFilePointer += (UINT64)buffer->Size; + ClearBuf(buffer); + } + } + } + } + + if (rec == NULL) + { + if (buffer->Size != 0) + { + // Write the contents of the buffer to the file + if (*io != NULL) + { + if ((log_object->CurrentFilePointer + (UINT64)buffer->Size) > GetMaxLogSize()) + { + if (log_object->log_number_incremented == false) + { + log_object->CurrentLogNumber++; + log_object->log_number_incremented = true; + } + } + else + { + if (FileWrite(*io, buffer->Buf, buffer->Size) == false) + { + FileCloseEx(*io, true); + // If it fails to write to the file, + // erase the buffer and give up + ClearBuf(buffer); + *io = NULL; + } + else + { + log_object->CurrentFilePointer += (UINT64)buffer->Size; + ClearBuf(buffer); + } + } + } + } + + Set(log_object->FlushEvent); + return false; + } + + // Generate a log file name + LockLog(log_object); + { + *log_date_changed = MakeLogFileName(log_object, file_name, sizeof(file_name), + log_object->DirName, log_object->Prefix, rec->Tick, log_object->SwitchType, log_object->CurrentLogNumber, current_logfile_datename); + + if (*log_date_changed) + { + UINT i; + + log_object->CurrentLogNumber = 0; + MakeLogFileName(log_object, file_name, sizeof(file_name), + log_object->DirName, log_object->Prefix, rec->Tick, log_object->SwitchType, 0, current_logfile_datename); + for (i = 0;;i++) + { + char tmp[MAX_SIZE]; + MakeLogFileName(log_object, tmp, sizeof(tmp), + log_object->DirName, log_object->Prefix, rec->Tick, log_object->SwitchType, i, current_logfile_datename); + + if (IsFileExists(tmp) == false) + { + break; + } + StrCpy(file_name, sizeof(file_name), tmp); + log_object->CurrentLogNumber = i; + } + } + } + UnlockLog(log_object); + + if (*io != NULL) + { + if (StrCmp(current_file_name, file_name) != 0) + { + // If a log file is currently opened and writing to another log + // file is needed for this time, write the contents of the + //buffer and close the log file. Write the contents of the buffer + if (*io != NULL) + { + if (*log_date_changed) + { + if ((log_object->CurrentFilePointer + (UINT64)buffer->Size) <= GetMaxLogSize()) + { + if (FileWrite(*io, buffer->Buf, buffer->Size) == false) + { + FileCloseEx(*io, true); + ClearBuf(buffer); + *io = NULL; + } + else + { + log_object->CurrentFilePointer += (UINT64)buffer->Size; + ClearBuf(buffer); + } + } + } + // Close the file + FileCloseEx(*io, true); + } + + log_object->log_number_incremented = false; + + // Open or create a new log file + StrCpy(current_file_name, sizeof(current_file_name), file_name); + *io = FileOpen(file_name, true); + if (*io == NULL) + { + // Create a log file + LockLog(log_object); + { + MakeDir(log_object->DirName); + +#ifdef OS_WIN32 + Win32SetFolderCompress(log_object->DirName, true); +#endif // OS_WIN32 + } + UnlockLog(log_object); + *io = FileCreate(file_name); + log_object->CurrentFilePointer = 0; + } + else + { + // Seek to the end of the log file + log_object->CurrentFilePointer = FileSize64(*io); + FileSeek(*io, SEEK_END, 0); + } + } + } + else + { + // Open or create a new log file + StrCpy(current_file_name, sizeof(current_file_name), file_name); + *io = FileOpen(file_name, true); + if (*io == NULL) + { + // Create a log file + LockLog(log_object); + { + MakeDir(log_object->DirName); +#ifdef OS_WIN32 + Win32SetFolderCompress(log_object->DirName, true); +#endif // OS_WIN32 + } + UnlockLog(log_object); + *io = FileCreate(file_name); + log_object->CurrentFilePointer = 0; + if (*io == NULL) + { + //Debug("Logging.c: SleepThread(30);\n"); + SleepThread(30); + } + } + else + { + // Seek to the end of the log file + log_object->CurrentFilePointer = FileSize64(*io); + FileSeek(*io, SEEK_END, 0); + } + + log_object->log_number_incremented = false; + } + + // Write the contents of the log to the buffer + WriteRecordToBuffer(buffer, rec); + + // Release the memory of record + Free(rec); + + return (*io != NULL); +} + +static bool LogThreadWriteStdout(LOG *log_object, BUF *buffer, IO *io) +{ + RECORD *rec; + + // Retrieve a record from the head of the queue + LockQueue(log_object->RecordQueue); + { + rec = GetNext(log_object->RecordQueue); + } + UnlockQueue(log_object->RecordQueue); + + if (rec == NULL) + { + Set(log_object->FlushEvent); + return false; + } + + ClearBuf(buffer); + WriteRecordToBuffer(buffer, rec); + if (!FileWrite(io, buffer->Buf, buffer->Size)) + { + ClearBuf(buffer); + } + Free(rec); + + return true; +} + +static IO *GetIO4Stdout() +{ +#ifndef UNIX + return NULL; +#else // UNIX + static IO IO4Stdout = + { + .Name = {0}, + .NameW = {0}, + .pData = NULL, + .WriteMode = true, + .HamMode = false, + .HamBuf = NULL, + }; + + if (!g_foreground) + { + return NULL; + } + + IO4Stdout.pData = GetUnixio4Stdout(); + + return &IO4Stdout; +#endif // UNIX +} + // Write the contents of the log to the buffer void WriteRecordToBuffer(BUF *b, RECORD *r) { diff --git a/src/Mayaqua/Mayaqua.c b/src/Mayaqua/Mayaqua.c index 23520915..cec007cc 100644 --- a/src/Mayaqua/Mayaqua.c +++ b/src/Mayaqua/Mayaqua.c @@ -133,6 +133,7 @@ BOOL kernel_status_inited = false; // Kernel state initialization flag bool g_little_endian = true; char *cmdline = NULL; // Command line wchar_t *uni_cmdline = NULL; // Unicode command line +bool g_foreground = false; // Execute service in foreground mode // Static variable static char *exename = NULL; // EXE file name (ANSI) @@ -512,6 +513,7 @@ void InitMayaqua(bool memcheck, bool debug, int argc, char **argv) // Fail this for some reason when this is called this in .NET mode setbuf(stdout, NULL); } + g_foreground = (argc >= 3 && StrCmpi(argv[2], UNIX_SVC_ARG_FOREGROUND) == 0); // Acquisition whether NT #ifdef OS_WIN32 diff --git a/src/Mayaqua/Mayaqua.h b/src/Mayaqua/Mayaqua.h index 99656d8e..c4ba1db7 100644 --- a/src/Mayaqua/Mayaqua.h +++ b/src/Mayaqua/Mayaqua.h @@ -395,6 +395,7 @@ extern char *cmdline; extern wchar_t *uni_cmdline; extern bool g_little_endian; extern LOCK *tick_manual_lock; +extern bool g_foreground; // Kernel state #define NUM_KERNEL_STATUS 128 diff --git a/src/Mayaqua/Unix.c b/src/Mayaqua/Unix.c index 435021bd..73a999ed 100755 --- a/src/Mayaqua/Unix.c +++ b/src/Mayaqua/Unix.c @@ -1703,6 +1703,23 @@ void *UnixFileOpen(char *name, bool write_mode, bool read_lock) return (void *)p; } +// Get UNIXIO object for stdout +void* GetUnixio4Stdout() +{ + static UNIXIO unixio = + { + .fd = -1, + .write_mode = true + }; + + if (g_foreground) + { + unixio.fd = STDOUT_FILENO; + return &unixio; + } + return NULL; +} + // Return the current thread ID UINT UnixThreadId() { diff --git a/src/Mayaqua/Unix.h b/src/Mayaqua/Unix.h index 652aef4b..ed6d719e 100644 --- a/src/Mayaqua/Unix.h +++ b/src/Mayaqua/Unix.h @@ -179,6 +179,7 @@ void *UnixFileOpen(char *name, bool write_mode, bool read_lock); void *UnixFileOpenW(wchar_t *name, bool write_mode, bool read_lock); void *UnixFileCreate(char *name); void *UnixFileCreateW(wchar_t *name); +void *GetUnixio4Stdout(); bool UnixFileWrite(void *pData, void *buf, UINT size); bool UnixFileRead(void *pData, void *buf, UINT size); void UnixFileClose(void *pData, bool no_flush);