Adding upstream version 14.2.21.upstream/14.2.21upstream

Signed-off-by: Daniel Baumann <daniel.baumann@progress-linux.org>

1 files changed, 449 insertions, 0 deletions

diff --git a/src/log/Log.cc b/src/log/Log.cc
new file mode 100644
index 00000000..85b8ba22
--- /dev/null
+++ b/src/log/Log.cc
@@ -0,0 +1,449 @@
+// -*- mode:C++; tab-width:8; c-basic-offset:2; indent-tabs-mode:t -*-
+// vim: ts=8 sw=2 smarttab
+
+#include "Log.h"
+
+#include "common/errno.h"
+#include "common/safe_io.h"
+#include "common/Graylog.h"
+#include "common/valgrind.h"
+
+#include "include/ceph_assert.h"
+#include "include/compat.h"
+#include "include/on_exit.h"
+
+#include "Entry.h"
+#include "LogClock.h"
+#include "SubsystemMap.h"
+
+#include <errno.h>
+#include <fcntl.h>
+#include <syslog.h>
+
+#include <iostream>
+
+#define MAX_LOG_BUF 65536
+
+namespace ceph {
+namespace logging {
+
+static OnExitManager exit_callbacks;
+
+static void log_on_exit(void *p)
+{
+  Log *l = *(Log **)p;
+  if (l)
+    l->flush();
+  delete (Log **)p;// Delete allocated pointer (not Log object, the pointer only!)
+}
+
+Log::Log(const SubsystemMap *s)
+  : m_indirect_this(nullptr),
+    m_subs(s),
+    m_recent(DEFAULT_MAX_RECENT)
+{
+  m_log_buf.reserve(MAX_LOG_BUF);
+}
+
+Log::~Log()
+{
+  if (m_indirect_this) {
+    *m_indirect_this = nullptr;
+  }
+
+  ceph_assert(!is_started());
+  if (m_fd >= 0)
+    VOID_TEMP_FAILURE_RETRY(::close(m_fd));
+}
+
+
+///
+void Log::set_coarse_timestamps(bool coarse) {
+  std::scoped_lock lock(m_flush_mutex);
+  if (coarse)
+    Entry::clock().coarsen();
+  else
+    Entry::clock().refine();
+}
+
+void Log::set_flush_on_exit()
+{
+  std::scoped_lock lock(m_flush_mutex);
+  // Make sure we flush on shutdown.  We do this by deliberately
+  // leaking an indirect pointer to ourselves (on_exit() can't
+  // unregister a callback).  This is not racy only becuase we
+  // assume that exit() won't race with ~Log().
+  if (m_indirect_this == NULL) {
+    m_indirect_this = new (Log*)(this);
+    exit_callbacks.add_callback(log_on_exit, m_indirect_this);
+  }
+}
+
+void Log::set_max_new(std::size_t n)
+{
+  std::scoped_lock lock(m_queue_mutex);
+  m_max_new = n;
+}
+
+void Log::set_max_recent(std::size_t n)
+{
+  std::scoped_lock lock(m_flush_mutex);
+  m_max_recent = n;
+}
+
+void Log::set_log_file(std::string_view fn)
+{
+  std::scoped_lock lock(m_flush_mutex);
+  m_log_file = fn;
+}
+
+void Log::set_log_stderr_prefix(std::string_view p)
+{
+  std::scoped_lock lock(m_flush_mutex);
+  m_log_stderr_prefix = p;
+}
+
+void Log::reopen_log_file()
+{
+  std::scoped_lock lock(m_flush_mutex);
+  if (!is_started()) {
+    return;
+  }
+  m_flush_mutex_holder = pthread_self();
+  if (m_fd >= 0)
+    VOID_TEMP_FAILURE_RETRY(::close(m_fd));
+  if (m_log_file.length()) {
+    m_fd = ::open(m_log_file.c_str(), O_CREAT|O_WRONLY|O_APPEND|O_CLOEXEC, 0644);
+    if (m_fd >= 0 && (m_uid || m_gid)) {
+      if (::fchown(m_fd, m_uid, m_gid) < 0) {
+	int e = errno;
+	std::cerr << "failed to chown " << m_log_file << ": " << cpp_strerror(e)
+	     << std::endl;
+      }
+    }
+  } else {
+    m_fd = -1;
+  }
+  m_flush_mutex_holder = 0;
+}
+
+void Log::chown_log_file(uid_t uid, gid_t gid)
+{
+  std::scoped_lock lock(m_flush_mutex);
+  if (m_fd >= 0) {
+    int r = ::fchown(m_fd, uid, gid);
+    if (r < 0) {
+      r = -errno;
+      std::cerr << "failed to chown " << m_log_file << ": " << cpp_strerror(r)
+	   << std::endl;
+    }
+  }
+}
+
+void Log::set_syslog_level(int log, int crash)
+{
+  std::scoped_lock lock(m_flush_mutex);
+  m_syslog_log = log;
+  m_syslog_crash = crash;
+}
+
+void Log::set_stderr_level(int log, int crash)
+{
+  std::scoped_lock lock(m_flush_mutex);
+  m_stderr_log = log;
+  m_stderr_crash = crash;
+}
+
+void Log::set_graylog_level(int log, int crash)
+{
+  std::scoped_lock lock(m_flush_mutex);
+  m_graylog_log = log;
+  m_graylog_crash = crash;
+}
+
+void Log::start_graylog()
+{
+  std::scoped_lock lock(m_flush_mutex);
+  if (! m_graylog.get())
+    m_graylog = std::make_shared<Graylog>(m_subs, "dlog");
+}
+
+
+void Log::stop_graylog()
+{
+  std::scoped_lock lock(m_flush_mutex);
+  m_graylog.reset();
+}
+
+void Log::submit_entry(Entry&& e)
+{
+  std::unique_lock lock(m_queue_mutex);
+  m_queue_mutex_holder = pthread_self();
+
+  if (unlikely(m_inject_segv))
+    *(volatile int *)(0) = 0xdead;
+
+  // wait for flush to catch up
+  while (is_started() &&
+	 m_new.size() > m_max_new) {
+    if (m_stop) break; // force addition
+    m_cond_loggers.wait(lock);
+  }
+
+  m_new.emplace_back(std::move(e));
+  m_cond_flusher.notify_all();
+  m_queue_mutex_holder = 0;
+}
+
+void Log::flush()
+{
+  std::scoped_lock lock1(m_flush_mutex);
+  m_flush_mutex_holder = pthread_self();
+
+  {
+    std::scoped_lock lock2(m_queue_mutex);
+    m_queue_mutex_holder = pthread_self();
+    assert(m_flush.empty());
+    m_flush.swap(m_new);
+    m_cond_loggers.notify_all();
+    m_queue_mutex_holder = 0;
+  }
+
+  _flush(m_flush, true, false);
+  m_flush_mutex_holder = 0;
+}
+
+void Log::_log_safe_write(std::string_view sv)
+{
+  if (m_fd < 0)
+    return;
+  int r = safe_write(m_fd, sv.data(), sv.size());
+  if (r != m_fd_last_error) {
+    if (r < 0)
+      std::cerr << "problem writing to " << m_log_file
+           << ": " << cpp_strerror(r)
+           << std::endl;
+    m_fd_last_error = r;
+  }
+}
+
+void Log::_flush_logbuf()
+{
+  if (m_log_buf.size()) {
+    _log_safe_write(std::string_view(m_log_buf.data(), m_log_buf.size()));
+    m_log_buf.resize(0);
+  }
+}
+
+void Log::_flush(EntryVector& t, bool requeue, bool crash)
+{
+  long len = 0;
+  if (crash) {
+    len = t.size();
+  }
+  if (!requeue && t.empty()) {
+    return;
+  }
+  for (auto& e : t) {
+    auto prio = e.m_prio;
+    auto stamp = e.m_stamp;
+    auto sub = e.m_subsys;
+    auto thread = e.m_thread;
+    auto str = e.strv();
+
+    bool should_log = crash || m_subs->get_log_level(sub) >= prio;
+    bool do_fd = m_fd >= 0 && should_log;
+    bool do_syslog = m_syslog_crash >= prio && should_log;
+    bool do_stderr = m_stderr_crash >= prio && should_log;
+    bool do_graylog2 = m_graylog_crash >= prio && should_log;
+
+    if (do_fd || do_syslog || do_stderr) {
+      const std::size_t cur = m_log_buf.size();
+      std::size_t used = 0;
+      const std::size_t allocated = e.size() + 80;
+      m_log_buf.resize(cur + allocated);
+
+      char* const start = m_log_buf.data();
+      char* pos = start + cur;
+
+      if (crash) {
+        used += (std::size_t)snprintf(pos + used, allocated - used, "%6ld> ", -(--len));
+      }
+      used += (std::size_t)append_time(stamp, pos + used, allocated - used);
+      used += (std::size_t)snprintf(pos + used, allocated - used, " %lx %2d ", (unsigned long)thread, prio);
+      memcpy(pos + used, str.data(), str.size());
+      used += str.size();
+      pos[used] = '\0';
+      ceph_assert((used + 1 /* '\n' */) < allocated);
+
+      if (do_syslog) {
+        syslog(LOG_USER|LOG_INFO, "%s", pos);
+      }
+
+      if (do_stderr) {
+        std::cerr << m_log_stderr_prefix << std::string_view(pos, used) << std::endl;
+      }
+
+      /* now add newline */
+      pos[used++] = '\n';
+
+      if (do_fd) {
+        m_log_buf.resize(cur + used);
+      } else {
+        m_log_buf.resize(0);
+      }
+
+      if (m_log_buf.size() > MAX_LOG_BUF) {
+        _flush_logbuf();
+      }
+    }
+
+    if (do_graylog2 && m_graylog) {
+      m_graylog->log_entry(e);
+    }
+
+    if (requeue) {
+      m_recent.push_back(std::move(e));
+    }
+  }
+  t.clear();
+
+  _flush_logbuf();
+}
+
+void Log::_log_message(const char *s, bool crash)
+{
+  if (m_fd >= 0) {
+    size_t len = strlen(s);
+    std::string b;
+    b.reserve(len + 1);
+    b.append(s, len);
+    b += '\n';
+    int r = safe_write(m_fd, b.c_str(), b.size());
+    if (r < 0)
+      std::cerr << "problem writing to " << m_log_file << ": " << cpp_strerror(r) << std::endl;
+  }
+  if ((crash ? m_syslog_crash : m_syslog_log) >= 0) {
+    syslog(LOG_USER|LOG_INFO, "%s", s);
+  }
+
+  if ((crash ? m_stderr_crash : m_stderr_log) >= 0) {
+    std::cerr << s << std::endl;
+  }
+}
+
+void Log::dump_recent()
+{
+  std::scoped_lock lock1(m_flush_mutex);
+  m_flush_mutex_holder = pthread_self();
+
+  {
+    std::scoped_lock lock2(m_queue_mutex);
+    m_queue_mutex_holder = pthread_self();
+    assert(m_flush.empty());
+    m_flush.swap(m_new);
+    m_queue_mutex_holder = 0;
+  }
+
+  _flush(m_flush, true, false);
+  _flush_logbuf();
+
+  _log_message("--- begin dump of recent events ---", true);
+  {
+    EntryVector t;
+    t.insert(t.end(), std::make_move_iterator(m_recent.begin()), std::make_move_iterator(m_recent.end()));
+    m_recent.clear();
+    _flush(t, true, true);
+  }
+
+  char buf[4096];
+  _log_message("--- logging levels ---", true);
+  for (const auto& p : m_subs->m_subsys) {
+    snprintf(buf, sizeof(buf), "  %2d/%2d %s", p.log_level, p.gather_level, p.name);
+    _log_message(buf, true);
+  }
+
+  sprintf(buf, "  %2d/%2d (syslog threshold)", m_syslog_log, m_syslog_crash);
+  _log_message(buf, true);
+  sprintf(buf, "  %2d/%2d (stderr threshold)", m_stderr_log, m_stderr_crash);
+  _log_message(buf, true);
+  sprintf(buf, "  max_recent %9zu", m_max_recent);
+  _log_message(buf, true);
+  sprintf(buf, "  max_new    %9zu", m_max_new);
+  _log_message(buf, true);
+  sprintf(buf, "  log_file %s", m_log_file.c_str());
+  _log_message(buf, true);
+
+  _log_message("--- end dump of recent events ---", true);
+
+  _flush_logbuf();
+
+  m_flush_mutex_holder = 0;
+}
+
+void Log::start()
+{
+  ceph_assert(!is_started());
+  {
+    std::scoped_lock lock(m_queue_mutex);
+    m_stop = false;
+  }
+  create("log");
+}
+
+void Log::stop()
+{
+  if (is_started()) {
+    {
+      std::scoped_lock lock(m_queue_mutex);
+      m_stop = true;
+      m_cond_flusher.notify_one();
+      m_cond_loggers.notify_all();
+    }
+    join();
+  }
+}
+
+void *Log::entry()
+{
+  reopen_log_file();
+  {
+    std::unique_lock lock(m_queue_mutex);
+    m_queue_mutex_holder = pthread_self();
+    while (!m_stop) {
+      if (!m_new.empty()) {
+        m_queue_mutex_holder = 0;
+        lock.unlock();
+        flush();
+        lock.lock();
+        m_queue_mutex_holder = pthread_self();
+        continue;
+      }
+
+      m_cond_flusher.wait(lock);
+    }
+    m_queue_mutex_holder = 0;
+  }
+  flush();
+  return NULL;
+}
+
+bool Log::is_inside_log_lock()
+{
+  return
+    pthread_self() == m_queue_mutex_holder ||
+    pthread_self() == m_flush_mutex_holder;
+}
+
+void Log::inject_segv()
+{
+  m_inject_segv = true;
+}
+
+void Log::reset_segv()
+{
+  m_inject_segv = false;
+}
+
+} // ceph::logging::
+} // ceph::