diff --git a/File.cpp b/File.cpp index b90d481..fe8036d 100644 --- a/File.cpp +++ b/File.cpp @@ -6,6 +6,9 @@ #include #include #include +#include +#include +#include namespace coreutils { @@ -16,6 +19,8 @@ namespace coreutils { void File::open(coreutils::ZString fileName, int mode, int authority) { this->fileName = fileName; + this->mode = mode; + this->authority = authority; buffer = NULL; @@ -89,6 +94,63 @@ namespace coreutils { int len = ::write(fd, data.getData(), data.getLength()); } + size_t File::currentSize() { + struct stat status; + if (fstat(fd, &status) != 0) { + std::stringstream temp; + temp << "Error statting file " << fileName << "."; + throw Exception(temp.str(), __FILE__, __LINE__); + } + return (size_t)status.st_size; + } + + void File::rotate(int maxBackups) { + close(fd); + + // Resolve through fileName first, not its raw configured spelling - + // rename() never follows symlinks for either its source or + // destination path. BARANTMail's own "barantmail.log" is a symlink + // into /var/log/ on purpose (keeps a large, fast-growing log off + // the same filesystem/tree as the source checkout) - renaming that + // SYMLINK's own path to ".1" below, then recreating a plain file + // at the original (now-empty) path via open()'s O_CREAT, would + // silently sever the symlink and start a brand new file right back + // in the source tree, undoing that setup the very first time + // rotation ever fires on a symlinked path. Confirmed live: exactly + // this happened to BARANTMail's real log on this code's first + // real trigger (a 23GB pre-existing file, already far past the + // configured threshold, rotated on the very next size check after + // a fresh process started logging to it). realpath() requires the + // target to already exist, which it does here (this object has it + // open) - falls back to the configured path unresolved only if + // that somehow isn't true (e.g. the target was deleted out from + // under it), matching plain (non-symlink) File usage exactly as + // before. + char resolved[PATH_MAX]; + std::string configuredPath(fileName.c_str()); + std::string base = realpath(configuredPath.c_str(), resolved) ? + std::string(resolved) : configuredPath; + + // Oldest-first: delete what's about to fall off the end, then + // shift each remaining backup up by one, working from the + // highest number down so a lower-numbered file is never + // clobbered before it's been moved out of the way. + std::string oldest = base + "." + std::to_string(maxBackups); + ::remove(oldest.c_str()); + for (int i = maxBackups - 1; i >= 1; i--) { + std::string from = base + "." + std::to_string(i); + std::string to = base + "." + std::to_string(i + 1); + ::rename(from.c_str(), to.c_str()); + } + ::rename(base.c_str(), (base + ".1").c_str()); + + // Reopens via the ORIGINAL (possibly symlinked) fileName, not the + // resolved `base` - the symlink itself was never touched above + // (only its target was renamed away), so this correctly follows it + // again and creates a fresh file at the real target location. + open(fileName, mode, authority); + } + std::string File::asString() { return std::string(buffer, size); } diff --git a/File.h b/File.h index 86937c9..d13616b 100644 --- a/File.h +++ b/File.h @@ -29,11 +29,34 @@ namespace coreutils { size_t size; bool eof(); + /// + /// Real, on-disk size of this file right now, queried directly + /// from the OS via fstat() - not the "size" member above, which + /// is only ever set at open()/read() time and goes stale the + /// moment anything else appends to this fd (exactly the case for + /// a long-lived, append-mode file such as Log's static logFile). + /// + + size_t currentSize(); + + /// + /// Close this file, shift any existing ".1" .. ".maxBackups-1" + /// backups up by one (deleting whatever already sits at + /// ".maxBackups"), rename the current file to ".1", then reopen + /// a fresh file at the original path/mode/authority. Meant for a + /// long-lived, append-mode file that needs a size cap - not + /// meaningful for a file opened for reading. + /// + + void rotate(int maxBackups); + coreutils::ZString fileName; private: void open(coreutils::ZString fileName, int mode, int authority); int fd; + int mode; + int authority; coreutils::ZString zstring; bool mEof = false; diff --git a/HTTPRequest.cpp b/HTTPRequest.cpp index 0f2a308..4022878 100644 --- a/HTTPRequest.cpp +++ b/HTTPRequest.cpp @@ -23,7 +23,26 @@ namespace coreutils { if (!checkParse(*lineParser)) return Status::INCOMPLETE; { + // line is a view into reader's own buffer (see + // LineParser::parse()), not into lineParser itself - safe to + // delete lineParser immediately, before the parts.size() + // check below can throw. Previously this delete sat AFTER + // that check, so a malformed request line (any count other + // than exactly 3 space-separated parts - confirmed live via + // real scanner/bot traffic hitting this daily) leaked + // lineParser and left the member non-NULL. Since state is + // never advanced past REQUEST_LINE on this throw, ANY later + // reentry into this same case (state itself surviving the + // exception, e.g. if this HTTPRequest is ever driven again + // before its owning session tears down) would see a + // non-NULL lineParser and skip allocating a fresh one, + // reusing an already-completed, now-stale parser instance + // instead - a real invariant violation that a heap- + // corruption crash (munmap_chunk(): invalid pointer) was + // traced back to. ZString line = lineParser->getLine(); + delete lineParser; + lineParser = NULL; ZString sp(" "); std::vector &parts = line.split(sp); if (parts.size() != 3) @@ -33,8 +52,6 @@ namespace coreutils { path = MString(parts[1]); version = MString(parts[2]); } - delete lineParser; - lineParser = NULL; { // Split the query string off before anything else sees `path` - // a route table (see the APIServer plan) should never have to @@ -49,16 +66,33 @@ namespace coreutils { return Status::DATA_AVAIL; } - case HEADERS: + case HEADERS: { if (!headerParser) headerParser = new IMFHeader(reader); - if (!checkParse(*headerParser)) + // The actual throw for a malformed header (e.g. a header line + // with no ':') happens deep inside checkParse() -> IMFHeader:: + // parse(), well before headerParser->getHeaders() below ever + // runs - same leaked-pointer/stale-reentry hazard as + // REQUEST_LINE above, confirmed as the other half of the same + // real crash. Cleaning up here before rethrowing keeps + // headerParser NULL on every exit path, matching the + // REQUEST_LINE fix. + bool complete; + try { + complete = checkParse(*headerParser); + } catch (...) { + delete headerParser; + headerParser = NULL; + throw; + } + if (!complete) return Status::INCOMPLETE; headers = headerParser->getHeaders(); delete headerParser; headerParser = NULL; state = BODY; return Status::DATA_AVAIL; + } case BODY: { MString contentLengthHeader = getHeader("Content-Length"); diff --git a/JString.cpp b/JString.cpp index e91f0aa..5c6bc0a 100644 --- a/JString.cpp +++ b/JString.cpp @@ -393,6 +393,20 @@ namespace coreutils { throw coreutils::Exception("Path is expecting an array for selector value."); while (index > 0) { skipValue(); + // Reaching the array's closing bracket here means the + // caller asked for an index past the last real element - + // a legitimate "does this exist" probe (see exists()'s own + // doc comment), not malformed JSON, and the one real + // caller of this shape (BARANTMailConfig::getDkimEntries(), + // walking a "dkim" array of unknown length ascending until + // exists() first returns false) depends on getting a clean + // "not found" back rather than an uncaught exception. + // Confirmed live: querying one index past a real 2-element + // array threw this unconditionally before, crashing server + // startup outright instead of the config simply reporting + // "no more entries". + if (ifNext("]")) + return false; if (!ifNext(",")) throw coreutils::Exception("expecting comma to seperate array elements."); --index; diff --git a/Log.cpp b/Log.cpp index e135175..5dcd545 100644 --- a/Log.cpp +++ b/Log.cpp @@ -11,6 +11,9 @@ namespace coreutils { LogListener *Log::logListener = NULL; File *Log::logFile = NULL; int Log::seq = 0; + std::mutex Log::mtx; + size_t Log::maxLogSize = 100 * 1024 * 1024; + int Log::maxLogBackups = 5; Log::Log(LogListener *logListener) { this->logListener = logListener; @@ -71,20 +74,39 @@ namespace coreutils { std::stringstream out; out << this->str() << std::endl; - ; + std::string text = out.str(); mtx.lock(); - if (logListener) - logListener->logSend(out.str()); + if (logFile) { + logFile->write(text); + if (maxLogSize > 0 && logFile->currentSize() >= maxLogSize) + logFile->rotate(maxLogBackups); + } - if (logFile) - logFile->write(out.str()); - -// std::cout << out.str(); +// std::cout << text; ++seq; mtx.unlock(); + + // Called AFTER releasing mtx - a real, confirmed (via gdb thread + // dump on a hung production BARANTMail) lock-order inversion: + // ConsoleServer::logSend() takes TCPServer's own `lock` + // (recursive_mutex) to echo this line to connected console + // sessions, but TCPServer::connectionRequest() holds that SAME + // lock for the whole span of accepting+TLS-handshaking a new + // connection - during which another Log() call (e.g. from TLS's + // own handshake-complete callback, on a DIFFERENT thread) needs + // mtx. One thread held mtx and waited on TCPServer::lock; another + // held TCPServer::lock and waited on mtx - neither the + // recursive_mutex fix (which only helps the SAME thread re-enter + // TCPServer::lock) nor anything else here prevented it, since + // that's a same-thread-only guarantee and this is a two-thread, + // two-different-mutex inversion. logListener->logSend() only + // relays an already-built string and touches no other Log state, + // so it doesn't need mtx held at all. + if (logListener) + logListener->logSend(text); } } diff --git a/Log.h b/Log.h index 8419b84..a98bf74 100644 --- a/Log.h +++ b/Log.h @@ -89,8 +89,34 @@ namespace coreutils { static int seq; + /// + /// Rotation threshold for the static logFile, in bytes - checked + /// after every write that reaches it. Default 100MB. Change it + /// any time (takes effect on the next log call); 0 disables + /// rotation entirely. + /// + + static size_t maxLogSize; + + /// + /// How many rotated-out backups (logFile.1, logFile.2, ...) to + /// keep once maxLogSize is hit - the oldest beyond this count is + /// deleted outright, not just renamed away. Default 5. + /// + + static int maxLogBackups; + private: - std::mutex mtx; + // Static, not per-instance - every Log(level) call constructs + // and destructs its own temporary Log object, so a per-instance + // mutex (the original declaration here) provided no actual + // mutual exclusion between concurrent threads at all, each + // locking a separate mutex of their own. Only became load-bearing + // once rotation was added: two threads racing between "check + // size" and "close/rename/reopen" on the one shared logFile + // could otherwise write to a stale fd mid-rotation or rotate out + // from under an in-flight write. + static std::mutex mtx; }; diff --git a/MString.cpp b/MString.cpp index 301b54c..2b28e62 100644 --- a/MString.cpp +++ b/MString.cpp @@ -336,8 +336,25 @@ namespace coreutils { } MString &MString::read(int fd) { + // ::read() returns 0 on EOF, a positive byte count on success, or + // -1 on error (EINTR - a signal interrupting the call, most + // plausibly, but any read() error) - the old `while(::read(...))` + // treated -1 as truthy exactly like a successful read, so a + // single interrupted read turned this into an infinite loop: + // every iteration from then on called write() with whatever + // garbage was left in the uninitialized `ch`, growing this + // MString without bound. Confirmed via a real production core + // dump - the eventual crash was a SIGSEGV in write() itself, + // because unbounded growth made realloc() in setSize() finally + // fail (returning NULL) under memory pressure, and the next + // *(data + length - 1) = ch wrote through that null pointer. The + // actual trigger was 's own out.read(fdo[0]), reading a + // subprocess's output pipe, but this bug lives in a core utility + // used throughout the codebase - anything reading a fd through + // MString was exposed to it whenever that read() call errored. char ch; - while(::read(fd, &ch, 1)) + ssize_t n; + while((n = ::read(fd, &ch, 1)) > 0) write(ch); onChange(); return *this; @@ -345,7 +362,8 @@ namespace coreutils { MString &MString::read(int fd, int count) { char ch; - while(count-- && ::read(fd, &ch, 1)) + ssize_t n; + while(count-- && (n = ::read(fd, &ch, 1)) > 0) write(ch); onChange(); return *this;