From 5716e3fb50eea8d4b90c5f9873d537cea26b2f46 Mon Sep 17 00:00:00 2001 From: "Jason A. Donenfeld" Date: Sun, 17 Mar 2019 00:41:10 -0600 Subject: [PATCH] ringlogger: support mpsc for singlefile --- WireGuard/Shared/FileManager+Extension.swift | 10 +- WireGuard/Shared/Logging/Logger.swift | 18 ++- WireGuard/Shared/Logging/ringlogger.c | 129 +++++++++++------- WireGuard/Shared/Logging/ringlogger.h | 7 +- WireGuard/Shared/Logging/test_ringlogger.c | 63 +++++++++ .../WireGuard/Base.lproj/Localizable.strings | 3 - WireGuard/WireGuard/UI/iOS/AppDelegate.swift | 2 +- .../SettingsTableViewController.swift | 7 +- .../WireGuard/UI/macOS/AppDelegate.swift | 2 +- .../TunnelsListTableViewController.swift | 7 +- .../PacketTunnelProvider.swift | 2 +- 11 files changed, 158 insertions(+), 92 deletions(-) create mode 100644 WireGuard/Shared/Logging/test_ringlogger.c diff --git a/WireGuard/Shared/FileManager+Extension.swift b/WireGuard/Shared/FileManager+Extension.swift index edd764f..d52ec0b 100644 --- a/WireGuard/Shared/FileManager+Extension.swift +++ b/WireGuard/Shared/FileManager+Extension.swift @@ -27,7 +27,7 @@ extension FileManager { return sharedFolderURL } - static var networkExtensionLogFileURL: URL? { + static var logFileURL: URL? { return sharedFolderURL?.appendingPathComponent("tunnel-log.bin") } @@ -35,14 +35,6 @@ extension FileManager { return sharedFolderURL?.appendingPathComponent("last-error.txt") } - static var appLogFileURL: URL? { - guard let documentDirURL = FileManager.default.urls(for: .cachesDirectory, in: .userDomainMask).first else { - wg_log(.error, message: "Cannot obtain app documents folder URL") - return nil - } - return documentDirURL.appendingPathComponent("app-log.bin") - } - static func deleteFile(at url: URL) -> Bool { do { try FileManager.default.removeItem(at: url) diff --git a/WireGuard/Shared/Logging/Logger.swift b/WireGuard/Shared/Logging/Logger.swift index 23cc719..345fc10 100644 --- a/WireGuard/Shared/Logging/Logger.swift +++ b/WireGuard/Shared/Logging/Logger.swift @@ -12,10 +12,12 @@ public class Logger { static var global: Logger? var log: OpaquePointer + var tag: String - init(withFilePath filePath: String) throws { + init(tagged tag: String, withFilePath filePath: String) throws { guard let log = open_log(filePath) else { throw LoggerError.openFailure } self.log = log + self.tag = tag } deinit { @@ -23,17 +25,14 @@ public class Logger { } func log(message: String) { - write_msg_to_log(log, message.trimmingCharacters(in: .newlines)) + write_msg_to_log(log, tag, message.trimmingCharacters(in: .newlines)) } - func writeLog(called ourTag: String, mergedWith otherLogFile: String, called otherTag: String, to targetFile: String) -> Bool { - guard let other = open_log(otherLogFile) else { return false } - let ret = write_logs_to_file(targetFile, log, ourTag, other, otherTag) - close_log(other) - return ret == 0 + func writeLog(to targetFile: String) -> Bool { + return write_log_to_file(targetFile, self.log) == 0 } - static func configureGlobal(withFilePath filePath: String?) { + static func configureGlobal(tagged tag: String, withFilePath filePath: String?) { if Logger.global != nil { return } @@ -41,7 +40,7 @@ public class Logger { os_log("Unable to determine log destination path. Log will not be saved to file.", log: OSLog.default, type: .error) return } - guard let logger = try? Logger(withFilePath: filePath) else { + guard let logger = try? Logger(tagged: tag, withFilePath: filePath) else { os_log("Unable to open log file for writing. Log will not be saved to file.", log: OSLog.default, type: .error) return } @@ -52,7 +51,6 @@ public class Logger { } let goBackendVersion = WIREGUARD_GO_VERSION Logger.global?.log(message: "App version: \(appVersion); Go backend version: \(goBackendVersion)") - } } diff --git a/WireGuard/Shared/Logging/ringlogger.c b/WireGuard/Shared/Logging/ringlogger.c index fcdc19d..440a269 100644 --- a/WireGuard/Shared/Logging/ringlogger.c +++ b/WireGuard/Shared/Logging/ringlogger.c @@ -6,6 +6,8 @@ #include #include #include +#include +#include #include #include #include @@ -19,100 +21,121 @@ enum { MAX_LOG_LINE_LENGTH = 512, - MAX_LINES = 1024, - MAGIC = 0xbeefbabeU + MAX_LINES = 2048, + MAGIC = 0xabadbeefU }; struct log_line { - struct timeval tv; + atomic_uint_fast64_t time_ns; char line[MAX_LOG_LINE_LENGTH]; }; struct log { - struct { uint32_t first, len; } header; + atomic_uint_fast32_t next_index; struct log_line lines[MAX_LINES]; uint32_t magic; }; -void write_msg_to_log(struct log *log, const char *msg) +void write_msg_to_log(struct log *log, const char *tag, const char *msg) { - struct log_line *line = &log->lines[(log->header.first + log->header.len) % MAX_LINES]; + uint32_t index; + struct log_line *line; + struct timespec ts; - if (log->header.len == MAX_LINES) - log->header.first = (log->header.first + 1) % MAX_LINES; - else - ++log->header.len; + clock_gettime(CLOCK_REALTIME, &ts); - gettimeofday(&line->tv, NULL); - strncpy(line->line, msg, MAX_LOG_LINE_LENGTH - 1); - line->line[MAX_LOG_LINE_LENGTH - 1] = '\0'; + index = atomic_fetch_add(&log->next_index, 1); + line = &log->lines[index % MAX_LINES]; - msync(&log->header, sizeof(log->header), MS_ASYNC); + atomic_store(&line->time_ns, 0); + memset(line->line, 0, MAX_LOG_LINE_LENGTH); + + snprintf(line->line, MAX_LOG_LINE_LENGTH, "[%s] %s", tag, msg); + atomic_store(&line->time_ns, ts.tv_sec * 1000000000ULL + ts.tv_nsec); + + msync(&log->next_index, sizeof(log->next_index), MS_ASYNC); msync(line, sizeof(*line), MS_ASYNC); } -static bool first_before_second(const struct log_line *line1, const struct log_line *line2) +int write_log_to_file(const char *file_name, const struct log *input_log) { - if (line1->tv.tv_sec <= line2->tv.tv_sec) - return true; - if (line1->tv.tv_sec == line2->tv.tv_sec) - return line1->tv.tv_usec <= line2->tv.tv_usec; - return false; -} - -int write_logs_to_file(const char *file_name, const struct log *log1, const char *tag1, const struct log *log2, const char *tag2) -{ - uint32_t i1, i2, len1 = log1->header.len, len2 = log2->header.len; + struct log *log; + uint32_t l, i; FILE *file; int ret; - if (len1 > MAX_LINES) - len1 = MAX_LINES; - if (len2 > MAX_LINES) - len2 = MAX_LINES; + log = malloc(sizeof(*log)); + if (!log) + return -errno; + memcpy(log, input_log, sizeof(*log)); file = fopen(file_name, "w"); - if (!file) + if (!file) { + free(log); return -errno; + } - for (i1 = 0, i2 = 0;;) { + for (l = 0, i = log->next_index; l < MAX_LINES; ++l, ++i) { + const struct log_line *line = &log->lines[i % MAX_LINES]; + time_t seconds = line->time_ns / 1000000000ULL; + uint32_t useconds = (line->time_ns % 1000000000ULL) / 1000ULL; struct tm tm; - char buf[MAX_LOG_LINE_LENGTH]; - const struct log_line *line1 = &log1->lines[(log1->header.first + i1) % MAX_LINES]; - const struct log_line *line2 = &log2->lines[(log2->header.first + i2) % MAX_LINES]; - const struct log_line *line; - const char *tag; - if (i1 < len1 && (i2 >= len2 || first_before_second(line1, line2))) { - line = line1; - tag = tag1; - ++i1; - } else if (i2 < len2 && (i1 >= len1 || first_before_second(line2, line1))) { - line = line2; - tag = tag2; - ++i2; - } else { - break; - } + if (!line->time_ns) + continue; - memcpy(buf, line->line, MAX_LOG_LINE_LENGTH); - buf[MAX_LOG_LINE_LENGTH - 1] = '\0'; - if (!localtime_r(&line->tv.tv_sec, &tm)) + if (!localtime_r(&seconds, &tm)) goto err; - if (fprintf(file, "%04d-%02d-%02d %02d:%02d:%02d.%06d: [%s] %s\n", + + if (fprintf(file, "%04d-%02d-%02d %02d:%02d:%02d.%06d: %s\n", tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, - tm.tm_hour, tm.tm_min, tm.tm_sec, line->tv.tv_usec, - tag, buf) < 0) + tm.tm_hour, tm.tm_min, tm.tm_sec, useconds, + line->line) < 0) goto err; + + } errno = 0; err: ret = -errno; fclose(file); + free(log); return ret; } +uint32_t view_lines_from_cursor(const struct log *input_log, uint32_t cursor, void(*cb)(const char *, uint64_t)) +{ + struct log *log; + uint32_t l, i = cursor; + + log = malloc(sizeof(*log)); + if (!log) + return cursor; + memcpy(log, input_log, sizeof(*log)); + + if (i == -1) + i = log->next_index; + + for (l = 0; l < MAX_LINES; ++l, ++i) { + const struct log_line *line = &log->lines[i % MAX_LINES]; + + if (cursor != -1 && i % MAX_LINES == log->next_index % MAX_LINES) + break; + + if (!line->time_ns) { + if (cursor == -1) + continue; + else + break; + } + cb(line->line, line->time_ns); + cursor = (i + 1) % MAX_LINES; + } + free(log); + return cursor; +} + struct log *open_log(const char *file_name) { int fd; diff --git a/WireGuard/Shared/Logging/ringlogger.h b/WireGuard/Shared/Logging/ringlogger.h index 0ee202d..7f5b074 100644 --- a/WireGuard/Shared/Logging/ringlogger.h +++ b/WireGuard/Shared/Logging/ringlogger.h @@ -6,9 +6,12 @@ #ifndef RINGLOGGER_H #define RINGLOGGER_H +#include + struct log; -void write_msg_to_log(struct log *log, const char *msg); -int write_logs_to_file(const char *file_name, const struct log *log1, const char *tag1, const struct log *log2, const char *tag2); +void write_msg_to_log(struct log *log, const char *tag, const char *msg); +int write_log_to_file(const char *file_name, const struct log *input_log); +uint32_t view_lines_from_cursor(const struct log *input_log, uint32_t cursor, void(*)(const char *, uint64_t)); struct log *open_log(const char *file_name); void close_log(struct log *log); diff --git a/WireGuard/Shared/Logging/test_ringlogger.c b/WireGuard/Shared/Logging/test_ringlogger.c new file mode 100644 index 0000000..ae3f4a9 --- /dev/null +++ b/WireGuard/Shared/Logging/test_ringlogger.c @@ -0,0 +1,63 @@ +#include "ringlogger.h" +#include +#include +#include +#include +#include +#include + +static void forkwrite(void) +{ + struct log *log = open_log("/tmp/test_log"); + char c[512]; + int i, base; + bool in_fork = !fork(); + + base = 10000 * in_fork; + for (i = 0; i < 1024; ++i) { + snprintf(c, 512, "bla bla bla %d", base + i); + write_msg_to_log(log, "HMM", c); + } + + + if (in_fork) + _exit(0); + wait(NULL); + + write_log_to_file("/dev/stdout", log); + close_log(log); +} + +static void writetext(const char *text) +{ + struct log *log = open_log("/tmp/test_log"); + write_msg_to_log(log, "TXT", text); + close_log(log); +} + +static void show_line(const char *line, uint64_t time_ns) +{ + printf("%" PRIu64 ": %s\n", time_ns, line); +} + +static void follow(void) +{ + uint32_t cursor = -1; + struct log *log = open_log("/tmp/test_log"); + + for (;;) { + cursor = view_lines_from_cursor(log, cursor, show_line); + usleep(1000 * 300); + } +} + +int main(int argc, char *argv[]) +{ + if (!strcmp(argv[1], "fork")) + forkwrite(); + else if (!strcmp(argv[1], "write")) + writetext(argv[2]); + else if (!strcmp(argv[1], "follow")) + follow(); + return 0; +} diff --git a/WireGuard/WireGuard/Base.lproj/Localizable.strings b/WireGuard/WireGuard/Base.lproj/Localizable.strings index 55610aa..b42d40f 100644 --- a/WireGuard/WireGuard/Base.lproj/Localizable.strings +++ b/WireGuard/WireGuard/Base.lproj/Localizable.strings @@ -188,9 +188,6 @@ "alertUnableToRemovePreviousLogTitle" = "Log export failed"; "alertUnableToRemovePreviousLogMessage" = "The pre-existing log could not be cleared"; -"alertUnableToFindExtensionLogPathTitle" = "Log export failed"; -"alertUnableToFindExtensionLogPathMessage" = "Unable to determine extension log path"; - "alertUnableToWriteLogTitle" = "Log export failed"; "alertUnableToWriteLogMessage" = "Unable to write logs to file"; diff --git a/WireGuard/WireGuard/UI/iOS/AppDelegate.swift b/WireGuard/WireGuard/UI/iOS/AppDelegate.swift index 8743c70..d274280 100644 --- a/WireGuard/WireGuard/UI/iOS/AppDelegate.swift +++ b/WireGuard/WireGuard/UI/iOS/AppDelegate.swift @@ -11,7 +11,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate { var mainVC: MainViewController? func application(_ application: UIApplication, willFinishLaunchingWithOptions launchOptions: [UIApplication.LaunchOptionsKey: Any]?) -> Bool { - Logger.configureGlobal(withFilePath: FileManager.appLogFileURL?.path) + Logger.configureGlobal(tagged: "APP", withFilePath: FileManager.logFileURL?.path) let window = UIWindow(frame: UIScreen.main.bounds) window.backgroundColor = .white diff --git a/WireGuard/WireGuard/UI/iOS/ViewController/SettingsTableViewController.swift b/WireGuard/WireGuard/UI/iOS/ViewController/SettingsTableViewController.swift index 3addea4..ff83b2c 100644 --- a/WireGuard/WireGuard/UI/iOS/ViewController/SettingsTableViewController.swift +++ b/WireGuard/WireGuard/UI/iOS/ViewController/SettingsTableViewController.swift @@ -126,12 +126,7 @@ class SettingsTableViewController: UITableViewController { } } - guard let networkExtensionLogFilePath = FileManager.networkExtensionLogFileURL?.path else { - ErrorPresenter.showErrorAlert(title: tr("alertUnableToFindExtensionLogPathTitle"), message: tr("alertUnableToFindExtensionLogPathMessage"), from: self) - return - } - - let isWritten = Logger.global?.writeLog(called: "APP", mergedWith: networkExtensionLogFilePath, called: "NET", to: destinationURL.path) ?? false + let isWritten = Logger.global?.writeLog(to: destinationURL.path) ?? false DispatchQueue.main.async { guard isWritten else { diff --git a/WireGuard/WireGuard/UI/macOS/AppDelegate.swift b/WireGuard/WireGuard/UI/macOS/AppDelegate.swift index cbe6153..9f08e15 100644 --- a/WireGuard/WireGuard/UI/macOS/AppDelegate.swift +++ b/WireGuard/WireGuard/UI/macOS/AppDelegate.swift @@ -14,7 +14,7 @@ class AppDelegate: NSObject, NSApplicationDelegate { var manageTunnelsWindowObject: NSWindow? func applicationDidFinishLaunching(_ aNotification: Notification) { - Logger.configureGlobal(withFilePath: FileManager.appLogFileURL?.path) + Logger.configureGlobal(tagged: "APP", withFilePath: FileManager.logFileURL?.path) TunnelsManager.create { [weak self] result in guard let self = self else { return } diff --git a/WireGuard/WireGuard/UI/macOS/ViewController/TunnelsListTableViewController.swift b/WireGuard/WireGuard/UI/macOS/ViewController/TunnelsListTableViewController.swift index 7f2dbc8..8987f79 100644 --- a/WireGuard/WireGuard/UI/macOS/ViewController/TunnelsListTableViewController.swift +++ b/WireGuard/WireGuard/UI/macOS/ViewController/TunnelsListTableViewController.swift @@ -198,17 +198,12 @@ class TunnelsListTableViewController: NSViewController { let timeStampString = dateFormatter.string(from: Date()) savePanel.nameFieldStringValue = "wireguard-log-\(timeStampString).txt" - guard let networkExtensionLogFilePath = FileManager.networkExtensionLogFileURL?.path else { - ErrorPresenter.showErrorAlert(title: tr("alertUnableToFindExtensionLogPathTitle"), message: tr("alertUnableToFindExtensionLogPathMessage"), from: self) - return - } - savePanel.beginSheetModal(for: window) { response in guard response == .OK else { return } guard let destinationURL = savePanel.url else { return } DispatchQueue.global(qos: .userInitiated).async { - let isWritten = Logger.global?.writeLog(called: "APP", mergedWith: networkExtensionLogFilePath, called: "NET", to: destinationURL.path) ?? false + let isWritten = Logger.global?.writeLog(to: destinationURL.path) ?? false guard isWritten else { DispatchQueue.main.async { [weak self] in ErrorPresenter.showErrorAlert(title: tr("alertUnableToWriteLogTitle"), message: tr("alertUnableToWriteLogMessage"), from: self) diff --git a/WireGuard/WireGuardNetworkExtension/PacketTunnelProvider.swift b/WireGuard/WireGuardNetworkExtension/PacketTunnelProvider.swift index e33890d..c4fefd4 100644 --- a/WireGuard/WireGuardNetworkExtension/PacketTunnelProvider.swift +++ b/WireGuard/WireGuardNetworkExtension/PacketTunnelProvider.swift @@ -122,7 +122,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider { } private func configureLogger() { - Logger.configureGlobal(withFilePath: FileManager.networkExtensionLogFileURL?.path) + Logger.configureGlobal(tagged: "NET", withFilePath: FileManager.logFileURL?.path) wgSetLogger { level, msgC in guard let msgC = msgC else { return } let logType: OSLogType