diff --git a/LiteCore/Logging/LogDecoder.hh b/LiteCore/Logging/LogDecoder.hh index 478820e76..dcc888f1b 100644 --- a/LiteCore/Logging/LogDecoder.hh +++ b/LiteCore/Logging/LogDecoder.hh @@ -16,6 +16,7 @@ #include #include #include +#include #include #include @@ -31,6 +32,9 @@ namespace litecore { unsigned microsecs; }; + static constexpr Timestamp kMinTimestamp{0, 0}; + static constexpr Timestamp kMaxTimestamp{std::numeric_limits::max(), 999999}; + virtual ~LogIterator() = default; /** Decodes the entire log and writes it to the output stream, with timestamps. diff --git a/LiteCore/Logging/MultiLogDecoder.hh b/LiteCore/Logging/MultiLogDecoder.hh index eb2365a34..35ebf8d47 100644 --- a/LiteCore/Logging/MultiLogDecoder.hh +++ b/LiteCore/Logging/MultiLogDecoder.hh @@ -12,7 +12,9 @@ #pragma once #include "LogDecoder.hh" +#include "TextLogDecoder.hh" #include +#include #include #include #include @@ -27,22 +29,20 @@ namespace litecore { class MultiLogDecoder : public LogIterator { public: MultiLogDecoder() { - _startTime = {UINT_MAX, 0}; - for ( unsigned i = 0; i <= kMaxLevel; i++ ) _startTimeByLevel[i] = {UINT_MAX, 0}; + _startTime = kMaxTimestamp; + for ( unsigned i = 0; i <= kMaxLevel; i++ ) _startTimeByLevel[i] = kMaxTimestamp; } /// Adds a log iterator. Must be called before calling \ref next(). /// The iterator is assumed to be at its start, so its \ref next() will be called first. void add(LogIterator* log) { assert(!_current); - if ( !log->next() ) return; - - _logs.push(log); auto startTime = log->startTime(); _startTime = std::min(_startTime, startTime); - auto level = log->level(); - if ( level >= 0 && level <= kMaxLevel ) + if ( !log->next() ) return; + _logs.push(log); + if ( auto level = log->level(); level >= 0 && level <= kMaxLevel ) _startTimeByLevel[level] = std::min(_startTimeByLevel[level], startTime); } @@ -52,19 +52,28 @@ namespace litecore { if ( !in ) return false; in.exceptions(std::ifstream::badbit); _inputs.push_back(std::move(in)); - LogDecoder decoder(_inputs.back()); + std::unique_ptr decoder; + if ( TextLogDecoder::looksTextual(_inputs.back()) ) + decoder = std::make_unique(_inputs.back()); + else + decoder = std::make_unique(_inputs.back()); _decoders.push_back(std::move(decoder)); - add(&_decoders.back()); + add(_decoders.back().get()); return true; } /// Time when the earliest log began [[nodiscard]] Timestamp startTime() const override { return _startTime; } + /// Time that earliest logs at `level` begin, or kMaxTimestamp if none. + [[nodiscard]] Timestamp startTimeOfLevel(unsigned level) const { return _startTimeByLevel[level]; } + /// First time when logs of all levels are available [[nodiscard]] Timestamp fullStartTime() const { - Timestamp fullStartTime = {0, 0}; - for ( unsigned i = 0; i <= kMaxLevel; i++ ) fullStartTime = std::max(fullStartTime, _startTimeByLevel[i]); + Timestamp fullStartTime = kMinTimestamp; + for ( auto& ts : _startTimeByLevel ) { + if ( fullStartTime < ts && ts != kMaxTimestamp ) fullStartTime = ts; + } return fullStartTime; } @@ -116,10 +125,10 @@ namespace litecore { std::priority_queue, logcmp> _logs; LogIterator* _current{nullptr}; Timestamp _startTime{}; - Timestamp _startTimeByLevel[kMaxLevel + 1]{}; + std::array _startTimeByLevel{}; - std::deque _decoders; - std::deque _inputs; + std::vector> _decoders; + std::deque _inputs; }; diff --git a/LiteCore/Logging/TextLogDecoder.hh b/LiteCore/Logging/TextLogDecoder.hh new file mode 100644 index 000000000..c63558270 --- /dev/null +++ b/LiteCore/Logging/TextLogDecoder.hh @@ -0,0 +1,140 @@ +// +// TextLogDecoder.hh +// +// Copyright 2025-Present Couchbase, Inc. +// +// Use of this software is governed by the Business Source License included +// in the file licenses/BSL-Couchbase.txt. As of the Change Date specified +// in that file, in accordance with the Business Source License, use of this +// software will be governed by the Apache License, Version 2.0, included in +// the file licenses/APL2.txt. +// + +#pragma once +#include "LogDecoder.hh" +#include "ParseDate.hh" +#include +#include +#include + +namespace litecore { + + /** Parses LiteCore-generated textual log files. */ + class TextLogDecoder : public LogIterator { + public: + /** Returns true if the stream `in` appears to contain textual log data. */ + static bool looksTextual(std::istream& in) { + auto pos = in.tellg(); + char chars[27] = {}; + bool result = true; + in.read((char*)chars, sizeof(chars)); + in.seekg(pos); + return looksLikeLogLine(std::string_view(chars, std::size(chars))); + } + + /** Initializes decoder with a stream written by LiteCore's textual log encoder. */ + explicit TextLogDecoder(std::istream& in) : _in(in) { + _in.exceptions(std::istream::badbit); + if ( next() && next() ) // Read header line to get the initial timestamp + _startTime = _curTimestamp; + } + + bool next() override { + if ( _line.empty() ) { + // Read next line if there's not one in the buffer: + if ( !_in || _in.peek() < 0 ) return false; + std::getline(_in, _line); + if ( _line.empty() ) return false; + } + + // Example: 2025-12-09T06:47:55.507699Z WS Verbose Obj=/JRepl@1175308903/…/ Received 58-byte message + + std::string_view rest(_line); + auto nextColumn = [&] { + auto next = rest.find(' '); + std::string_view column = rest.substr(0, next); + rest = rest.substr(next + 1); + return column; + }; + + auto timestamp = nextColumn(); + auto micros = std::stoul(std::string(timestamp.substr(timestamp.size() - 7, 6))); + auto millis = fleece::ParseISO8601Date(timestamp); + if ( millis == kInvalidDate || millis < 0x19000000 || micros > 999999 ) + throw std::runtime_error("Could not parse timestamp in log line: " + _line); + _curTimestamp = {millis / 1000, unsigned(micros)}; + + _curDomain = nextColumn(); + + auto levelStr = nextColumn(); + if ( auto i = std::ranges::find(kLevelNames, levelStr); i != std::end(kLevelNames) ) + _curLevel = i - std::begin(kLevelNames); + else + _curLevel = 0; + + _curObject.clear(); + _curObjectID = 0; + if ( rest.starts_with("Obj=/") ) { + std::string_view obj = nextColumn(); + if ( auto size = obj.size(); size >= 13 && obj.ends_with('/') ) { + if ( auto pos = obj.rfind('#'); pos != std::string::npos ) { + _curObject = obj.substr(5, size - 6); // trim 'Obj=/' and '/ ' + _curObjectID = std::stoul(std::string(obj.substr(pos + 1, size - 2 - pos))); + } + } + } + + _curMessage = rest; + + // Add any following non-log-format lines to the message: + _line.clear(); + while ( _in && _in.peek() >= 0 ) { + std::getline(_in, _line); + if ( _line.empty() ) break; + if ( looksLikeLogLine(_line) ) break; + _curMessage += '\n'; + _curMessage += _line; + _line.clear(); + } + + return true; + } + + Timestamp startTime() const override { return _startTime; } + + Timestamp timestamp() const override { return _curTimestamp; } + + int8_t level() const override { return _curLevel; } + + const std::string& domain() const override { return _curDomain; } + + uint64_t objectID() const override { return _curObjectID; } + + const std::string* objectDescription() const override { return &_curObject; } + + void decodeMessageTo(std::ostream& out) override { out << _curMessage; } + + private: + static bool looksLikeLogLine(std::string_view line) { + if ( line.size() < 27 ) return false; + for ( uint8_t c : line.substr(0, 27) ) { + if ( !isdigit(c) && c != '-' && c != ':' && c != '.' && c != 'Z' && c != 'T' ) return false; + } + return true; + } + + static constexpr std::string_view kLevelNames[] = {"Debug", "Verbose", "Info", "WARNING", "ERROR"}; + + std::istream& _in; + Timestamp _startTime{}; + std::string _line; + + Timestamp _curTimestamp; + int8_t _curLevel; + std::string _curDomain; + std::string _curObject; + uint64_t _curObjectID; + std::string _curMessage; + }; + +} // namespace litecore diff --git a/tool_support/Tool.hh b/tool_support/Tool.hh index c5fc7bfe2..ee35fb011 100644 --- a/tool_support/Tool.hh +++ b/tool_support/Tool.hh @@ -28,8 +28,9 @@ #include #include #include -#include +#include #include +#include #if defined(CMAKE) && __has_include("config.h") # include "config.h" @@ -182,8 +183,12 @@ class Tool { std::string ansiItalic() { return ansi("3"); } + std::string ansiNoItalic() { return ansi("23"); } + std::string ansiUnderline() { return ansi("4"); } + std::string ansiNoUnderline() { return ansi("24"); } + std::string ansiRed() { return ansi("31"); } std::string ansiReset() { return ansi("0"); } @@ -241,6 +246,12 @@ class Tool { /** Returns & consumes the next arg, or fails if there are none. */ std::string nextArg(const char* what) { + if ( _flagArg ) { + // This is the part after the `=` while handling a flag of the form `--flag=value` + std::string arg = std::move(*_flagArg); + _flagArg = std::nullopt; + return arg; + } if ( !_argTokenizer.hasArgument() ) failMisuse(litecore::stringprintf("Missing argument: expected %s", what)); std::string arg = _argTokenizer.argument(); _argTokenizer.next(); @@ -290,31 +301,46 @@ class Tool { virtual void processFlags(std::initializer_list specs) { while ( true ) { std::string flag = peekNextArg(); - if ( !flag.starts_with('-') || flag.size() > 20 ) return; + if ( !flag.starts_with('-') ) return; _argTokenizer.next(); if ( flag == "--" ) return; // marks end of flags - bool handled; try { - handled = processFlag(flag, specs); - } catch ( std::exception const& x ) { fail("in flag " + flag + ": " + x.what()); } - - if ( !handled ) { - // Flags all subcommands accept: - if ( flag == "--help" ) { - usage(); - exit(0); - } else if ( flag == "--verbose" || flag == "-v" ) { - ++_verbose; - } else if ( flag == "--color" ) { - enableColor(); - } else if ( flag == "--version" ) { - std::cout << _name << " " << TOOLS_VERSION_STRING << std::endl << std::endl; - exit(0); - } else { - fail(std::string("Unknown flag ") + flag); + if ( auto [f, arg] = litecore::split2(flag, "="); !arg.empty() ) { + // Flag of the form `--flag=value`; treat `value` as the next arg during parsing + flag = f; + _flagArg = arg; } + + bool handled; + try { + handled = processFlag(flag, specs); + } catch ( std::exception const& x ) { fail("in flag " + flag + ": " + x.what()); } + + if ( !handled ) { + // Flags all subcommands accept: + if ( flag == "--help" ) { + usage(); + exit(0); + } else if ( flag == "--verbose" || flag == "-v" ) { + ++_verbose; + } else if ( flag == "--color" ) { + enableColor(); + } else if ( flag == "--version" ) { + std::cout << _name << " " << TOOLS_VERSION_STRING << std::endl << std::endl; + exit(0); + } else { + fail(std::string("Unknown flag ") + flag); + } + } + + if ( _flagArg ) // arg portion of flag wasn't consumed by handler + fail("Flag " + flag + " does not take an argument"); + + } catch ( ... ) { + _flagArg = std::nullopt; + throw; } } } @@ -322,7 +348,7 @@ class Tool { /** Subroutine of processFlags; looks up one flag and calls its handler, or returns false. */ virtual bool processFlag(const std::string& flag, const std::initializer_list& specs) { for ( auto& spec : specs ) { - if ( flag == std::string(spec.flag) ) { + if ( flag == spec.flag ) { spec.handler(); return true; } @@ -356,7 +382,8 @@ class Tool { void enableColor(); static void initReadLine(); - std::string _toolPath; - std::string _name; - ArgumentTokenizer _argTokenizer; + std::string _toolPath; + std::string _name; + ArgumentTokenizer _argTokenizer; + std::optional _flagArg; };