]> git.apps.os.sepia.ceph.com Git - ceph-ci.git/commitdiff
crimson/admin/admin_socket: add logs, move to ceph_assert
authorMatan Breizman <mbreizma@redhat.com>
Thu, 29 May 2025 09:18:01 +0000 (09:18 +0000)
committerMatan Breizman <mbreizma@redhat.com>
Wed, 25 Jun 2025 16:41:44 +0000 (19:41 +0300)
Signed-off-by: Matan Breizman <mbreizma@redhat.com>
(cherry picked from commit 566a91544d55a27bb5215fb9464d52e4d2d70495)

src/crimson/admin/admin_socket.cc

index 3b18708cb59af42a41ccbbdfa47105ad768caad4..4bebf5de4e72705c93bb180f8a5c4e14a22b5f59 100644 (file)
@@ -30,12 +30,7 @@ using ceph::common::bad_cmd_get;
 using ceph::common::validate_cmd;
 using ceph::common::dump_cmd_and_help_to_json;
 
-namespace {
-seastar::logger& logger()
-{
-  return crimson::get_logger(ceph_subsys_osd);
-}
-}  // namespace
+SET_SUBSYS(asok);
 
 using std::string;
 using std::string_view;
@@ -59,15 +54,18 @@ tell_result_t::tell_result_t(std::unique_ptr<Formatter> formatter)
 
 void AdminSocket::register_command(std::unique_ptr<AdminSocketHook>&& hook)
 {
+  LOG_PREFIX(AdminSocket::register_command);
   auto prefix = hook->prefix;
   auto [it, added] = hooks.emplace(prefix, std::move(hook));
-  assert(added);
-  logger().info("register_command(): {})", it->first);
+  ceph_assert(added);
+  INFO("register_command(): {})", it->first);
 }
 
 auto AdminSocket::parse_cmd(const std::vector<std::string>& cmd)
   -> std::variant<parsed_command_t, tell_result_t>
 {
+  LOG_PREFIX(AdminSocket::parse_cmd);
+  INFO("");
   // preliminaries:
   //   - create the formatter specified by the cmd parameters
   //   - locate the "op-code" string (the 'prefix' segment)
@@ -79,13 +77,13 @@ auto AdminSocket::parse_cmd(const std::vector<std::string>& cmd)
     stringstream errss;
     //  note that cmdmap_from_json() may throw on syntax issues
     if (!cmdmap_from_json(cmd, &cmdmap, errss)) {
-      logger().error("{}: incoming command error: {}", __func__, errss.str());
+      ERROR("incoming command error: {}", errss.str());
       out.append("error:"s);
       out.append(errss.str());
       return tell_result_t{-EINVAL, "invalid json", std::move(out)};
     }
   } catch (const std::runtime_error& e) {
-    logger().error("{}: incoming command syntax: {}", __func__, cmd);
+    ERROR("incoming command syntax: {}", cmd);
     out.append(string{e.what()});
     return tell_result_t{-EINVAL, "invalid json", std::move(out)};
   }
@@ -100,30 +98,34 @@ auto AdminSocket::parse_cmd(const std::vector<std::string>& cmd)
       cmd_getval(cmdmap, "cmd", prefix);
     }
   } catch (const bad_cmd_get& e) {
-    logger().error("{}: invalid syntax: {}", __func__, cmd);
+    ERROR("invalid syntax: {}", cmd);
     out.append(string{e.what()});
     return tell_result_t{-EINVAL, "invalid json", std::move(out)};
   }
 
   // match the incoming op-code to one of the registered APIs
