log: Preserve log messages during RPM transaction

There is an issue with RotatingFileLogger where log messages during an
RPM transaction in installroot fail to be recorded. When RPM enters a
chroot environment during the transaction, the path resolution changes,
and RotatingFileLogger attempts to reopen the log file from its disk
path for each message. However, once inside the chroot, the log file
path can no longer be resolved, leading to a failure in logging until
the RPM transaction completes.

This patch modifies the RotatingFileLogger behavior to keep the log file
descriptor open, ensuring continuous logging throughout the RPM
transaction.

libdnf5/logger/rotating_file_logger.cpp

@@ -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;