| 1 | // Copyright (C) Microsoft Corporation. All rights reserved. |
| 2 | #include "precomp.h" |
| 3 | #include "p9defs.h" |
| 4 | #include "p9tracelogging.h" |
| 5 | #include "p9tracelogginghelper.h" |
| 6 | |
| 7 | namespace { |
| 8 | |
| 9 | const char* c_levelLabels[] = {": CRITICAL: ", ": ERROR: ", ": WARNING: ", ": INFO: ", ": VERBOSE: "}; |
| 10 | |
| 11 | constexpr int c_levelLabelLength = 12; |
| 12 | |
| 13 | } // namespace |
| 14 | |
| 15 | namespace p9fs { |
| 16 | |
| 17 | int Plan9TraceLoggingProvider::m_level{TRACE_LEVEL_ERROR}; |
| 18 | int Plan9TraceLoggingProvider::m_log{-1}; |
| 19 | |
| 20 | constexpr int c_numberBufferSize = 64; |
| 21 | |
| 22 | // Helper to convert unsigned numbers without the use of printf or iostream. |
| 23 | std::string_view ConvertNumber(char* buffer, int bufferSize, UINT64 value, int base = 10, int minWidth = 0) |
| 24 | { |
| 25 | if (value == 0) |
| 26 | { |
| 27 | return "0"; |
| 28 | } |
| 29 | |
| 30 | auto* characters = "0123456789abcdef"; |
| 31 | int index; |
| 32 | for (index = bufferSize - 1; index > 0 && value > 0; --index, value /= base) |
| 33 | { |
| 34 | buffer[index] = characters[value % base]; |
| 35 | } |
| 36 | |
| 37 | for (; index > 0 && c_numberBufferSize - (index + 1) < minWidth; --index) |
| 38 | { |
| 39 | buffer[index] = '0'; |
| 40 | } |
| 41 | |
| 42 | if (base == 16 && index > 1) |
| 43 | { |
| 44 | buffer[index--] = 'x'; |
| 45 | buffer[index--] = '0'; |
| 46 | } |
| 47 | |
| 48 | index += 1; |
| 49 | return {&buffer[index], c_numberBufferSize - index}; |
| 50 | } |
| 51 | |
| 52 | // Sets the file descriptor to log to. |
| 53 | void Plan9TraceLoggingProvider::SetLogFileDescriptor(int fd) |
| 54 | { |
| 55 | m_log = fd; |
| 56 | } |
| 57 | |
| 58 | // Checks whether logging is enabled for messages of the specified level. |
| 59 | bool Plan9TraceLoggingProvider::IsEnabled(int level) |
| 60 | { |
| 61 | return m_log >= 0 && level <= m_level; |
| 62 | } |
| 63 | |
| 64 | // Sets the current logging level. |
| 65 | void Plan9TraceLoggingProvider::SetLevel(int level) |
| 66 | { |
| 67 | m_level = level; |
| 68 | } |
| 69 | |
| 70 | // Logs a message at the specified level. |
| 71 | void Plan9TraceLoggingProvider::LogMessage(const char* message, int level) |
| 72 | { |
| 73 | if (!IsEnabled(level)) |
| 74 | { |
| 75 | return; |
| 76 | } |
| 77 | |
| 78 | timespec timestamp; |
| 79 | clock_gettime(CLOCK_MONOTONIC, ×tamp); |
| 80 | char secondsBuffer[c_numberBufferSize]; |
| 81 | auto seconds = ConvertNumber(secondsBuffer, c_numberBufferSize, timestamp.tv_sec); |
| 82 | char nsecondsBuffer[c_numberBufferSize]; |
| 83 | auto nseconds = ConvertNumber(nsecondsBuffer, c_numberBufferSize, timestamp.tv_nsec, 10, 9); |
| 84 | if (level < 1) |
| 85 | { |
| 86 | level = 1; |
| 87 | } |
| 88 | else if (level > TRACE_LEVEL_VERBOSE) |
| 89 | { |
| 90 | level = TRACE_LEVEL_VERBOSE; |
| 91 | } |
| 92 | |
| 93 | // Use writev to ensure the message is written atomically with all its parts. |
| 94 | iovec buffers[6]; |
| 95 | buffers[0].iov_base = const_cast<char*>(seconds.data()); |
| 96 | buffers[0].iov_len = seconds.size(); |
| 97 | buffers[1].iov_base = const_cast<char*>("."); |
| 98 | buffers[1].iov_len = 1; |
| 99 | buffers[2].iov_base = const_cast<char*>(nseconds.data()); |
| 100 | buffers[2].iov_len = nseconds.size(); |
| 101 | buffers[3].iov_base = const_cast<char*>(c_levelLabels[level - 1]); |
| 102 | buffers[3].iov_len = c_levelLabelLength; |
| 103 | buffers[4].iov_base = const_cast<char*>(message); |
| 104 | buffers[4].iov_len = strlen(message); |
| 105 | buffers[5].iov_base = const_cast<char*>("\n"); |
| 106 | buffers[5].iov_len = 1; |
| 107 | writev(m_log, buffers, std::extent<decltype(buffers)>::value); |
| 108 | } |
| 109 | |
| 110 | // Logs a message at the specified level. |
| 111 | void Plan9TraceLoggingProvider::LogMessage(const std::string& message, int level) |
| 112 | { |
| 113 | LogMessage(message.c_str(), level); |
| 114 | } |
| 115 | |
| 116 | // Logs an exception with an optional additional message to the output. |
| 117 | void Plan9TraceLoggingProvider::LogException(const char* message, const char* exceptionDescription, int level) |
| 118 | { |
| 119 | if (!IsEnabled(level)) |
| 120 | { |
| 121 | return; |
| 122 | } |
| 123 | |
| 124 | std::string logMessage; |
| 125 | if (message != nullptr) |
| 126 | { |
| 127 | logMessage += message; |
| 128 | if (exceptionDescription != nullptr) |
| 129 | { |
| 130 | logMessage += " "; |
| 131 | } |
| 132 | } |
| 133 | |
| 134 | if (exceptionDescription != nullptr) |
| 135 | { |
| 136 | logMessage += "Exception: "; |
| 137 | logMessage += exceptionDescription; |
| 138 | } |
| 139 | |
| 140 | LogMessage(logMessage.c_str(), level); |
| 141 | } |
| 142 | |
| 143 | // Logs a message that the server has started. |
| 144 | void Plan9TraceLoggingProvider::ServerStart() |
| 145 | { |
| 146 | LogMessage("Server started.", TRACE_LEVEL_INFORMATION); |
| 147 | } |
| 148 | |
| 149 | // Logs a message that the server has stopped. |
| 150 | void Plan9TraceLoggingProvider::ServerStop() |
| 151 | { |
| 152 | LogMessage("Server stopped.", TRACE_LEVEL_INFORMATION); |
| 153 | } |
| 154 | |
| 155 | // Logs a message that the server has accepted a connection. |
| 156 | void Plan9TraceLoggingProvider::AcceptedConnection() |
| 157 | { |
| 158 | LogMessage("Accepted connection.", TRACE_LEVEL_INFORMATION); |
| 159 | } |
| 160 | |
| 161 | // Logs a message that a connection was disconnected. |
| 162 | void Plan9TraceLoggingProvider::ConnectionDisconnected() |
| 163 | { |
| 164 | LogMessage("Connection disconnected.", TRACE_LEVEL_INFORMATION); |
| 165 | } |
| 166 | |
| 167 | // Logs a message that the server has rejected a connection attempt because there are too many |
| 168 | // active connections. |
| 169 | void Plan9TraceLoggingProvider::TooManyConnections() |
| 170 | { |
| 171 | LogMessage("Too many connections.", TRACE_LEVEL_ERROR); |
| 172 | } |
| 173 | |
| 174 | // Logs a message indicating that the buffer provided by the virtio transport for the response is |
| 175 | // too small. |
| 176 | void Plan9TraceLoggingProvider::InvalidResponseBufferSize() |
| 177 | { |
| 178 | LogMessage("Invalid response buffer size.", TRACE_LEVEL_ERROR); |
| 179 | } |
| 180 | |
| 181 | // A socket has been accepted |
| 182 | void Plan9TraceLoggingProvider::PreAccept() |
| 183 | { |
| 184 | LogMessage("PreAccept", TRACE_LEVEL_VERBOSE); |
| 185 | } |
| 186 | |
| 187 | // A socket has been closed |
| 188 | void Plan9TraceLoggingProvider::PostAccept() |
| 189 | { |
| 190 | LogMessage("PostAccept", TRACE_LEVEL_INFORMATION); |
| 191 | } |
| 192 | |
| 193 | // An accept operation has been aborted |
| 194 | void Plan9TraceLoggingProvider::OperationAborted() |
| 195 | { |
| 196 | LogMessage("OperationAborted", TRACE_LEVEL_VERBOSE); |
| 197 | } |
| 198 | |
| 199 | // A client connected |
| 200 | void Plan9TraceLoggingProvider::ClientConnected(unsigned int connectionCount) |
| 201 | { |
| 202 | LogMessage(std::format("ClientConnected, connectionCount={}", connectionCount), TRACE_LEVEL_VERBOSE); |
| 203 | } |
| 204 | |
| 205 | // A client disconnected |
| 206 | void Plan9TraceLoggingProvider::ClientDisconnected(unsigned int connectionCount) |
| 207 | { |
| 208 | LogMessage(std::format("ClientDisconnected, connectionCount={}", connectionCount), TRACE_LEVEL_VERBOSE); |
| 209 | } |
| 210 | |
| 211 | // Adds the message name to the log message. |
| 212 | // N.B. This should be the first call on a new LogMessageBuilder. |
| 213 | void LogMessageBuilder::AddName(std::string_view name) |
| 214 | { |
| 215 | m_message += name; |
| 216 | } |
| 217 | |
| 218 | // Adds a string field to the message. |
| 219 | void LogMessageBuilder::AddField(std::string_view name, std::string_view value) |
| 220 | { |
| 221 | AddFieldName(name); |
| 222 | AddRawValue(value); |
| 223 | } |
| 224 | |
| 225 | // Adds an unsigned integer field to the message. |
| 226 | void LogMessageBuilder::AddField(std::string_view name, UINT64 value, int base) |
| 227 | { |
| 228 | AddFieldName(name); |
| 229 | AddRawValue(value, base); |
| 230 | } |
| 231 | |
| 232 | // Adds a qid field to the message. |
| 233 | void LogMessageBuilder::AddField(std::string_view name, const Qid& value) |
| 234 | { |
| 235 | AddFieldName(name); |
| 236 | AddRawValue(value); |
| 237 | } |
| 238 | |
| 239 | // Adds a string value to the message. |
| 240 | void LogMessageBuilder::AddValue(std::string_view value) |
| 241 | { |
| 242 | m_message += " "; |
| 243 | AddRawValue(value); |
| 244 | } |
| 245 | |
| 246 | // Adds a qid value to the message. |
| 247 | void LogMessageBuilder::AddValue(const Qid& value) |
| 248 | { |
| 249 | m_message += " "; |
| 250 | AddRawValue(value); |
| 251 | } |
| 252 | |
| 253 | // Returns the message text as a string. |
| 254 | const char* LogMessageBuilder::String() const |
| 255 | { |
| 256 | return m_message.c_str(); |
| 257 | } |
| 258 | |
| 259 | // Adds the name of the field, including separators. |
| 260 | void LogMessageBuilder::AddFieldName(std::string_view name) |
| 261 | { |
| 262 | m_message += " "; |
| 263 | m_message += name; |
| 264 | m_message += "="; |
| 265 | } |
| 266 | |
| 267 | // Adds an unsigned integer value without any separators or prefix. |
| 268 | void LogMessageBuilder::AddRawValue(UINT64 value, int base) |
| 269 | { |
| 270 | char buffer[c_numberBufferSize]{}; |
| 271 | m_message += ConvertNumber(buffer, c_numberBufferSize, value, base); |
| 272 | } |
| 273 | |
| 274 | // Adds a qid value without any separators or prefix. |
| 275 | void LogMessageBuilder::AddRawValue(const Qid& value) |
| 276 | { |
| 277 | m_message += "{"; |
| 278 | AddRawValue(static_cast<UINT32>(value.Type), 16); |
| 279 | m_message += ","; |
| 280 | AddRawValue(value.Version); |
| 281 | m_message += ","; |
| 282 | AddRawValue(value.Path); |
| 283 | m_message += "}"; |
| 284 | } |
| 285 | |
| 286 | // Adds a string value without any separators of prefix. |
| 287 | // N.B. This function does adds quotes surrounding the string. |
| 288 | void LogMessageBuilder::AddRawValue(std::string_view value) |
| 289 | { |
| 290 | m_message += "\""; |
| 291 | m_message.append(value.data(), value.size()); |
| 292 | m_message += "\""; |
| 293 | } |
| 294 | |
| 295 | } // namespace p9fs |