-  if (auto found = hooks.find(prefix); found != hooks.end()) {
-    return parsed_command_t{ cmdmap, format, *found->second };
-  } else {
+  auto found = hooks.find(prefix);
+  if (found == hooks.end()) {
+    ERROR("unknown command: {}", prefix);
     return tell_result_t{-EINVAL,
                          fmt::format("unknown command '{}'", prefix),
                          std::move(out)};
   }
+  DEBUG("parsed successfully {} {}", prefix, cmd);
+  return parsed_command_t{ cmdmap, format, *found->second };
 }
 
 seastar::future<> AdminSocket::finalize_response(
   seastar::output_stream<char>& out, ceph::bufferlist&& msgs)
 {
+  LOG_PREFIX(AdminSocket::finalize_response);
+  INFO("");
   string outbuf_cont = msgs.to_str();
   if (outbuf_cont.empty()) {
     outbuf_cont = " {} ";
   }
   uint32_t response_length = htonl(outbuf_cont.length());
-  logger().info("asok response length: {}", outbuf_cont.length());
+  INFO("asok response length: {}", outbuf_cont.length());
 
   return out.write(reinterpret_cast<char*>(&response_length),
                    sizeof(response_length))
@@ -134,12 +136,15 @@ seastar::future<> AdminSocket::finalize_response(
 seastar::future<> AdminSocket::handle_command(crimson::net::ConnectionRef conn,
                                              boost::intrusive_ptr<MCommand> m)
 {
+  LOG_PREFIX(AdminSocket::handle_command);
+  INFO("");
   return execute_command(m->cmd, std::move(m->get_data())).then(
-    [conn, tid=m->get_tid()](auto result) {
+    [FNAME, conn, tid=m->get_tid()](auto result) {
     auto [ret, err, out] = std::move(result);
     auto reply = crimson::make_message<MCommandReply>(ret, err);
     reply->set_tid(tid);
     reply->set_data(out);
+    DEBUG("replying with ret {} error {}", ret, err);
     return conn->send(std::move(reply));
   });
 }
@@ -147,12 +152,16 @@ seastar::future<> AdminSocket::handle_command(crimson::net::ConnectionRef conn,
 seastar::future<> AdminSocket::execute_line(std::string cmdline,
                                             seastar::output_stream<char>& out)
 {
-  return execute_command({std::move(cmdline)}, {}).then([&out, this](auto result) {
+  LOG_PREFIX(AdminSocket::execute_line);
+  INFO("");
+  return execute_command({std::move(cmdline)}, {}).then([FNAME, &out, this](auto result) {
      auto [ret, stderr, stdout] = std::move(result);
      if (ret < 0) {
+       ERROR("{}", cpp_strerror(ret));
        stdout.append(fmt::format("ERROR: {}\n", cpp_strerror(ret)));
        stdout.append(stderr);
      }
+     DEBUG("finalizing response");
      return finalize_response(out, std::move(stdout));
   });
 }
@@ -161,20 +170,24 @@ auto AdminSocket::execute_command(const std::vector<std::string>& cmd,
                                  ceph::bufferlist&& buf)
   -> seastar::future<tell_result_t>
 {
+  LOG_PREFIX(AdminSocket::execute_command);
+  INFO("");
   auto maybe_parsed = parse_cmd(cmd);
   if (auto* parsed = std::get_if<parsed_command_t>(&maybe_parsed); parsed) {
+    DEBUG("parsed ok");
     stringstream os;
     string desc{parsed->hook.desc};
     if (!validate_cmd(desc, parsed->params, os)) {
-      logger().error("AdminSocket::execute_command: "
-                     "failed to validate '{}': {}", cmd, os.str());
+      ERROR("failed to validate '{}': {}", cmd, os.str());
       ceph::bufferlist out;
       out.append(os);
       return seastar::make_ready_future<tell_result_t>(
         tell_result_t{-EINVAL, "invalid command json", std::move(out)});
     }
+    DEBUG("validated {} {}", cmd, os.str());
     return parsed->hook.call(parsed->params, parsed->format, std::move(buf));
   } else {
+    DEBUG("failed to parse");
     auto& result = std::get<tell_result_t>(maybe_parsed);
     return seastar::make_ready_future<tell_result_t>(std::move(result));
   }
@@ -188,17 +201,21 @@ struct line_consumer {
     typename seastar::input_stream<char>::consumption_result_type;
 
   seastar::future<consumption_result_type> operator()(tmp_buf&& buf) {
+    LOG_PREFIX(line_consumer::operator());
+    INFO("");
     size_t consumed = 0;
     for (auto c : buf) {
       consumed++;
       if (c == '\0') {
        buf.trim_front(consumed);
+       INFO("stop consuming");
        return seastar::make_ready_future<consumption_result_type>(
          consumption_result_type::stop_consuming_type(std::move(buf)));
       } else {
        line.push_back(c);
       }
     }
+    INFO("continue consuming");
     return seastar::make_ready_future<consumption_result_type>(
       seastar::continue_consuming{});
   }
@@ -208,77 +225,90 @@ struct line_consumer {
 seastar::future<> AdminSocket::handle_client(seastar::input_stream<char>& in,
                                              seastar::output_stream<char>& out)
 {
+  LOG_PREFIX(AdminSocket::handle_client);
+  INFO("");
   auto consumer = seastar::make_shared<line_consumer>();
-  return in.consume(*consumer).then([consumer, &out, this] {
-    logger().debug("AdminSocket::handle_client: incoming asok string: {}",
-                   consumer->line);
+  return in.consume(*consumer).then([FNAME, consumer, &out, this] {
+    DEBUG("incoming asok string: {}", consumer->line);
     return execute_line(consumer->line, out);
-  }).then([&out] {
+  }).then([FNAME, &out] {
+    DEBUG("flush");
     return out.flush();
-  }).finally([&out] {
+  }).finally([FNAME, &out] {
+    DEBUG("out close");
     return out.close();
-  }).then([&in] {
+  }).then([FNAME, &in] {
+    DEBUG("in close");
     return in.close();
-  }).handle_exception([](auto ep) {
-    logger().debug("exception on {}: {}", __func__, ep);
+  }).handle_exception([FNAME](auto ep) {
+    ERROR("exception on {}", ep);
   });
 }
 
 seastar::future<> AdminSocket::start(const std::string& path)
 {
+  LOG_PREFIX(AdminSocket::start);
+  INFO("");
   if (path.empty()) {
-    logger().error(
-      "{}: Admin Socket socket path missing from the configuration", __func__);
+    ERROR("socket path missing from the configuration");
     return seastar::now();
   }
 
-  logger().debug("{}: asok socket path={}", __func__, path);
+  DEBUG("asok socket path={}", path);
   auto sock_path = seastar::socket_address{ seastar::unix_domain_addr{ path } };
   try {
     server_sock = seastar::engine().listen(sock_path);
   } catch (const std::system_error& e) {
     if (e.code() == std::errc::address_in_use) {
-      logger().debug("{}: Admin Socket socket path={} already exists, retrying",
-                     __func__, path);
-      return seastar::remove_file(path).then([this, path] {
+      DEBUG("socket path={} already exists, retrying", path);
+      return seastar::remove_file(path).then([FNAME, this, path] {
+        DEBUG("socket path={} retrying", path);
         server_sock.reset();
         return start(path);
       });
     }
-    logger().error("{}: unable to listen({}): {}", __func__, path, e.what());
+    ERROR("unable to listen({}): {}", path, e.what());
     server_sock.reset();
     return seastar::make_ready_future<>();
   }
   // listen in background
-  task = seastar::keep_doing([this] {
-    return seastar::try_with_gate(stop_gate, [this] {
-      assert(!connected_sock.has_value());
-      return server_sock->accept().then([this](seastar::accept_result acc) {
+  task = seastar::keep_doing([FNAME, this] {
+    return seastar::try_with_gate(stop_gate, [FNAME, this] {
+      ceph_assert(!connected_sock.has_value());
+      return server_sock->accept().then([FNAME, this](seastar::accept_result acc) {
         connected_sock = std::move(acc.connection);
         return seastar::do_with(connected_sock->input(),
                                 connected_sock->output(),
-          [this](auto& input, auto& output) mutable {
+          [FNAME, this](auto& input, auto& output) mutable {
+          DEBUG("handling client");
           return handle_client(input, output);
-        }).finally([this] {
-          assert(connected_sock.has_value());
+        }).finally([FNAME, this] {
+          DEBUG("reset");
+          ceph_assert(connected_sock.has_value());
           connected_sock.reset();
         });
-      }).handle_exception([this](auto ep) {
+      }).handle_exception([FNAME, this](auto ep) {
         if (!stop_gate.is_closed()) {
-          logger().error("AdminSocket: terminated: {}", ep);
+          ERROR("terminated: {}", ep);
         }
       });
     });
-  }).handle_exception_type([](const seastar::gate_closed_exception&) {
-  }).finally([path] {
+  }).handle_exception_type([FNAME](const seastar::gate_closed_exception&) {
+    DEBUG("gate closed");
+  }).finally([FNAME, path] {
+    DEBUG("closing: {}", path);
     return seastar::remove_file(path);
   });
+  DEBUG("exisited, listening in background");
   return seastar::make_ready_future<>();
 }
 
 seastar::future<> AdminSocket::stop()
 {
+  LOG_PREFIX(AdminSocket::stop);
+  INFO("");
   if (!server_sock) {
+    DEBUG("no server socket");
     return seastar::now();
   }
   server_sock->abort_accept();
@@ -286,10 +316,10 @@ seastar::future<> AdminSocket::stop()
     connected_sock->shutdown_input();
     connected_sock->shutdown_output();
   }
-  return stop_gate.close().then([this] {
-    assert(task.has_value());
-    return task->then([] {
-      logger().info("AdminSocket: stopped");
+  return stop_gate.close().then([FNAME, this] {
+    ceph_assert(task.has_value());
+    return task->then([FNAME] {
+      INFO("stopped");
       return seastar::now();
     });
   });
@@ -308,6 +338,8 @@ class VersionHook final : public AdminSocketHook {
                                      std::string_view format,
                                      ceph::bufferlist&&) const final
   {
+    LOG_PREFIX(AdminSocket::VersionHook);
+    INFO("");
     unique_ptr<Formatter> f{Formatter::create(format, "json-pretty", "json-pretty")};
     f->open_object_section("version");
     f->dump_string("version", ceph_version_to_str());
@@ -331,6 +363,8 @@ class GitVersionHook final : public AdminSocketHook {
                                      std::string_view format,
                                      ceph::bufferlist&&) const final
   {
+    LOG_PREFIX(AdminSocket::AdminSocketHook);
+    INFO("");
     unique_ptr<Formatter> f{Formatter::create(format, "json-pretty", "json-pretty")};
     f->open_object_section("version");
     f->dump_string("git_version", git_version_to_str());
@@ -352,6 +386,8 @@ class HelpHook final : public AdminSocketHook {
                                      std::string_view format,
                                      ceph::bufferlist&&) const final
   {
+    LOG_PREFIX(AdminSocket::HelpHook);
+    INFO("");
     unique_ptr<Formatter> f{Formatter::create(format,
                                              "json-pretty", "json-pretty")};
     f->open_object_section("help");
@@ -379,6 +415,8 @@ class GetdescsHook final : public AdminSocketHook {
                                      std::string_view format,
                                      ceph::bufferlist&&) const final
   {
+    LOG_PREFIX(AdminSocket::GetdescsHook);
+    INFO("");
     unique_ptr<Formatter> f{Formatter::create(format, "json-pretty", "json-pretty")};
     int cmdnum = 0;
     f->open_object_section("command_descriptions");
@@ -405,6 +443,8 @@ public:
                                      std::string_view format,
                                      ceph::bufferlist&&) const final
   {
+    LOG_PREFIX(AdminSocket::InjectArgsHook);
+    INFO("");
     std::vector<std::string> argv;
     if (!cmd_getval(cmdmap, "injected_args", argv)) {
       return seastar::make_ready_future<tell_result_t>();
@@ -433,6 +473,8 @@ public:
                                       std::string_view format,
                                       ceph::bufferlist&& input) const final
   {
+    LOG_PREFIX(AdminSocket::ConfigShowHook);
+    INFO("");
     unique_ptr<Formatter> f{Formatter::create(format, "json-pretty", "json-pretty")};
     f->open_object_section("config_show");
     local_conf().show_config(f.get());
@@ -455,9 +497,11 @@ public:
                                       std::string_view format,
                                       ceph::bufferlist&& input) const final
   {
+    LOG_PREFIX(AdminSocket::ConfigGetHook);
+    INFO("");
     std::string var;
     [[maybe_unused]] bool found = cmd_getval(cmdmap, "var", var);
-    assert(found);
+    ceph_assert(found);
     std::string conf_val;
     if (int r = local_conf().get_val(var, &conf_val); r < 0) {
       return seastar::make_ready_future<tell_result_t>(
@@ -490,6 +534,8 @@ public:
                                       std::string_view format,
                                       ceph::bufferlist&&) const final
   {
+    LOG_PREFIX(AdminSocket::ConfigSetHook);
+    INFO("");
     std::string var;
     std::vector<std::string> new_val;
     cmd_getval(cmdmap, "var", var);
@@ -523,6 +569,8 @@ public:
                                       std::string_view format,
                                       ceph::bufferlist&& input) const final
   {
+    LOG_PREFIX(AdminSocket::ConfigHelpHook);
+    INFO("");
     unique_ptr<Formatter> f{Formatter::create(format, "json-pretty", "json-pretty")};
     // Output all
     f->open_array_section("options");