| 1 | /*++ |
| 2 | |
| 3 | Copyright (c) Microsoft. All rights reserved. |
| 4 | |
| 5 | Module Name: |
| 6 | |
| 7 | lxtlog.c |
| 8 | |
| 9 | Abstract: |
| 10 | |
| 11 | This file contains lx test logging routines. |
| 12 | |
| 13 | --*/ |
| 14 | |
| 15 | #include <stdio.h> |
| 16 | #include <stdarg.h> |
| 17 | #include <unistd.h> |
| 18 | #include <string.h> |
| 19 | #include <time.h> |
| 20 | #include <fcntl.h> |
| 21 | #include "lxtutil.h" |
| 22 | #include "lxtlog.h" |
| 23 | |
| 24 | #define LXT_LOG_TIMESTAMP_BUFFER_SIZE 64 |
| 25 | |
| 26 | static LxtLogType g_LxtLogTypeMask = LXT_LOG_TYPE_DEFAULT_MASK; |
| 27 | static const char* g_LxtTestName = ""; |
| 28 | static char g_LXTestLogFileName[64] = "/data/test/log/"; |
| 29 | static FILE* g_LxtFile = NULL; |
| 30 | |
| 31 | void LxtLog(LxtLogLevel LogLevel, const char* Message, ...) |
| 32 | |
| 33 | /*++ |
| 34 | --*/ |
| 35 | |
| 36 | { |
| 37 | |
| 38 | static volatile int Active = 0; |
| 39 | va_list Args; |
| 40 | char TimeFormat[LXT_LOG_TIMESTAMP_BUFFER_SIZE]; |
| 41 | struct tm* TimeInfo; |
| 42 | static struct timespec TimeSpec; |
| 43 | char TimeStamp[LXT_LOG_TIMESTAMP_BUFFER_SIZE]; |
| 44 | |
| 45 | if ((LogLevel == LxtLogLevelResourceError) && ((g_LxtLogTypeMask & LxtLogTypeStress) != 0)) |
| 46 | { |
| 47 | |
| 48 | goto Exit; |
| 49 | } |
| 50 | |
| 51 | // |
| 52 | // Create a timestamp string which will precede the provided log message. |
| 53 | // The format of the string is: [Hours:Minutes:Seconds.Milliseconds] |
| 54 | // |
| 55 | // N.B. The returns of strftime and snprintf are not checked because the |
| 56 | // provided buffers are large enough for the format strings. |
| 57 | // |
| 58 | |
| 59 | LxtClockGetTime(CLOCK_REALTIME, &TimeSpec); |
| 60 | |
| 61 | // |
| 62 | // N.B. The signal handling code may use this function and not all of the |
| 63 | // functions used here are reentrant safe, resulting in possible |
| 64 | // deadlocks or crashes. To avoid these keep an active count and skip |
| 65 | // functions known to be problematic in the signal case. The functions |
| 66 | // identified at this point are: |
| 67 | // - fflush |
| 68 | // - localtime |
| 69 | // - strftime |
| 70 | // |
| 71 | |
| 72 | if (__sync_add_and_fetch(&Active, 1) == 1) |
| 73 | { |
| 74 | TimeInfo = localtime(&TimeSpec.tv_sec); |
| 75 | strftime(TimeFormat, sizeof(TimeFormat), "[%H:%M:%S", TimeInfo); |
| 76 | } |
| 77 | |
| 78 | snprintf(TimeStamp, sizeof(TimeStamp), "%s.%03u] ", TimeFormat, (unsigned int)TimeSpec.tv_nsec / (1000 * 1000)); |
| 79 | |
| 80 | // |
| 81 | // Print the timestamp string followed by the provided message. |
| 82 | // |
| 83 | |
| 84 | if ((g_LxtLogTypeMask & LxtLogTypePrintf) != 0) |
| 85 | { |
| 86 | va_start(Args, Message); |
| 87 | printf("%s", TimeStamp); |
| 88 | vprintf(Message, Args); |
| 89 | va_end(Args); |
| 90 | } |
| 91 | |
| 92 | if (((g_LxtLogTypeMask & LxtLogTypeFile) != 0) && (g_LxtFile != NULL)) |
| 93 | { |
| 94 | va_start(Args, Message); |
| 95 | fprintf(g_LxtFile, "%s", TimeStamp); |
| 96 | vfprintf(g_LxtFile, Message, Args); |
| 97 | va_end(Args); |
| 98 | } |
| 99 | |
| 100 | if (__sync_sub_and_fetch(&Active, 1) == 0) |
| 101 | { |
| 102 | sigset_t PreviousSignals; |
| 103 | sigset_t SignalMask; |
| 104 | sigfillset(&SignalMask); |
| 105 | |
| 106 | int MaskResult = pthread_sigmask(SIG_BLOCK, &SignalMask, &PreviousSignals); |
| 107 | if (((g_LxtLogTypeMask & LxtLogTypeFile) != 0) && (g_LxtFile != NULL)) |
| 108 | { |
| 109 | fflush(g_LxtFile); |
| 110 | } |
| 111 | |
| 112 | if ((g_LxtLogTypeMask & LxtLogTypePrintf) != 0) |
| 113 | { |
| 114 | fflush(stdout); |
| 115 | } |
| 116 | |
| 117 | if (MaskResult == 0) |
| 118 | { |
| 119 | pthread_sigmask(SIG_SETMASK, &PreviousSignals, NULL); |
| 120 | } |
| 121 | } |
| 122 | |
| 123 | Exit: |
| 124 | return; |
| 125 | } |
| 126 | |
| 127 | int LxtLogInitialize(const char* TestName, LxtLogType LogTypeMask, bool LogAppend) |
| 128 | |
| 129 | /*++ |
| 130 | --*/ |
| 131 | |
| 132 | { |
| 133 | |
| 134 | char* Mode; |
| 135 | int Result; |
| 136 | |
| 137 | g_LxtTestName = TestName; |
| 138 | g_LxtLogTypeMask = LogTypeMask; |
| 139 | strcat(g_LXTestLogFileName, TestName); |
| 140 | if ((g_LxtLogTypeMask & LxtLogTypeFile) != 0) |
| 141 | { |
| 142 | Mode = "w"; |
| 143 | if (LogAppend != false) |
| 144 | { |
| 145 | Mode = "a"; |
| 146 | } |
| 147 | |
| 148 | g_LxtFile = fopen(g_LXTestLogFileName, Mode); |
| 149 | if (g_LxtFile == NULL) |
| 150 | { |
| 151 | Result = LXT_RESULT_FAILURE; |
| 152 | g_LxtLogTypeMask &= ~LxtLogTypeFile; |
| 153 | LxtLogError("Failed to open %s: %s", g_LXTestLogFileName, strerror(errno)); |
| 154 | |
| 155 | goto ErrorExit; |
| 156 | } |
| 157 | } |
| 158 | |
| 159 | Result = LXT_RESULT_SUCCESS; |
| 160 | |
| 161 | ErrorExit: |
| 162 | return Result; |
| 163 | } |
| 164 | |
| 165 | void LxtLogUninitialize(void) |
| 166 | |
| 167 | /*++ |
| 168 | --*/ |
| 169 | |
| 170 | { |
| 171 | |
| 172 | // |
| 173 | // Close and flush the log file. This ensures that the file contents are |
| 174 | // able to be read from Windows. |
| 175 | // |
| 176 | |
| 177 | if (g_LxtFile != NULL) |
| 178 | { |
| 179 | fflush(g_LxtFile); |
| 180 | fsync(fileno(g_LxtFile)); |
| 181 | fclose(g_LxtFile); |
| 182 | g_LxtFile = NULL; |
| 183 | } |
| 184 | |
| 185 | return; |
| 186 | } |