Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

log: Preserve log messages during RPM transaction #1772

Merged
merged 1 commit into from
Oct 15, 2024
Merged
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
147 changes: 89 additions & 58 deletions libdnf5/logger/rotating_file_logger.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -25,117 +25,148 @@ along with libdnf. If not, see <https://www.gnu.org/licenses/>.
#include <fmt/format.h>
#include <string.h>
#include <sys/file.h>
#include <sys/stat.h>
#include <unistd.h>

#include <mutex>

namespace libdnf5 {

const int LOG_FILE_OPEN_FLAGS = O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC;
const mode_t LOG_FILE_OPEN_MODE = S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH;

class RotatingFileLogger::Impl {
public:
explicit Impl(const std::filesystem::path & base_file_path, std::size_t max_bytes, std::size_t backup_count);
~Impl();

void write(const char * line) noexcept;

private:
bool should_rotate(int fd, std::size_t msg_len) const noexcept;
bool should_rotate(std::size_t msg_len) const noexcept;

const std::filesystem::path base_file_path;
const std::size_t max_bytes;
const std::size_t backup_count;

std::mutex stream_mutex;

int log_file_fd{-1};
};


RotatingFileLogger::Impl::Impl(
const std::filesystem::path & base_file_path, std::size_t max_bytes, std::size_t backup_count)
: base_file_path{base_file_path},
max_bytes{max_bytes},
backup_count{backup_count} {
if (::open(
base_file_path.c_str(), O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH) ==
-1) {
backup_count{backup_count},
log_file_fd(::open(base_file_path.c_str(), LOG_FILE_OPEN_FLAGS, LOG_FILE_OPEN_MODE)) {
if (log_file_fd == -1) {
throw FileSystemError(errno, base_file_path, M_("Cannot open log file"));
}
}


RotatingFileLogger::Impl::~Impl() {
if (log_file_fd != -1) {
::close(log_file_fd);
}
}

void RotatingFileLogger::Impl::write(const char * line) noexcept {
try {
// required for thread safety
std::lock_guard<std::mutex> guard(stream_mutex);

auto line_len = strlen(line);
while (true) {
// open (create) the base log file and lock it
auto fd = ::open(
base_file_path.c_str(),
O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC,
S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH);
if (fd == -1) {
if (log_file_fd == -1) {
// something is terribly wrong, cannot log
return;
}
::flock(fd, LOCK_EX);

if (!should_rotate(fd, line_len)) {
// no need to rotate log files, just write a message to the log and return
std::size_t written = 0;
ssize_t ret;
do {
ret = ::write(fd, line + written, line_len - written);
if (ret <= 0) {
break;

// acquire log file lock
::flock(log_file_fd, LOCK_EX);

// verify that the log file has not been rotated by another process
auto check_file_fd = ::open(base_file_path.c_str(), O_RDONLY | O_CLOEXEC);
if (check_file_fd == -1) {
// try to create log file in case it was rotated by another process
auto log_file_fd_tmp = ::open(base_file_path.c_str(), LOG_FILE_OPEN_FLAGS, LOG_FILE_OPEN_MODE);
if (log_file_fd_tmp != -1) {
// log file created, update log_file_fd and retry
::close(log_file_fd);
log_file_fd = log_file_fd_tmp;
continue;
}
// cannot create the log file - this can mean that libdnf5 is
// inside the rpm transaction which enters the chroot changing
// path resolution. In such case just use log_file_fd without
// checking rotation.
} else {
// check that log_file_fd and check_file_fd belong to the same inode
struct stat log_fd_stat;
struct stat check_fd_stat;
if (::fstat(log_file_fd, &log_fd_stat) == -1 || fstat(check_file_fd, &check_fd_stat) == -1) {
// something went wrong, cannot stat log file.
// Close file descriptors and return
::close(check_file_fd);
::close(log_file_fd);
log_file_fd = -1;
return;
}
::close(check_file_fd);
if (log_fd_stat.st_ino != check_fd_stat.st_ino) {
// log file descriptor belongs to another file than base_file_path.
// Probably the log file was rotated by another process.
// Re-open log_file_fd and try again
::close(log_file_fd);
log_file_fd = ::open(base_file_path.c_str(), LOG_FILE_OPEN_FLAGS, LOG_FILE_OPEN_MODE);
continue;
}
if (should_rotate(line_len)) {
// A log file rotation is needed and so far no one has done it.
// Let's rotate the files and start from the beginning.
try {
for (auto file_idx = backup_count; file_idx > 0; --file_idx) {
auto path_old = file_idx > 1 ? fmt::format("{}.{}", base_file_path.string(), file_idx - 1)
: base_file_path.string();
auto path_new = fmt::format("{}.{}", base_file_path.string(), file_idx);
::rename(path_old.c_str(), path_new.c_str());
}
} catch (...) {
}
written += static_cast<std::size_t>(ret);
} while (written < line_len);
::close(fd);
return;
::close(log_file_fd);
log_file_fd = ::open(base_file_path.c_str(), LOG_FILE_OPEN_FLAGS, LOG_FILE_OPEN_MODE);
continue;
}
}

// A rotation of the log files is needed, rotate the files and start from the beginning.
// But before that, we will verify that another process did not perform the rotation.

auto fd_base_file = ::open(base_file_path.c_str(), O_RDONLY | O_CLOEXEC);
if (fd_base_file == -1) {
// Unable to reopen the base log file, it was probably rotated by another process.
// Close the locked file descriptor and start from the beginning.
::close(fd);
continue;
}
if (::lseek(fd_base_file, 0, SEEK_END) != ::lseek(fd, 0, SEEK_END)) {
// The size of the base log file is different than the size of the locked descriptor,
// probably rotated by another process.
// Close file descriptors and start from the beginning.
::close(fd_base_file);
::close(fd);
continue;
}
::close(fd_base_file);

// A log file rotation is needed and so far no one has done it.
// Let's rotate the files and start from the beginning.
try {
for (auto file_idx = backup_count; file_idx > 0; --file_idx) {
auto path_old = file_idx > 1 ? fmt::format("{}.{}", base_file_path.string(), file_idx - 1)
: base_file_path.string();
auto path_new = fmt::format("{}.{}", base_file_path.string(), file_idx);
::rename(path_old.c_str(), path_new.c_str());
// write the log line
std::size_t written = 0;
ssize_t ret;
do {
ret = ::write(log_file_fd, line + written, line_len - written);
if (ret <= 0) {
break;
}
} catch (...) {
}
::close(fd);
written += static_cast<std::size_t>(ret);
} while (written < line_len);

// we are done, unlock the log_file_fd and return
::flock(log_file_fd, LOCK_UN);
return;
}
} catch (...) {
}
}


bool RotatingFileLogger::Impl::should_rotate(int fd, std::size_t msg_len) const noexcept {
bool RotatingFileLogger::Impl::should_rotate(std::size_t msg_len) const noexcept {
if (max_bytes == 0 || backup_count < 1) {
return false;
}
auto len = ::lseek(fd, 0, SEEK_END);
auto len = ::lseek(log_file_fd, 0, SEEK_END);
if (len < 0) {
// error
return false;
Expand Down
Loading