NVMe: use phosphor-logging/lg2 for logging
Inspired by https://gerrit.openbmc.org/c/openbmc/dbus-sensors/+/78412.
Using lg2 for nvmed logging.
Also, utilize log level to concise the log printing.
* using lg2::warning for all retries
* using lg2::error for errors
* using lg2::info for the state transition info
* using lg2::debug for all debug related stuff
Fix some minor issue which was not detected by std::cerr.
Tested: journal log: https://paste.googleplex.com/6575901127081984
Change-Id: Ia14236654c2b12034e3d087ca84a5168c62106ea
Signed-off-by: Hao Jiang <jianghao@google.com>
diff --git a/src/NVMeBasic.cpp b/src/NVMeBasic.cpp
index de71423..f8fca8b 100644
--- a/src/NVMeBasic.cpp
+++ b/src/NVMeBasic.cpp
@@ -7,6 +7,7 @@
#include <boost/asio/read.hpp>
#include <boost/asio/streambuf.hpp>
#include <boost/asio/write.hpp>
+#include <phosphor-logging/lg2.hpp>
#include <iostream>
#include <map>
@@ -72,9 +73,9 @@
// NOLINTNEXTLINE(cppcoreguidelines-pro-type-vararg)
if (::ioctl(fileHandle.handle(), I2C_SLAVE, addr) == -1)
{
- std::cerr << "Failed to configure device address 0x" << std::hex
- << (int)addr << " for bus " << std::dec << bus << ": "
- << strerror(errno) << "\n";
+ lg2::error(
+ "Failed to configure device address '{ADDR}' for bus '{BUS}': ERRNO",
+ "ADDR", lg2::hex, addr, "BUS", bus, "ERRNO", lg2::hex, errno);
resp.resize(0);
return;
}
@@ -85,16 +86,17 @@
size = i2c_smbus_read_block_data(fileHandle.handle(), cmd, resp.data());
if (size < 0)
{
- std::cerr << "Failed to read block data from device 0x" << std::hex
- << (int)addr << " on bus " << std::dec << bus << ": "
- << strerror(errno) << "\n";
+ lg2::error(
+ "Failed to read block data from device '{ADDR}' on bus '{BUS}': ERRNO",
+ "ADDR", lg2::hex, addr, "BUS", bus, "ERRNO", lg2::hex, errno);
resp.resize(0);
}
else if (size > UINT8_MAX + 1)
{
- std::cerr << "Unexpected message length from device 0x" << std::hex
- << (int)addr << " on bus " << std::dec << bus << ": "
- << size << " (" << UINT8_MAX << ")\n";
+ lg2::error(
+ "Unexpected message length from device '{ADDR}' on bus '{BUS}': '{SIZE}' ({MAX})",
+ "ADDR", lg2::hex, addr, "BUS", bus, "SIZE", size, "MAX",
+ UINT8_MAX);
resp.resize(0);
}
else
@@ -104,8 +106,8 @@
}
catch (const std::out_of_range& e)
{
- std::cerr << "Failed to create file handle for bus " << std::dec << bus
- << ": " << e.what() << "\n";
+ lg2::error("Failed to create file handle for bus '{BUS}': '{ERR}'",
+ "BUS", bus, "ERR", e);
resp.resize(0);
}
}
@@ -129,8 +131,9 @@
ssize_t rc = ::read(in.handle(), req.data(), req.size());
if (rc != static_cast<ssize_t>(req.size()))
{
- std::cerr << "Failed to read request from in descriptor "
- << strerror(errno) << "\n";
+ lg2::error(
+ "Failed to read request from in descriptor '{ERROR_MESSAGE}'",
+ "ERROR_MESSAGE", strerror(errno));
if (rc != 0)
{
return -errno;
@@ -148,9 +151,9 @@
rc = ::write(out.handle(), &len, sizeof(len));
if (rc != sizeof(len))
{
- std::cerr << "Failed to write block (" << std::dec << len
- << ") length to out descriptor: "
- << strerror(static_cast<int>(-rc)) << "\n";
+ lg2::error(
+ "Failed to write block ({LEN}) length to out descriptor: '{ERRNO}'",
+ "LEN", len, "ERRNO", strerror(static_cast<int>(-rc)));
if (rc != 0)
{
return -errno;
@@ -166,9 +169,9 @@
ssize_t egress = ::write(out.handle(), &(*cursor), lenRemaining);
if (egress == -1)
{
- std::cerr << "Failed to write block data of length " << std::dec
- << lenRemaining << " to out pipe: " << strerror(errno)
- << "\n";
+ lg2::error(
+ "Failed to write block data of length '{LEN}' to out pipe: '{ERROR_MESSAGE}'",
+ "LEN", lenRemaining, "ERROR_MESSAGE", strerror(errno));
if (rc != 0)
{
return -errno;
@@ -194,26 +197,26 @@
/* Set up inter-thread communication */
if (::pipe(requestPipe.data()) == -1)
{
- std::cerr << "Failed to create request pipe: " << strerror(errno)
- << "\n";
+ lg2::error("Failed to create request pipe: '{ERROR}'", "ERROR",
+ strerror(errno));
throw std::error_code(errno, std::system_category());
}
if (::pipe(responsePipe.data()) == -1)
{
- std::cerr << "Failed to create response pipe: " << strerror(errno)
- << "\n";
+ lg2::error("Failed to create response pipe: '{ERROR}'", "ERROR",
+ strerror(errno));
if (::close(requestPipe[0]) == -1)
{
- std::cerr << "Failed to close write fd of request pipe: "
- << strerror(errno) << "\n";
+ lg2::error("Failed to close write fd of request pipe '{ERROR}'",
+ "ERROR", strerror(errno));
}
if (::close(requestPipe[1]) == -1)
{
- std::cerr << "Failed to close read fd of request pipe: "
- << strerror(errno) << "\n";
+ lg2::error("Failed to close read fd of request pipe '{ERROR}'",
+ "ERROR", strerror(errno));
}
throw std::error_code(errno, std::system_category());
@@ -231,11 +234,11 @@
if ((rc = procFunc(streamIn, streamOut)) < 0)
{
- std::cerr << "Failure while processing query stream: "
- << strerror(static_cast<int>(-rc)) << "\n";
+ lg2::error("Failure while processing query stream: '{ERROR}'",
+ "ERROR", strerror(static_cast<int>(-rc)));
}
- std::cerr << "Terminating basic query thread\n";
+ lg2::error("Terminating basic query thread");
});
}
@@ -269,7 +272,8 @@
[command](boost::system::error_code ec, std::size_t) {
if (ec)
{
- std::cerr << "Got error writing basic query: " << ec << "\n";
+ lg2::error("Got error writing basic query: '{ERROR_MESSAGE}'",
+ "ERROR_MESSAGE", ec.message());
}
});
@@ -282,7 +286,8 @@
[response](const boost::system::error_code& ec, std::size_t n) {
if (ec)
{
- std::cerr << "Got error completing basic query: " << ec << "\n";
+ lg2::error("Got error completing basic query: '{ERROR_MESSAGE}'",
+ "ERROR_MESSAGE", ec.message());
return static_cast<std::size_t>(0);
}
@@ -296,8 +301,9 @@
if (n > len + 1)
{
- std::cerr << "Query stream has become unsynchronised: " << "n: "
- << n << ", " << "len: " << len << "\n";
+ lg2::error(
+ "Query stream has become unsynchronised: n: {N}, len: {LEN}",
+ "N", n, "LEN", len);
return static_cast<std::size_t>(0);
}
@@ -318,7 +324,8 @@
const boost::system::error_code& ec, std::size_t length) mutable {
if (ec)
{
- std::cerr << "Got error reading basic query: " << ec << "\n";
+ lg2::error("Got error reading basic query: '{ERROR_MESSAGE}'",
+ "ERROR_MESSAGE", ec.message());
boost::asio::post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::io_error), nullptr);
});
@@ -327,7 +334,7 @@
if (length == 0)
{
- std::cerr << "Invalid message length: " << length << "\n";
+ lg2::error("Invalid message length: '{LEN}'", "LEN", length);
return;
}
diff --git a/src/NVMeCache.hpp b/src/NVMeCache.hpp
index d1869ef..bf8e538 100644
--- a/src/NVMeCache.hpp
+++ b/src/NVMeCache.hpp
@@ -1,9 +1,10 @@
#pragma once
#include <boost/asio/steady_timer.hpp>
+#include <phosphor-logging/lg2.hpp>
#include <chrono>
+#include <format>
#include <functional>
-#include <iostream>
#include <memory>
#include <set>
#include <vector>
@@ -215,8 +216,7 @@
auto metric = itr->second.lock();
if (!metric)
{
- // LOG_INFO
- std::cerr << "the task is invalid, removed from task queue\n";
+ lg2::info("the task is invalid, removed from task queue");
itr = taskQueue.erase(itr);
}
else if (!metric.owner_before(task) &&
@@ -256,8 +256,7 @@
weakFlag](boost::system::error_code ec) {
if (ec || weakFlag.expired())
{
- // LOG_INFO
- std::cerr << "new expiration time set\n";
+ lg2::info("new expiration time set");
return;
}
@@ -265,8 +264,7 @@
if (!self)
{
- // LOG_INFO
- std::cerr << "the scheduler has stopped\n";
+ lg2::info("the scheduler has stopped");
return;
}
@@ -275,8 +273,7 @@
auto task = weakTask.lock();
if (!task)
{
- // LOG_INFO
- std::cerr << "the task is invalid, removed from task queue\n";
+ lg2::info("the task is invalid, removed from task queue");
self->dequeue();
return;
}
@@ -290,7 +287,7 @@
std::shared_ptr<MetricBase<ClockType_>> task = weakTask.lock();
if (!task)
{
- std::cerr << "the task is invalid, removed from task queue\n";
+ lg2::info("the task is invalid, removed from task queue");
self->executingTask.reset();
self->dequeue();
return;
diff --git a/src/NVMeCacheImpl.hpp b/src/NVMeCacheImpl.hpp
index 0f5968f..51252f9 100644
--- a/src/NVMeCacheImpl.hpp
+++ b/src/NVMeCacheImpl.hpp
@@ -100,9 +100,8 @@
ControllerLogPageMetric<LID, ClockType>>(weakSelf.lock());
if (!self)
{
- // TODO: error_level = INFO
- std::cerr << std::format(
- "[{}, {}]metric released before callback\n", path, id);
+ lg2::info("metric released before callback", "PATH", path, "ID",
+ id);
// The Scheduler will clear the invalid cache Task
cb({}, 4096, true);
return;
@@ -112,19 +111,17 @@
if (self->errorCount <
ControllerLogPageMetric<LID, ClockType>::errorCountMax)
{
- // TODO: error_level = WARN
- std::cerr << std::format(
- "[{}, {}]fail to fresh log page at retry({})\n", path,
- id, self->errorCount++);
+ lg2::warning("fail to fresh log page at retry({RETRY})",
+ "PATH", path, "ID", id, "RETRY",
+ self->errorCount++);
// Schedule the retry after 1s
// TODO: costomize the retry delay for each log pages.
cb(std::make_error_code(std::errc::io_error), 4096, false);
return;
}
-
- std::cerr << std::format(
- "[{}, {}]retry exhausted to fresh log page\n", path, id);
+ lg2::error("retry exhausted to fresh log page", "PATH", path,
+ "ID", id);
self->cacheValid = false;
// Notify the RefreshCB with error code; the task will
@@ -247,9 +244,8 @@
weakSelf.lock());
if (!self)
{
- // TODO: error_level = INFO
- std::cerr << std::format(
- "[{}, {}]metric released before callback\n", path, id);
+ lg2::info("metric released before callback", "PATH", path, "ID",
+ id);
// The Scheduler will clear the invalid cache Task
cb({}, 4096, true);
return;
@@ -259,18 +255,17 @@
if (self->errorCount <
IdentifyMetric<CNS, ClockType>::errorCountMax)
{
- // TODO: error_level = WARN
- std::cerr << std::format(
- "[{}, {}]fail to fresh identify at retry({}): {}\n",
- path, id, self->errorCount++, ex->description());
+ lg2::warning(
+ "fail to fresh identify at retry({RETRY}): {ERROR}",
+ "PATH", path, "ID", id, "RETRY", self->errorCount++,
+ "ERROR", ex->description());
// Schedule the retry after 1s
cb(std::make_error_code(std::errc::io_error), 4096, false);
return;
}
- std::cerr << std::format(
- "[{}, {}]retry exhausted to fresh identify: {}\n", path, id,
- ex->description());
+ lg2::error("retry exhausted to fresh identify: {ERROR}", "PATH",
+ path, "ID", id, "ERROR", ex->description());
self->cacheValid = false;
// Notify the RefreshCB with error code; the task will
diff --git a/src/NVMeController.cpp b/src/NVMeController.cpp
index 427b484..881f225 100644
--- a/src/NVMeController.cpp
+++ b/src/NVMeController.cpp
@@ -8,6 +8,7 @@
#include "NVMePlugin.hpp"
#include "NVMeSubsys.hpp"
+#include <phosphor-logging/lg2.hpp>
#include <sdbusplus/exception.hpp>
#include <sdbusplus/message/native_types.hpp>
#include <xyz/openbmc_project/Common/File/error.hpp>
@@ -16,7 +17,6 @@
#include <cstdio>
#include <filesystem>
#include <fstream>
-#include <iostream>
// using sdbusplus::xyz::openbmc_project::Inventory::Item::server::
// StorageController;
@@ -81,7 +81,7 @@
if (self->status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
return self->adminNonDataCmdMethod(std::move(yield), opcode, cdw1, cdw2,
@@ -106,7 +106,7 @@
if (self->status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -128,7 +128,7 @@
if (self->status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -154,7 +154,7 @@
if (self->status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -174,7 +174,7 @@
if (self->status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -308,7 +308,7 @@
auto s = subsys.lock();
if (!s)
{
- std::cerr << "makeAssociation() after shutdown\n";
+ lg2::error("makeAssociation() after shutdown");
return associations;
}
@@ -335,15 +335,15 @@
{
if (status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
std::array<int, 2> pipe{};
if (::pipe(pipe.data()) < 0)
{
- std::cerr << "GetLogPage fails to open pipe: " << std::strerror(errno)
- << '\n';
+ lg2::error("GetLogPage fails to open pipe: {ERROR}", "ERROR",
+ strerror(errno));
throw sdbusplus::xyz::openbmc_project::Common::File::Error::Open();
}
@@ -356,7 +356,8 @@
std::span<uint8_t> data) {
if (ec)
{
- std::cerr << "fail to GetLogPage: " << ec.message() << '\n';
+ lg2::error("fail to GetLogPage: {ERROR}", "ERROR",
+ ec.message());
close(pipe[1]);
close(pipe[0]);
return;
@@ -377,9 +378,8 @@
std::size_t /* transferredSize */) {
if (error)
{
- std::cerr
- << "GetLogPage fails to write fd: " << error.message()
- << '\n';
+ lg2::error("GetLogPage fails to write fd: {ERROR}", "ERROR",
+ error.message());
}
});
@@ -409,7 +409,8 @@
std::span<uint8_t> data) {
if (ec)
{
- std::cerr << "fail to GetLogPage: " << ec.message() << '\n';
+ lg2::error("fail to GetLogPage: {ERROR}", "ERROR",
+ ec.message());
close(pipe[1]);
close(pipe[0]);
return;
@@ -431,8 +432,8 @@
std::size_t /* transferredSize */) {
if (error)
{
- std::cerr << "GetLogPage fails to write fd: "
- << error.message() << '\n';
+ lg2::error("GetLogPage fails to write fd: {ERROR}",
+ "ERROR", error.message());
}
});
@@ -474,15 +475,15 @@
{
if (status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
std::array<int, 2> pipe{};
if (::pipe(pipe.data()) < 0)
{
- std::cerr << "Identify fails to open pipe: " << std::strerror(errno)
- << '\n';
+ lg2::error("Identify fails to open pipe: {ERROR}", "ERROR",
+ strerror(errno));
throw sdbusplus::xyz::openbmc_project::Common::File::Error::Open();
}
@@ -491,7 +492,7 @@
[pipe, &io = this->io](const nvme_ex_ptr& ex, std::span<uint8_t> data) {
if (ex)
{
- std::cerr << "fail to Identify: " << ex << '\n';
+ lg2::error("fail to Identify: {ERROR}", "ERROR", ex->what());
close(pipe[1]);
close(pipe[0]);
return;
@@ -512,8 +513,8 @@
std::size_t /* transferredSize */) {
if (error)
{
- std::cerr << "Identify fails to write fd: " << error.message()
- << '\n';
+ lg2::error("Identify fails to write fd: {ERROR}", "ERROR",
+ error.message());
}
});
@@ -558,7 +559,7 @@
if (status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -684,7 +685,7 @@
{
if (status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -714,7 +715,7 @@
{
if (status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -765,8 +766,8 @@
},
yield);
- std::cerr << "nvme_status:" << nvmeStatus << ", dw0:" << completionDw0
- << '\n';
+ lg2::debug("nvme_status:{STATUS}, dw0:{DW0}", "STATUS", nvmeStatus, "DW0",
+ completionDw0);
if (nvmeStatus < 0)
{
throw sdbusplus::exception::SdBusError(err.value(),
@@ -797,7 +798,7 @@
{
if (status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -844,7 +845,7 @@
}
catch (const std::exception& e)
{
- std::cerr << e.what() << '\n';
+ lg2::error("{ERROR}", "ERROR", e.what());
throw sdbusplus::xyz::openbmc_project::Common::Error::
InternalFailure();
}
@@ -859,7 +860,7 @@
{
if (status != Status::Enabled)
{
- std::cerr << "Controller has been disabled" << '\n';
+ lg2::error("Controller has been disabled");
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
@@ -906,7 +907,7 @@
}
catch (const std::exception& e)
{
- std::cerr << e.what() << '\n';
+ lg2::error("{ERROR}", "ERROR", e.what());
throw sdbusplus::xyz::openbmc_project::Common::Error::
InternalFailure();
}
diff --git a/src/NVMeDrive.cpp b/src/NVMeDrive.cpp
index 48bb6c1..d022961 100644
--- a/src/NVMeDrive.cpp
+++ b/src/NVMeDrive.cpp
@@ -3,7 +3,7 @@
#include "NVMeError.hpp"
#include "NVMeSubsys.hpp"
-#include <iostream>
+#include <phosphor-logging/lg2.hpp>
namespace common_err = sdbusplus::xyz::openbmc_project::Common::Error;
@@ -118,8 +118,8 @@
(void)scdw10;
if (ex)
{
- std::cerr << "Error returned reading sanitize log: " << ex
- << '\n';
+ lg2::error("Error returned reading sanitize log: {ERROR}",
+ "ERROR", ex->what());
}
else
{
diff --git a/src/NVMeError.cpp b/src/NVMeError.cpp
index eda98de..85e4ea5 100644
--- a/src/NVMeError.cpp
+++ b/src/NVMeError.cpp
@@ -2,6 +2,7 @@
#include <libnvme-mi.h>
+#include <phosphor-logging/lg2.hpp>
#include <xyz/openbmc_project/Common/Device/error.hpp>
#include <xyz/openbmc_project/Common/error.hpp>
@@ -177,7 +178,8 @@
if (nvmeStatus < 0)
{
auto desc = std::string("libnvme error: ") + err.message();
- std::cerr << methodName << ":" << desc << '\n';
+ lg2::error("{METHOD}: {DESC}", "METHOD", methodName, "DESC",
+ desc.c_str());
return std::make_shared<NVMeSdBusPlusError>(desc);
}
if (nvmeStatus > 0)
@@ -196,11 +198,11 @@
translateLibNVMeMI(val, desc, specific);
break;
default:
- std::cerr << "Unknown libnvme error status " << nvmeStatus
- << '\n';
+ lg2::error("Unknown libnvme error status {STATUS}", "STATUS",
+ nvmeStatus);
desc = "Unknown libnvme error";
}
- std::cerr << methodName << ":" << desc << '\n';
+ lg2::error("{METHOD}: {DESC}", "METHOD", methodName, "DESC", desc);
return std::make_shared<NVMeSdBusPlusError>(desc, specific);
}
// No Error
diff --git a/src/NVMeMetricStore.cpp b/src/NVMeMetricStore.cpp
index d3f577f..ff39271 100644
--- a/src/NVMeMetricStore.cpp
+++ b/src/NVMeMetricStore.cpp
@@ -1,5 +1,6 @@
#include "NVMeMetricStore.hpp"
+#include <phosphor-logging/lg2.hpp>
#include <xyz/openbmc_project/Common/File/error.hpp>
#include <xyz/openbmc_project/Common/error.hpp>
@@ -10,8 +11,8 @@
std::array<int, 2> pipe{};
if (::pipe(pipe.data()) < 0)
{
- std::cerr << "Metric Fetcher failed due to pipe creation "
- << std::strerror(errno) << "\n";
+ lg2::error("Metric Fetcher failed due to pipe creation: {ERROR}",
+ "ERROR", strerror(errno));
throw sdbusplus::xyz::openbmc_project::Common::File::Error::Open{};
}
@@ -29,8 +30,8 @@
std::size_t /* transferredSize */) {
if (error)
{
- std::cerr << "Metric Fetcher fails to write fd: " << error.message()
- << "\n";
+ lg2::error("Metric Fetcher fails to write fd: {ERROR}", "ERROR",
+ error.message());
}
});
@@ -57,15 +58,15 @@
auto it = metricStore.find(name);
if (it == metricStore.end() || !it->second)
{
- std::cerr << std::format("[{}, {}]cannot find the target Metric",
- this->path, name);
+ lg2::error("Cannot find the target Metric", "PATH", this->path, "NAME",
+ name);
throw sdbusplus::xyz::openbmc_project::Common::Error::InvalidArgument{};
}
if (!it->second->isCacheValid())
{
- std::cerr << std::format("[{}, {}]the Metric cache is invalid",
- this->path, name);
+ lg2::error("The Metric cache is invalid", "PATH", this->path, "NAME",
+ name);
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable{};
}
auto data = it->second->getCache();
diff --git a/src/NVMeMetricStore.hpp b/src/NVMeMetricStore.hpp
index 607108b..1d22c39 100644
--- a/src/NVMeMetricStore.hpp
+++ b/src/NVMeMetricStore.hpp
@@ -18,7 +18,6 @@
#include <xyz/openbmc_project/NVMe/MetricStore/server.hpp>
#include <functional>
-#include <iostream>
#include <memory>
#include <string>
#include <tuple>
@@ -71,9 +70,8 @@
std::string{metric->getIdentifier()}, std::move(metric));
if (!res)
{
- std::cerr << std::format(
- "[{}, {}] drop a duplicated vendor metic\n", path,
- itr->first);
+ lg2::warning("drop a duplicated vendor metic", "PATH", path,
+ "METRIC", itr->first);
}
}
@@ -89,10 +87,9 @@
// use validFlag to protect this call
if (weakFlag.expired())
{
- // TODO: log_level = INFO
- std::cerr << std::format(
- "[{}]MetricStore interface expired, update signal skipped.\n",
- path);
+ lg2::info("MetricStore interface expired, update signal "
+ "skipped.",
+ "PATH", path);
return;
}
auto metric = weakMetric.lock();
diff --git a/src/NVMeMi.cpp b/src/NVMeMi.cpp
index 32162ae..46cbd94 100644
--- a/src/NVMeMi.cpp
+++ b/src/NVMeMi.cpp
@@ -6,11 +6,11 @@
#include <endian.h>
#include <boost/endian.hpp>
+#include <phosphor-logging/lg2.hpp>
#include <cassert>
#include <cerrno>
#include <fstream>
-#include <iostream>
#include <stdexcept>
namespace common_err = sdbusplus::xyz::openbmc_project::Common::Error;
@@ -63,9 +63,8 @@
case Status::Initiated:
if (optimizeTimer)
{
- std::cerr << "[" << endpoint->describe() << "]"
- << "Cancel the optimization Timer for the endpoint"
- << '\n';
+ lg2::info("Cancel the optimization Timer for the endpoint",
+ "ENDPOINT", endpoint->describe());
optimizeTimer->cancel();
}
[[fallthrough]];
@@ -76,8 +75,7 @@
"nvmeEP was unpopulated in Status::Initiated state");
}
mctpStatus = Status::Terminating;
- std::cerr << "[" << endpoint->describe() << "]"
- << "start MCTP closure" << '\n';
+ lg2::info("start MCTP closure", "ENDPOINT", endpoint->describe());
// Immediately reset endpoint so that we can capture the parameter
// from a subsequent invocation of start() while in
// Status::Terminating
@@ -91,8 +89,8 @@
self->mtu = 64;
self->nvmeEP = nullptr;
self->mctpStatus = Status::Reset;
- std::cerr << "[" << self->device->describe() << "] "
- << "end MCTP closure" << '\n';
+ lg2::info("end MCTP closure", "DEVICE",
+ self->device->describe());
if (self->restart)
{
// If restart is true then we've captured the updated
@@ -165,7 +163,8 @@
optimizeTimer->async_wait([this](boost::system::error_code ec) {
if (ec)
{
- std::cerr << "Endpoint optimize timer error " << ec << '\n';
+ lg2::error("Endpoint optimize timer error: {ERROR}", "ERROR",
+ ec.what());
return;
}
miSetMCTPConfiguration(
@@ -173,9 +172,8 @@
self->optimizeTimer = nullptr;
if (ec)
{
- std::cerr << "[" << self->device->describe() << "]"
- << "Failed setting up MTU for the MCTP endpoint."
- << '\n';
+ lg2::error("Failed setting up MTU for the MCTP endpoint.",
+ "DEVICE", self->device->describe());
self->recover();
return;
}
@@ -223,8 +221,7 @@
if (!epConnect(endpoint->network(), endpoint->eid()))
{
epReset();
- std::cerr << "[" << ep->describe() << "]"
- << "can't open MCTP endpoint " << '\n';
+ lg2::error("can't open MCTP endpoint", "ENDPOINT", ep->describe());
return;
}
}
@@ -344,7 +341,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << device->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "DEVICE", device->describe(), "ERROR", e.what());
return std::make_error_code(std::errc::no_such_device);
}
return {};
@@ -356,8 +353,7 @@
{
if (mctpStatus == Status::Reset || mctpStatus == Status::Terminating)
{
- std::cerr << "[" << device->describe() << "]"
- << "nvme endpoint is invalid" << '\n';
+ lg2::error("nvme endpoint is invalid", "DEVICE", device->describe());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device));
});
@@ -372,19 +368,19 @@
&smbusFreq);
if (rc != 0)
{
- std::cerr << "[" << ep->describe()
- << "] failed to get the SMBus frequency " << '\n';
+ lg2::error("failed to get the SMBus frequency", "ENDPOINT",
+ ep->describe());
}
else if (smbusFreq == NVME_MI_CONFIG_SMBUS_FREQ_100kHz)
{
- std::cerr << "[" << ep->describe()
- << "] Setting the SMBus frequency to 400kHz\n";
+ lg2::info("Setting the SMBus frequency to 400kHz", "ENDPOINT",
+ ep->describe());
rc = nvme_mi_mi_config_set_smbus_freq(
self->nvmeEP, portId, NVME_MI_CONFIG_SMBUS_FREQ_400kHz);
if (rc != 0)
{
- std::cerr << "[" << ep->describe()
- << "] failed to set the SMBus frequency\n";
+ lg2::error("failed to set the SMBus frequency", "ENDPOINT",
+ ep->describe());
}
}
if (rc != 0)
@@ -399,7 +395,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << device->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "DEVICE", device->describe(), "ERROR", e.what());
return;
}
}
@@ -410,8 +406,7 @@
{
if (mctpStatus == Status::Reset || mctpStatus == Status::Terminating)
{
- std::cerr << "[" << device->describe() << "] "
- << "nvme endpoint is invalid" << '\n';
+ lg2::error("nvme endpoint is invalid", "DEVICE", device->describe());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device));
});
@@ -428,9 +423,8 @@
if (rc != 0)
{
- std::cerr << "[" << self->device->describe() << "]"
- << " failed to set remote MCTP MTU for port :"
- << unsigned(port) << '\n';
+ lg2::error("failed to set remote MCTP MTU for port: {PORT}",
+ "DEVICE", self->device->describe(), "PORT", port);
self->io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::bad_message));
});
@@ -451,7 +445,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << device->describe() << "] " << e.what() << '\n';
+ lg2::error("{ERROR}", "DEVICE", device->describe(), "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device));
});
@@ -464,8 +458,7 @@
{
if (mctpStatus == Status::Reset || mctpStatus == Status::Terminating)
{
- std::cerr << "[" << device->describe() << "] "
- << "nvme endpoint is invalid" << '\n';
+ lg2::error("nvme endpoint is invalid", "DEVICE", device->describe());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device));
});
@@ -481,8 +474,8 @@
nvme_mi_ep_set_timeout(self->nvmeEP, timeout);
if (rc != 0)
{
- std::cerr << "[" << self->device->describe() << "] "
- << "Failed reading subsystem info failing " << '\n';
+ lg2::error("Failed reading subsystem info failing", "DEVICE",
+ self->device->describe());
self->io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::bad_message));
});
@@ -497,9 +490,9 @@
if (rc != 0)
{
/* PCIe port might not be ready right after AC/DC cycle. */
- std::cerr << "[" << self->device->describe()
- << "] failed reading port info for port_id: "
- << unsigned(portId) << '\n';
+ lg2::error("failed reading port info for port_id: {PORT}",
+ "DEVICE", self->device->describe(), "PORT",
+ portId);
}
else if (portInfo.portt == 0x2) // SMBus ports = 0x2
{
@@ -521,7 +514,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << device->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "DEVICE", device->describe(), "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device));
});
@@ -538,17 +531,16 @@
retries](const std::error_code& ec) mutable {
if (!endpoint)
{
- std::cerr << "[" << device->describe() << "] "
- << "failed to set MCTP path MTU: Status::Terminating"
- << '\n';
+ lg2::error("failed to set MCTP path MTU: Status::Terminating",
+ "DEVICE", device->describe());
cb(ec);
return;
}
if (!ec)
{
- std::cout << "[" << endpoint->describe() << "] "
- << "Finished MCTP initialization. MTU: " << mtu << '\n';
+ lg2::info("Finished MCTP initialization. MTU: {MTU}", "ENDPOINT",
+ endpoint->describe(), "MTU", mtu);
cb(ec);
return;
}
@@ -556,15 +548,14 @@
retries--;
if (retries == 0)
{
- std::cerr << "[" << endpoint->describe() << "] "
- << "failed to set MCTP path MTU: " << ec.message()
- << '\n';
+ lg2::error("failed to set MCTP path MTU: {ERROR}", "ENDPOINT",
+ endpoint->describe(), "ERROR", ec.message());
cb(ec);
return;
}
- std::cerr << "[" << endpoint->describe() << "] "
- << "retry to set MCTP path MTU" << '\n';
+ lg2::warning("retry to set MCTP path MTU", "ENDPOINT",
+ endpoint->describe());
configureLocalRouteMtu(std::move(cb), retries);
};
endpoint->setMtu(mctpMtu, std::move(retry));
@@ -576,8 +567,8 @@
{
if (auto degraded = isEndpointDegraded())
{
- std::cerr << "[" << device->describe() << "]"
- << " MCTP connection is not established" << '\n';
+ lg2::error("MCTP connection is not established", "DEVICE",
+ device->describe());
io.post([cb{std::move(cb)}, errc{degraded.value()}]() {
cb(errc, nullptr);
@@ -593,9 +584,9 @@
true, &ssHealth);
if (rc < 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << " fail to subsystem_health_status_poll: "
- << std::strerror(errno) << '\n';
+ lg2::error("fail to subsystem_health_status_poll: {ERROR}",
+ "ENDPOINT", ep->describe(), "ERROR",
+ strerror(errno));
self->io.post([cb{cb}, lastErrno{errno}]() mutable {
cb(std::make_error_code(static_cast<std::errc>(lastErrno)),
nullptr);
@@ -606,9 +597,8 @@
{
std::string_view errMsg =
statusToString(static_cast<nvme_mi_resp_status>(rc));
- std::cerr << "[" << ep->describe() << "]"
- << " fail to subsystem_health_status_poll: " << errMsg
- << '\n';
+ lg2::error("fail to subsystem_health_status_poll: {ERROR}",
+ "ENDPOINT", ep->describe(), "ERROR", errMsg.data());
self->io.post([cb{cb}]() mutable {
cb(std::make_error_code(std::errc::bad_message), nullptr);
});
@@ -621,7 +611,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << device->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "DEVICE", device->describe(), "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device), {});
});
@@ -635,8 +625,8 @@
{
if (auto degraded = isEndpointDegraded())
{
- std::cerr << "[" << device->describe() << "]"
- << " MCTP connection is not established" << '\n';
+ lg2::error("MCTP connection is not established", "DEVICE",
+ device->describe());
io.post(
[cb{std::move(cb)}, errc{degraded.value()}]() { cb(errc, {}); });
@@ -649,9 +639,8 @@
int rc = nvme_mi_scan_ep(self->nvmeEP, true);
if (rc < 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to scan controllers: "
- << std::strerror(errno) << '\n';
+ lg2::error("fail to scan controllers: {ERROR}", "ENDPOINT",
+ ep->describe(), "ERROR", strerror(errno));
self->io.post([cb{cb}, lastErrno{errno}]() mutable {
cb(std::make_error_code(static_cast<std::errc>(lastErrno)),
{});
@@ -662,8 +651,8 @@
{
std::string_view errMsg =
statusToString(static_cast<nvme_mi_resp_status>(rc));
- std::cerr << "[" << ep->describe() << "]"
- << "fail to scan controllers: " << errMsg << '\n';
+ lg2::error("fail to scan controllers: {ERROR}", "ENDPOINT",
+ ep->describe(), "ERROR", errMsg.data());
self->io.post([cb{cb}]() mutable {
cb(std::make_error_code(std::errc::bad_message), {});
});
@@ -682,7 +671,8 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << endpoint->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "ENDPOINT", endpoint->describe(), "ERROR",
+ e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device), {});
});
@@ -702,7 +692,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "Runtime error: " << e.what() << '\n';
+ lg2::error("Runtime error: {ERROR}", "ERROR", e.what());
return false;
}
}
@@ -713,8 +703,8 @@
{
if (auto degraded = isEndpointDegraded())
{
- std::cerr << "[" << device->describe() << "]"
- << " MCTP connection is not established" << '\n';
+ lg2::error("MCTP connection is not established", "DEVICE",
+ device->describe());
io.post([cb{std::move(cb)}, errc{degraded.value()}]() {
cb(makeLibNVMeError("nvme endpoint is degraded"), {});
});
@@ -770,23 +760,22 @@
if (rc < 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to do nvme identify: "
- << std::strerror(errno) << '\n';
+ lg2::error("fail to do nvme identify: {ERROR}", "ENDPOINT",
+ ep->describe(), "ERROR", strerror(errno));
}
else if (rc > 0)
{
std::string_view errMsg =
statusToString(static_cast<nvme_mi_resp_status>(rc));
- std::cerr << "[" << ep->describe() << "]"
- << "fail to do nvme identify: " << errMsg << '\n';
+ lg2::error("fail to do nvme identify: {ERROR}", "ENDPOINT",
+ ep->describe(), "ERROR", errMsg.data());
}
auto ex = makeLibNVMeError(errno, rc, "adminIdentify");
if (ex)
{
- std::cerr << "fail to do nvme identify: " << ex->description()
- << '\n';
+ lg2::error("fail to do nvme identify: {ERROR}", "ERROR",
+ ex->description());
}
self->io.post([cb{cb}, ex, data{std::move(data)}]() mutable {
@@ -797,9 +786,10 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << endpoint->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "ENDPOINT", endpoint->describe(), "ERROR",
+ e.what());
auto msg = std::string("Runtime error: ") + e.what();
- std::cerr << msg << '\n';
+ lg2::error("{MSG}", "MSG", msg);
io.post([cb{std::move(cb)}, msg]() { cb(makeLibNVMeError(msg), {}); });
return;
}
@@ -826,7 +816,7 @@
rc = nvme_mi_admin_get_log_create_telemetry_host(ctrl, &log);
if (rc != 0)
{
- std::cerr << "failed to create telemetry host log" << '\n';
+ lg2::error("failed to create telemetry host log");
return rc;
}
}
@@ -835,8 +825,8 @@
if (rc != 0)
{
- std::cerr << "failed to retain telemetry log for "
- << (host ? "host" : "ctrl") << '\n';
+ lg2::error("failed to retain telemetry log for {TYPE}", "TYPE",
+ [host] { return host ? "host" : "ctrl"; }());
return rc;
}
@@ -857,9 +847,10 @@
{
if (offset >= data.size())
{
- std::cerr << "[" << device->describe() << "]"
- << "get telemetry log: offset exceed the log size. "
- << "offset: " << offset << ", size: " << data.size() << '\n';
+ lg2::error(
+ "get telemetry log: offset exceed the log size. offset: {OFFSET}, size: {SIZE}",
+ "DEVICE", device->describe(), "OFFSET", offset, "SIZE",
+ data.size());
cb(std::make_error_code(std::errc::invalid_argument), {});
return;
}
@@ -884,9 +875,8 @@
if (rc < 0)
{
- std::cerr << "[" << self->device->describe() << "]"
- << "fail to get chunk for telemetry log: "
- << std::strerror(errno) << '\n';
+ lg2::error("fail to get chunk for telemetry log: {ERROR}", "DEVICE",
+ self->device->describe(), "ERROR", strerror(errno));
boost::asio::post(self->io,
[cb{std::move(cb)}, lastErrno{errno}]() {
cb(std::make_error_code(static_cast<std::errc>(lastErrno)), {});
@@ -897,9 +887,8 @@
{
std::string_view errMsg =
statusToString(static_cast<nvme_mi_resp_status>(rc));
- std::cerr << "[" << self->device->describe() << "]"
- << "fail to get chunk for telemetry log: " << errMsg
- << '\n';
+ lg2::error("fail to get chunk for telemetry log: {ERROR}", "DEVICE",
+ self->device->describe(), "ERROR", errMsg.data());
boost::asio::post(self->io, [cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::bad_message), {});
});
@@ -933,8 +922,8 @@
{
if (auto degraded = isEndpointDegraded())
{
- std::cerr << "[" << device->describe() << "]"
- << " MCTP connection is not established" << '\n';
+ lg2::error("MCTP connection is not established", "DEVICE",
+ device->describe());
io.post(
[cb{std::move(cb)}, errc{degraded.value()}]() { cb(errc, {}); });
return;
@@ -965,8 +954,8 @@
rc = nvme_mi_admin_get_log_error(ctrl, num, false, log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get error log" << '\n';
+ lg2::error("fail to get error log", "ENDPOINT",
+ ep->describe());
break;
}
}
@@ -980,8 +969,8 @@
rc = nvme_mi_admin_get_log_smart(ctrl, nsid, false, log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get smart log" << '\n';
+ lg2::error("fail to get smart log", "ENDPOINT",
+ ep->describe());
break;
}
}
@@ -1005,8 +994,8 @@
rc = nvme_mi_admin_get_log_fw_slot(ctrl, false, log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get firmware slot" << '\n';
+ lg2::error("fail to get firmware slot", "ENDPOINT",
+ ep->describe());
break;
}
}
@@ -1024,9 +1013,8 @@
log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get cmd supported and effects log"
- << '\n';
+ lg2::error("fail to get cmd supported and effects log",
+ "ENDPOINT", ep->describe());
break;
}
}
@@ -1040,8 +1028,8 @@
rc = nvme_mi_admin_get_log_device_self_test(ctrl, log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get device self test log" << '\n';
+ lg2::error("fail to get device self test log",
+ "ENDPOINT", ep->describe());
break;
}
}
@@ -1056,9 +1044,8 @@
log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get changed namespace list"
- << '\n';
+ lg2::error("fail to get changed namespace list",
+ "ENDPOINT", ep->describe());
break;
}
}
@@ -1092,10 +1079,9 @@
int rc = nvme_mi_admin_get_log_lockdown(ctrl, lsp, log);
if (rc != 0)
{
- std::cerr
- << "[" << ep->describe() << "]"
- << "fail to get command and feature lockdown log"
- << '\n';
+ lg2::error(
+ "fail to get command and feature lockdown log",
+ "ENDPOINT", ep->describe());
break;
}
}
@@ -1112,10 +1098,8 @@
log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get reservation "
- "notification log"
- << '\n';
+ lg2::error("fail to get reservation notification log",
+ "ENDPOINT", ep->describe());
break;
}
}
@@ -1130,16 +1114,16 @@
int rc = nvme_mi_admin_get_log_sanitize(ctrl, false, log);
if (rc != 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get sanitize status log" << '\n';
+ lg2::error("fail to get sanitize status log",
+ "ENDPOINT", ep->describe());
break;
}
}
break;
default:
{
- std::cerr << "[" << ep->describe() << "]"
- << "unknown lid for GetLogPage" << '\n';
+ lg2::error("unknown lid for GetLogPage", "ENDPOINT",
+ ep->describe());
rc = -1;
errno = EINVAL;
}
@@ -1147,9 +1131,8 @@
if (rc < 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get log page: " << std::strerror(errno)
- << '\n';
+ lg2::error("fail to get log page: {ERROR}", "ENDPOINT",
+ ep->describe(), "ERROR", strerror(errno));
logHandler = [cb{cb}, lastErrno{errno}]() mutable {
cb(std::make_error_code(static_cast<std::errc>(lastErrno)),
{});
@@ -1159,8 +1142,8 @@
{
std::string_view errMsg =
statusToString(static_cast<nvme_mi_resp_status>(rc));
- std::cerr << "[" << ep->describe() << "]"
- << "fail to get log pag: " << errMsg << '\n';
+ lg2::error("fail to get log page: {ERROR}", "ENDPOINT",
+ ep->describe(), "ERROR", errMsg.data());
logHandler = [cb{cb}]() mutable {
cb(std::make_error_code(std::errc::bad_message), {});
};
@@ -1178,8 +1161,8 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << endpoint->describe() << "]"
- << "NVMeMi adminGetLogPage throws: " << e.what() << '\n';
+ lg2::error("NVMeMi adminGetLogPage throws: {ERROR}", "ENDPOINT",
+ endpoint->describe(), "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device), {});
});
@@ -1195,8 +1178,8 @@
{
if (auto degraded = isEndpointDegraded())
{
- std::cerr << "[" << device->describe() << "]"
- << " MCTP connection is not established" << '\n';
+ lg2::error("MCTP connection is not established", "DEVICE",
+ device->describe());
io.post([cb{std::move(cb)}, errc{degraded.value()}]() {
cb(errc, {}, {});
});
@@ -1243,8 +1226,8 @@
if (rc < 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "failed to nvme_mi_admin_xfer" << '\n';
+ lg2::error("failed to nvme_mi_admin_xfer", "ENDPOINT",
+ ep->describe());
self->io.post([cb{std::move(cb)}, lastErrno{errno}]() {
cb(std::make_error_code(static_cast<std::errc>(lastErrno)),
{}, {});
@@ -1268,7 +1251,8 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << endpoint->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "ENDPOINT", endpoint->describe(), "ERROR",
+ e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device), {}, {});
});
@@ -1282,8 +1266,8 @@
{
if (auto degraded = isEndpointDegraded())
{
- std::cerr << "[" << device->describe() << "]"
- << " MCTP connection is not established" << '\n';
+ lg2::error("MCTP connection is not established", "DEVICE",
+ device->describe());
io.post([cb{std::move(cb)}, errc{degraded.value()}]() {
cb(errc, nvme_status_field::NVME_SC_MASK);
});
@@ -1302,9 +1286,9 @@
int rc = nvme_mi_admin_fw_commit(ctrl, &args);
if (rc < 0)
{
- std::cerr << "[" << ep->describe() << "]"
- << "fail to nvme_mi_admin_fw_commit: "
- << std::strerror(errno) << '\n';
+ lg2::error("fail to nvme_mi_admin_fw_commit: {ERROR}",
+ "ENDPOINT", ep->describe(), "ERROR",
+ strerror(errno));
self->io.post([cb{std::move(cb)}, lastErrno{errno}]() {
cb(std::make_error_code(static_cast<std::errc>(lastErrno)),
nvme_status_field::NVME_SC_MASK);
@@ -1326,9 +1310,8 @@
default:
std::string_view errMsg = statusToString(
static_cast<nvme_mi_resp_status>(rc));
- std::cerr
- << "fail to nvme_mi_admin_fw_commit: " << errMsg
- << '\n';
+ lg2::error("fail to nvme_mi_admin_fw_commit: {ERROR}",
+ "ERROR", errMsg.data());
self->io.post([rc, cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::bad_message),
static_cast<nvme_status_field>(rc));
@@ -1340,7 +1323,8 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << "[" << endpoint->describe() << "]" << e.what() << '\n';
+ lg2::error("{ERROR}", "ENDPOINT", endpoint->describe(), "ERROR",
+ e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device),
nvme_status_field::NVME_SC_MASK);
@@ -1356,8 +1340,8 @@
{
if (auto degraded = isEndpointDegraded())
{
- std::cerr << "[" << device->describe() << "]"
- << " MCTP connection is not established" << '\n';
+ lg2::error("MCTP connection is not established", "DEVICE",
+ device->describe());
io.post([cb{std::move(cb)}, errc{degraded.value()}]() {
cb(errc, nvme_status_field::NVME_SC_MASK);
});
@@ -1371,8 +1355,8 @@
std::ifstream fwFile(firmwarefile, std::ios::in | std::ios::binary);
if (fwFile.fail())
{
- std::cerr << "fail to open fw image file: " << firmwarefile
- << strerror(errno) << '\n';
+ lg2::error("fail to open fw image file: {FILE}, {ERROR}",
+ "FILE", firmwarefile, "ERROR", strerror(errno));
self->io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(static_cast<std::errc>(errno)),
nvme_status_field::NVME_SC_MASK);
@@ -1398,15 +1382,15 @@
{
if (attemptCount > 0)
{
- std::cout << "Retrying the firmware chunk. With Offset :"
- << offset << " Total firmware Size :" << size
- << '\n';
+ lg2::warning(
+ "Retrying the firmware chunk. With Offset: {OFFSET}, Total firmware Size: {SIZE}",
+ "OFFSET", offset, "SIZE", size);
attemptCount = attemptCount - 1;
}
else
{
- std::cerr << "fail to nvme_mi_admin_fw_download: "
- << std::strerror(errno) << '\n';
+ lg2::error("fail to nvme_mi_admin_fw_download: {ERROR}",
+ "ERROR", strerror(errno));
self->io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(static_cast<std::errc>(errno)),
nvme_status_field::NVME_SC_MASK);
@@ -1421,9 +1405,9 @@
}
if (offset >= size)
{
- std::cout
- << "Successfully transferred the firmware. Transfer Size : "
- << offset << " Total Size :" << size << '\n';
+ lg2::info(
+ "Successfully transferred the firmware. Transfer Size: {XFER}, Total Size: {SIZE}",
+ "XFER", offset, "SIZE", size);
self->io.post([rc, cb{std::move(cb)}]() {
cb({}, static_cast<nvme_status_field>(rc));
});
@@ -1438,7 +1422,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << e.what() << '\n';
+ lg2::error("{ERROR}", "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device),
nvme_status_field::NVME_SC_MASK);
@@ -1457,8 +1441,8 @@
std::ios::in | std::ios::binary | std::ios::ate);
if (imageFile.fail())
{
- std::cerr << "Can't open the firmware file: " << std::strerror(errno)
- << '\n';
+ lg2::error("Can't open the firmware file: {ERROR}", "ERROR",
+ strerror(errno));
io.post([cb{cb}]() {
cb(std::make_error_code(std::errc::no_such_device),
nvme_status_field::NVME_SC_MASK);
@@ -1499,8 +1483,8 @@
});
if (postErr)
{
- std::cerr << "[" << device->describe() << "]"
- << "adminSecuritySend post failed: " << postErr << '\n';
+ lg2::error("adminSecuritySend post failed: {ERROR}", "DEVICE",
+ device->describe(), "ERROR", postErr.message());
io.post([cb{std::move(cb)}, postErr]() { cb(postErr, -1); });
}
}
@@ -1539,9 +1523,9 @@
if (args.data_len > maxNVMeMILength)
{
- std::cerr << "[" << self->device->describe() << "]"
- << "nvme_mi_admin_security_send returned excess data, "
- << args.data_len << '\n';
+ lg2::error(
+ "nvme_mi_admin_security_send returned excess data, {LEN}",
+ "DEVICE", self->device->describe(), "LEN", args.data_len);
self->io.post([cb]() {
cb(std::make_error_code(std::errc::protocol_error), -1, {});
});
@@ -1557,8 +1541,8 @@
});
if (postErr)
{
- std::cerr << "[" << device->describe() << "]"
- << "adminSecurityReceive post failed: " << postErr << '\n';
+ lg2::error("adminSecurityReceive post failed: {ERROR}", "DEVICE",
+ device->describe(), "ERROR", postErr.message());
io.post([cb{std::move(cb)}, postErr]() { cb(postErr, -1, {}); });
}
}
@@ -1585,8 +1569,8 @@
});
if (postErr)
{
- std::cerr << "[" << device->describe() << "]"
- << "adminNonDataCmd post failed: " << postErr << '\n';
+ lg2::error("adminNonDataCmd post failed: {ERROR}", "DEVICE",
+ device->describe(), "ERROR", postErr.message());
io.post([cb{std::move(cb)}, postErr]() { cb(postErr, -1, 0); });
}
}
@@ -1595,7 +1579,7 @@
size_t NVMeMi::getBlockSize(nvme_mi_ctrl_t ctrl, size_t lbaFormat)
{
struct nvme_id_ns id = {};
- std::cout << "getblocksize" << '\n';
+ lg2::debug("getblocksize");
int status = nvme_mi_admin_identify_ns(ctrl, NVME_NSID_ALL, &id);
auto e = makeLibNVMeError(errno, status, "getBlockSize");
if (e)
@@ -1605,7 +1589,8 @@
throw e;
}
- std::cout << "nlbaf " << (int)id.nlbaf << "lbaf " << (int)lbaFormat << '\n';
+ lg2::debug("nlbaf {NLBAF}, lbaf {LBAF}", "NLBAF", (int)id.nlbaf, "LBAF",
+ (int)lbaFormat);
// Sanity check for the value from the drive
size_t maxLbaf = std::min(63, (int)id.nlbaf);
@@ -1629,7 +1614,7 @@
std::function<void(nvme_ex_ptr ex)>&& submittedCb,
std::function<void(nvme_ex_ptr ex, NVMeNSIdentify newid)>&& finishedCb)
{
- std::cout << "createns " << (int)gettid() << '\n';
+ lg2::debug("createns {TID}", "TID", (int)gettid());
std::error_code postErr = tryPost(
[self{shared_from_this()}, ctrl, size, lbaFormat, metadataAtEnd,
submittedCb{submittedCb}, finishedCb{std::move(finishedCb)}]() {
@@ -1679,14 +1664,14 @@
data.ncap = ::htole64(blocks);
data.flbas = flbas;
- std::cout << "verified " << (int)gettid() << '\n';
+ lg2::debug("verified {TID}", "TID", (int)gettid());
// submission has been verified. Handle the cb in main thread
// concurrently.
self->io.post([submittedCb{submittedCb}]() mutable {
submittedCb(nvme_ex_ptr());
});
- std::cout << "after submitted_cb " << (int)gettid() << '\n';
+ lg2::debug("after submitted_cb {TID}", "TID", (int)gettid());
unsigned timeout = nvme_mi_ep_get_timeout(self->nvmeEP);
nvme_mi_ep_set_timeout(self->nvmeEP, namespaceDefaultTimeoutMS);
@@ -1724,12 +1709,12 @@
#endif
});
- std::cout << "submitted cb " << (int)gettid() << '\n';
+ lg2::debug("submitted cb {TID}", "TID", (int)gettid());
if (postErr)
{
- std::cerr << "adminAttachDetachNamespace post failed: " << postErr
- << '\n';
+ lg2::error("createNamespace post failed: {ERROR}", "ERROR",
+ postErr.message());
auto e = makeLibNVMeError(postErr, -1, "createVolume");
io.post([submittedCb{std::move(submittedCb)}, e]() { submittedCb(e); });
}
@@ -1754,7 +1739,8 @@
});
if (postErr)
{
- std::cerr << "deleteNamespace post failed: " << postErr << '\n';
+ lg2::error("deleteNamespace post failed: {ERROR}", "ERROR",
+ postErr.message());
io.post([cb{std::move(cb)}, postErr]() { cb(postErr, -1); });
}
}
@@ -1851,8 +1837,8 @@
});
if (postErr)
{
- std::cerr << "adminAttachDetachNamespace post failed: " << postErr
- << '\n';
+ lg2::error("adminAttachDetachNamespace post failed: {ERROR}", "ERROR",
+ postErr.message());
io.post([cb{std::move(cb)}, postErr]() { cb(postErr, -1); });
}
}
@@ -1875,7 +1861,8 @@
nvme_mi_ep_set_timeout(self->nvmeEP, sanitizeDefaultTimeoutMS);
int status = nvme_mi_admin_sanitize_nvm(ctrl, &args);
nvme_mi_ep_set_timeout(self->nvmeEP, timeout);
- std::cout << "san status " << status << "errno " << errno << '\n';
+ lg2::debug("san status {STATUS}, errno {ERRNO}", "STATUS", status,
+ "ERRNO", errno);
auto ex = makeLibNVMeError(errno, status, "adminSanitize");
self->io.post([cb{cb}, ex]() mutable { cb(ex); });
diff --git a/src/NVMeMiFake.hpp b/src/NVMeMiFake.hpp
index bd13504..ce22761 100644
--- a/src/NVMeMiFake.hpp
+++ b/src/NVMeMiFake.hpp
@@ -2,8 +2,8 @@
#include <boost/asio.hpp>
#include <boost/endian.hpp>
+#include <phosphor-logging/lg2.hpp>
-#include <iostream>
#include <thread>
struct ListNode
@@ -30,8 +30,8 @@
thread = std::thread([&io = workerIO, &stop = workerStop,
&mtx = workerMtx, &cv = workerCv,
&isNotified = workerIsNotified, delay]() {
- std::cerr << "NVMeMiFake worker thread started: " << io.stopped()
- << '\n';
+ lg2::info("NVMeMiFake worker thread started: {STOPPED}", "STOPPED",
+ io.stopped());
// With BOOST_ASIO_DISABLE_THREADS, boost::asio::executor_work_guard
// issues null_event across the thread, which caused invalid
// invokation. We implement a simple invoke machenism based
@@ -44,7 +44,7 @@
std::this_thread::sleep_for(delay);
io.run();
io.restart();
- std::cerr << "job done\n";
+ lg2::info("job done");
{
std::unique_lock<std::mutex> lock(mtx);
cv.wait(lock, [&]() { return isNotified; });
@@ -57,22 +57,22 @@
}
}
}
- std::cerr << "NVMeMi worker this line should not be reached\n";
+ lg2::error("NVMeMi worker this line should not be reached");
});
ctrls.resize(3);
- std::cerr << "NVMeMiFake constructor\n";
+ lg2::info("NVMeMiFake constructor");
}
~NVMeMiFake() override
{
if (valid)
{
- std::cerr << "NVMeMiFake destroyer\n";
+ lg2::info("NVMeMiFake destroyer");
}
else
{
- std::cerr << "NVMeMiFake default destroyer\n";
+ lg2::info("NVMeMiFake default destroyer");
}
// close worker
@@ -109,7 +109,7 @@
{
if (workerStop)
{
- std::cerr << "worker thread for nvme endpoint is stopped\n";
+ lg2::error("worker thread for nvme endpoint is stopped");
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device), {});
@@ -118,7 +118,7 @@
}
post([self{shared_from_this()}, cb = std::move(cb)] {
- std::cerr << "libnvme: scan\n";
+ lg2::info("libnvme: scan");
self->io.post([self{self->shared_from_this()}, cb{cb}]() mutable {
auto& ctrl1 = self->ctrls[0];
auto& ctrl2 = self->ctrls[1];
@@ -145,9 +145,9 @@
[[maybe_unused]] uint32_t nsid, [[maybe_unused]] uint16_t cntid,
std::function<void(nvme_ex_ptr, std::span<uint8_t>)>&& cb) override
{
- std::cerr << "identify\n";
+ lg2::info("identify");
post([self{shared_from_this()}, cb = std::move(cb), cns, nsid]() {
- std::cerr << "libnvme: identify\n";
+ lg2::info("libnvme: identify");
self->io.post([cb{cb}, cns, nsid]() mutable {
std::vector<uint8_t> data;
switch (cns)
@@ -214,8 +214,8 @@
log.lpi = 0x07;
if (rc != 0)
{
- std::cerr
- << "failed to create telemetry host log\n";
+ lg2::error(
+ "failed to create telemetry host log");
throw std::system_error(
errno, std::generic_category());
}
@@ -236,9 +236,8 @@
if (rc != 0)
{
- std::cerr
- << "failed to retain telemetry host "
- "log full log\n";
+ lg2::error(
+ "failed to retain telemetry host log full log");
throw std::system_error(
errno, std::generic_category());
}
@@ -264,7 +263,7 @@
default:
{
- std::cerr << "unknown lid for GetLogPage\n";
+ lg2::error("unknown lid for GetLogPage");
throw std::system_error(std::make_error_code(
std::errc::invalid_argument));
}
@@ -284,7 +283,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << e.what() << '\n';
+ lg2::error("{ERROR}", "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device), {});
});
@@ -308,8 +307,8 @@
int rc = 1;
if (rc < 0)
{
- std::cerr << "fail to subsystem_health_status_poll: "
- << std::strerror(errno) << '\n';
+ lg2::error("fail to subsystem_health_status_poll: {ERROR}",
+ "ERROR", strerror(errno));
self->io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(static_cast<std::errc>(errno)),
nvme_status_field::NVME_SC_MASK);
@@ -330,9 +329,9 @@
default:
std::string_view errMsg = statusToString(
static_cast<nvme_mi_resp_status>(rc));
- std::cerr
- << "fail to subsystem_health_status_poll: "
- << errMsg << '\n';
+ lg2::error(
+ "fail to subsystem_health_status_poll: {ERROR}",
+ "ERROR", errMsg.data());
self->io.post([rc, cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::bad_message),
static_cast<nvme_status_field>(rc));
@@ -344,7 +343,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << e.what() << '\n';
+ lg2::error("{ERROR}", "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device),
nvme_status_field::NVME_SC_MASK);
@@ -392,7 +391,7 @@
if (rc < 0)
{
- std::cerr << "failed to nvme_mi_admin_xfer\n";
+ lg2::error("failed to nvme_mi_admin_xfer");
self->io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(static_cast<std::errc>(errno)),
{}, {});
@@ -425,7 +424,7 @@
}
catch (const std::runtime_error& e)
{
- std::cerr << e.what() << '\n';
+ lg2::error("{ERROR}", "ERROR", e.what());
io.post([cb{std::move(cb)}]() {
cb(std::make_error_code(std::errc::no_such_device), {}, {});
});
@@ -545,7 +544,7 @@
std::unique_lock<std::mutex> lock(workerMtx);
if (!workerStop)
{
- std::cerr << "do post\n";
+ lg2::info("do post");
workerIsNotified = true;
workerIO.post(std::move(func));
workerCv.notify_all();
diff --git a/src/NVMePlugin.cpp b/src/NVMePlugin.cpp
index e450017..702065c 100644
--- a/src/NVMePlugin.cpp
+++ b/src/NVMePlugin.cpp
@@ -7,6 +7,8 @@
#include "NVMeSubsys.hpp"
#include "Utils.hpp"
+#include <phosphor-logging/lg2.hpp>
+
// map from plugin path (subsystem path) to getMetric function
std::unordered_map<std::string,
std::function<std::vector<std::shared_ptr<MetricBase<>>>(
@@ -22,9 +24,8 @@
if (res == subsystem->controllers.end() ||
&controller != res->second.first.get())
{
- std::cerr << ("Failed to create controller plugin: "
- "cannot find the controller")
- << '\n';
+ lg2::error(
+ "Failed to create controller plugin: cannot find the controller");
res->second.second.reset();
return {};
}
diff --git a/src/NVMeSensorMain.cpp b/src/NVMeSensorMain.cpp
index b3a32b5..7189cdb 100644
--- a/src/NVMeSensorMain.cpp
+++ b/src/NVMeSensorMain.cpp
@@ -26,6 +26,7 @@
#include <boost/algorithm/string.hpp>
#include <boost/asio/steady_timer.hpp>
+#include <phosphor-logging/lg2.hpp>
#include <filesystem>
#include <fstream>
@@ -63,19 +64,20 @@
const std::string confPath = "/var/run/nvmed/banned-i2c-bus.conf";
if (!std::filesystem::exists(script))
{
- std::cerr << "Script " << script << " doesn't exist" << '\n';
+ lg2::error("Script {SCRIPT} doesn't exist", "SCRIPT", script);
return;
}
- std::cerr << "Begin to execute " << script << '\n';
+ lg2::info("Begin to execute {SCRIPT}", "SCRIPT", script);
// TODO: (b/376270522) cert-env33-c error: calling 'system' uses a command
// processor
int rc = std::system(script.c_str()); // NOLINT(cert-env33-c)
- std::cerr << "Shell script rc = " << rc << '\n';
+ lg2::info("Shell script rc = {RC}", "RC", rc);
if (!std::filesystem::exists(confPath))
{
- std::cerr << "Warning: " << confPath << " doesn't exist." << '\n';
+ lg2::warning("Warning: {CONF_PATH} doesn't exist.", "CONF_PATH",
+ confPath);
// Be optimistic，assume no bus is banned
return;
}
@@ -83,7 +85,7 @@
file.open(confPath);
if (!file.is_open())
{
- std::cerr << "Error: cannot open " << confPath << '\n';
+ lg2::error("Error: cannot open {CONF_PATH}", "CONF_PATH", confPath);
// Be optimistic，assume no bus is banned
return;
}
@@ -92,7 +94,7 @@
int i2cBus{0};
while (file >> i2cBus)
{
- std::cerr << "Banned i2c bus: " << i2cBus << '\n';
+ lg2::info("Banned i2c bus: {BUS}", "BUS", i2cBus);
bannedBuses.insert(i2cBus);
}
file.close();
@@ -105,7 +107,7 @@
auto findBus = properties.find("Bus");
if (findBus == properties.end())
{
- std::cerr << "could not determine bus number for " << path << "\n";
+ lg2::error("could not determine bus number for '{PATH}'", "PATH", path);
return std::nullopt;
}
@@ -118,7 +120,7 @@
auto findAddr = properties.find("Address");
if (findAddr == properties.end())
{
- std::cerr << "could not determine address for " << path << "\n";
+ lg2::error("could not determine address for '{PATH}'", "PATH", path);
return std::nullopt;
}
@@ -131,8 +133,8 @@
auto findName = properties.find("Name");
if (findName == properties.end())
{
- std::cerr << "could not determine configuration name for " << path
- << "\n";
+ lg2::error("could not determine configuration name for '{PATH}'",
+ "PATH", path);
return std::nullopt;
}
@@ -146,7 +148,8 @@
auto findProtocol = properties.find("Protocol");
if (findProtocol == properties.end())
{
- std::cerr << "could not determine nvme protocl for " << path << "\n";
+ lg2::error("could not determine nvme protocol for '{PATH}'", "PATH",
+ path);
return std::nullopt;
}
return std::get<std::string>(findProtocol->second);
@@ -298,15 +301,15 @@
// I2C directly.
if (!isMctpReactorDevice && !isI2cAccessible)
{
- std::cerr << "Found an mctpd device that isn't I2C accessible,"
- "but it must be: "
- << nvmeObjectPath.str << '\n';
+ lg2::info("Found an mctpd device that isn't I2C accessible,"
+ "but it must be: {PATH}",
+ "PATH", nvmeObjectPath.str);
continue;
}
if (busNumber && bannedBuses.contains(*busNumber))
{
- std::cerr << "Skip banned i2c bus:" << *busNumber << '\n';
+ lg2::info("Skip banned i2c bus: {BUS}", "BUS", *busNumber);
continue;
}
@@ -320,8 +323,8 @@
// protocol because we don't need it for now.
if (*nvmeProtocol == "mi_basic" && !isI2cAccessible)
{
- std::cerr << "Skipping an mi_basic device that's not accessible "
- "over i2c bus.\n";
+ lg2::info("Skipping an mi_basic device that's not accessible "
+ "over i2c bus.");
continue;
}
@@ -342,9 +345,9 @@
}
catch (std::exception& ex)
{
- std::cerr << "Failed to add nvme basic interface for "
- << std::string(nvmeObjectPath) << ": " << ex.what()
- << "\n";
+ lg2::error(
+ "Failed to add nvme basic interface for '{PATH}': {ERROR}",
+ "PATH", nvmeObjectPath.str, "ERROR", ex.what());
continue;
}
}
@@ -413,9 +416,9 @@
}
catch (std::exception& ex)
{
- std::cerr << "Failed to add nvme mi interface for "
- << std::string(nvmeObjectPath) << ": " << ex.what()
- << "\n";
+ lg2::error(
+ "Failed to add nvme mi interface for '{PATH}': {ERROR}",
+ "PATH", nvmeObjectPath.str, "ERROR", ex.what());
continue;
}
}
@@ -466,9 +469,8 @@
}
catch (std::exception& ex)
{
- std::cerr << "Failed to add nvme subsystem for "
- << std::string(interfacePath) << ": " << ex.what()
- << "\n";
+ lg2::error("Failed to add nvme subsystem for '{PATH}': {ERROR}",
+ "PATH", std::string(interfacePath), "ERROR", ex.what());
continue;
}
}
@@ -503,9 +505,8 @@
}
else
{
- std::cerr << "more than one `handleConfigurations` has been "
- "scheduled, cancel the current one"
- << '\n';
+ lg2::error("more than one `handleConfigurations` has been "
+ "scheduled, cancel the current one");
}
});
auto timer = std::make_shared<boost::asio::steady_timer>(
@@ -523,9 +524,8 @@
}
else
{
- std::cerr << "`handleConfigurations` has not been triggered, "
- "cancel the time"
- << '\n';
+ lg2::error("`handleConfigurations` has not been triggered, "
+ "cancel the timer");
}
});
@@ -536,7 +536,7 @@
{
if (message.is_method_error())
{
- std::cerr << "interfacesRemoved callback method error\n";
+ lg2::error("interfacesRemoved callback method error");
return;
}
@@ -566,7 +566,7 @@
{
if (singleWorkerFeature)
{
- std::cerr << "singleWorkerFeature on " << '\n';
+ lg2::info("singleWorkerFeature on");
}
// Load plugin shared libraries
@@ -582,13 +582,14 @@
}
else
{
- std::cerr << "could not load the plugin: " << dlerror() << '\n';
+ lg2::error("could not load the plugin: {ERROR}", "ERROR",
+ dlerror());
}
}
}
catch (const std::filesystem::filesystem_error& e)
{
- std::cerr << "failed to open plugin folder: " << e.what() << '\n';
+ lg2::error("failed to open plugin folder: {ERROR}", "ERROR", e.what());
}
// TODO: set single thread mode according to input parameters
@@ -616,7 +617,7 @@
if (ec)
{
- std::cerr << "Error: " << ec.message() << "\n";
+ lg2::error("Error: {ERROR}", "ERROR", ec.message());
return;
}
@@ -644,8 +645,8 @@
boost::asio::signal_set signals(io, SIGPIPE);
signals.async_wait(
[](const boost::system::error_code& error, int signalNumber) {
- std::cerr << "signal: " << strsignal(signalNumber) << ", "
- << error.message() << '\n';
+ lg2::info("signal: {SIGNAL}, {ERROR}", "SIGNAL",
+ strsignal(signalNumber), "ERROR", error.message());
});
io.run();
diff --git a/src/NVMeSubsys.cpp b/src/NVMeSubsys.cpp
index e2ae09c..0ae9a2f 100644
--- a/src/NVMeSubsys.cpp
+++ b/src/NVMeSubsys.cpp
@@ -183,9 +183,8 @@
findPrimary = controllers.find(secCntlrList->sc_entry[0].pcid);
if (findPrimary == controllers.end())
{
- std::cerr << "fail to match primary controller from "
- "identify sencondary cntrl list"
- << '\n';
+ lg2::error("fail to match primary controller from "
+ "identify secondary cntrl list");
status = Status::Aborting;
markFunctional(false);
markAvailable(false);
@@ -206,9 +205,8 @@
auto findSecondary = controllers.find(secCntlrList->sc_entry[i].scid);
if (findSecondary == controllers.end())
{
- std::cerr << "fail to match secondary controller from "
- "identify sencondary cntrl list"
- << '\n';
+ lg2::error("fail to match secondary controller from "
+ "identify secondary cntrl list");
break;
}
@@ -232,13 +230,12 @@
self->fillDrive(yield);
self->updateVolumes(yield);
self->querySupportedFormats(yield);
- std::cerr << "finished NS enum" << '\n';
+ lg2::info("finished NS enum");
}
catch (const std::exception& e)
{
- std::cerr << std::format("[{}] failed starting the subsystem: {}",
- self->name, e.what())
- << '\n';
+ lg2::error("failed starting the subsystem: {ERROR}", "SUBSYSTEM",
+ self->name, "ERROR", e.what());
self->status = Status::Aborting;
self->markFunctional(false);
self->markAvailable(false);
@@ -354,9 +351,8 @@
if (!posted)
{
- std::cerr
- << "Failed to flush operations, subsystem has stalled!"
- << '\n';
+ lg2::error(
+ "Failed to flush operations, subsystem has stalled!");
}
}
@@ -412,8 +408,9 @@
if (ec || ctrlList.empty())
{
// TODO: mark the subsystem invalid and reschedule refresh
- std::cerr << "fail to scan controllers for the nvme subsystem"
- << (ec ? ": " + ec.message() : "") << '\n';
+ lg2::error(
+ "fail to scan controllers for the nvme subsystem: {ERROR}",
+ "ERROR", ec.message());
self->status = Status::Aborting;
self->markFunctional(false);
self->markAvailable(false);
@@ -451,9 +448,9 @@
}
catch (const std::exception& e)
{
- std::cerr << "failed to create controller: "
- << std::to_string(*index)
- << ", reason: " << e.what() << '\n';
+ lg2::error(
+ "failed to create controller: {CONTROLLER}, reason: {REASON}",
+ "CONTROLLER", *index, "REASON", e.what());
}
index++;
@@ -493,8 +490,7 @@
std::span<uint8_t> data) {
if (ex || data.size() < sizeof(nvme_secondary_ctrl_list))
{
- std::cerr << "fail to identify secondary controller list"
- << '\n';
+ lg2::error("fail to identify secondary controller list");
self->status = Status::Aborting;
self->markFunctional(false);
self->markAvailable(false);
@@ -506,8 +502,7 @@
if (listHdr->num == 0)
{
- std::cerr << "empty identify secondary controller list"
- << '\n';
+ lg2::error("empty identify secondary controller list");
self->status = Status::Aborting;
self->markFunctional(false);
self->markAvailable(false);
@@ -546,8 +541,9 @@
{
if (!primaryController)
{
- std::cerr << "dbus call for inactive NVMe subsystem " << name
- << ". Returning Unavailable\n";
+ lg2::error(
+ "dbus call for inactive NVMe subsystem {SUBSYSTEM}. Returning Unavailable",
+ "SUBSYSTEM", name);
throw sdbusplus::xyz::openbmc_project::Common::Error::Unavailable();
}
return primaryController;
@@ -589,7 +585,8 @@
std::vector<thresholds::Threshold> sensorThresholds;
if (!parseThresholdsFromConfig(config, sensorThresholds))
{
- std::cerr << "error populating thresholds for " << *sensorName << "\n";
+ lg2::error("error populating thresholds for {SENSOR}", "SENSOR",
+ *sensorName);
throw std::runtime_error("error populating thresholds for " +
*sensorName);
}
@@ -606,10 +603,8 @@
auto sensorBase = config.find(configInterfaceName(nvme::sensorType));
if (sensorBase == config.end())
{
- std::cerr << "Warning: " << name
- << ": cannot find sensor config " +
- configInterfaceName(nvme::sensorType)
- << '\n';
+ lg2::warning("cannot find sensor config {CONFIG} for {NAME}", "CONFIG",
+ configInterfaceName(nvme::sensorType), "NAME", name);
}
else
{
@@ -666,8 +661,9 @@
// The device is physically absent
if (error == std::errc::no_such_device)
{
- std::cerr << "error reading ctemp from subsystem"
- << ", reason:" << error.message() << "\n";
+ lg2::error(
+ "error reading ctemp from subsystem, reason: {ERROR}",
+ "ERROR", error.message());
self->markFunctional(false);
self->markAvailable(false);
return;
@@ -675,15 +671,16 @@
// other communication errors
if (error)
{
- std::cerr << "error reading ctemp from subsystem"
- << ", reason:" << error.message() << "\n";
+ lg2::error(
+ "error reading ctemp from subsystem, reason: {ERROR}",
+ "ERROR", error.message());
self->ctemp->incrementError();
return;
}
if (status == nullptr)
{
- std::cerr << "empty data returned by data fetcher" << '\n';
+ lg2::error("empty data returned by data fetcher");
self->markFunctional(false);
return;
}
@@ -694,10 +691,9 @@
((flags & NVMeBasicIntf::StatusFlags::
NVME_MI_BASIC_SFLGS_DRIVE_FUNCTIONAL) == 0))
{
- std::cerr
- << self->name
- << ": health poll returns drive not ready or drive not functional"
- << '\n';
+ lg2::error(
+ "{NAME}: health poll returns drive not ready or drive not functional",
+ "NAME", self->name);
self->markFunctional(false);
return;
}
@@ -728,8 +724,7 @@
// do not poll the health status if the subsystem is intiatilzing
if (self->status == Status::Intiatilzing)
{
- std::cerr << "subsystem is intiatilzing, cancel the health poll"
- << '\n';
+ lg2::info("subsystem is initializing, cancel the health poll");
cb(std::make_error_code(std::errc::operation_canceled),
nullptr);
return;
@@ -749,25 +744,22 @@
if (error == std::errc::operation_canceled)
{
- std::cerr << "processing health data has been cancelled"
- << '\n';
+ lg2::info("processing health data has been cancelled");
return;
}
if (self->status == Status::Intiatilzing)
{
- // on initialization, the subsystem will not update the status.
- std::cerr
- << "subsystem is intiatilzing, do not process the status"
- << '\n';
+ lg2::info(
+ "subsystem is initializing, do not process the status");
return;
}
if (error == std::errc::no_such_device)
{
- std::cerr << "error reading ctemp "
- "from subsystem"
- << ", reason:" << error.message() << "\n";
+ lg2::error(
+ "error reading ctemp from subsystem, reason: {ERROR}",
+ "ERROR", error.message());
// stop the subsystem
self->markFunctional(false);
self->markAvailable(false);
@@ -776,9 +768,9 @@
}
if (error)
{
- std::cerr << "error reading ctemp "
- "from subsystem"
- << ", reason:" << error.message() << "\n";
+ lg2::error(
+ "error reading ctemp from subsystem, reason: {ERROR}",
+ "ERROR", error.message());
self->ctemp->incrementError();
if (self->ctemp->inError())
{
@@ -797,8 +789,8 @@
if (!df)
{
// stop the subsystem
- std::cerr << self->name << ": health poll returns df status 0"
- << '\n';
+ lg2::error("{NAME}: health poll returns df status 0", "NAME",
+ self->name);
self->markFunctional(false);
return;
}
@@ -827,7 +819,7 @@
if (status == Status::Intiatilzing)
{
- std::cerr << "status init" << '\n';
+ lg2::debug("status init");
auto timer = std::make_shared<boost::asio::steady_timer>(
io, std::chrono::milliseconds(100));
timer->async_wait(
@@ -841,7 +833,7 @@
}
else
{
- std::cerr << "status else" << '\n';
+ lg2::debug("status else");
markFunctional(false);
// There's been an explicit request to stop the subsystem. If it has
@@ -904,8 +896,8 @@
auto self = weak.lock();
if (!self)
{
- std::cerr << "createNamespace completed while nvmesensor was "
- "exiting\n";
+ lg2::warning(
+ "createNamespace completed while nvmesensor was exiting");
return;
}
// The NS create has completed (either successfully or not)
@@ -982,8 +974,8 @@
}
catch (const std::exception& e)
{
- std::cerr << "Unhandled error in createVolumeFinished: " << e.what()
- << "\n";
+ lg2::error("Unhandled error in createVolumeFinished: {ERROR}", "ERROR",
+ e.what());
}
}
@@ -1072,7 +1064,7 @@
uint16_t num = ::le16toh(list.num);
if (num == NVME_ID_CTRL_LIST_MAX)
{
- std::cerr << "Warning: full ctrl list returned\n";
+ lg2::warning("full ctrl list returned");
}
for (auto i = 0; i < num; i++)
@@ -1131,9 +1123,10 @@
std::set_difference(existing.begin(), existing.end(), ns.begin(), ns.end(),
std::back_inserter(deletions));
- std::cerr << std::format(
- "[{}] subsystem enum {} NS, {} will be added, {} will be deleted\n",
- name, ns.size(), additions.size(), deletions.size());
+ lg2::info(
+ "[{SUBSYSTEM}] subsystem enum {NS_SIZE} NS, {ADDITIONS} will be added, {DELETIONS} will be deleted",
+ "SUBSYSTEM", name, "NS_SIZE", ns.size(), "ADDITIONS", additions.size(),
+ "DELETIONS", deletions.size());
for (auto n : deletions)
{
@@ -1200,8 +1193,8 @@
{
if (volPath.parent_path() != path + "/volumes")
{
- std::cerr << "getVolume path '" << volPath.str
- << "' doesn't match parent " << path << "\n";
+ lg2::error("getVolume path '{PATH}' doesn't match parent {PARENT_PATH}",
+ "PATH", volPath.str, "PARENT_PATH", path);
return nullptr;
}
@@ -1210,14 +1203,14 @@
auto e = std::from_chars(id.data(), id.data() + id.size(), nsid);
if (e.ptr != id.data() + id.size() || e.ec != std::errc())
{
- std::cerr << "getVolume path '" << volPath.str << "' bad nsid\n";
+ lg2::error("getVolume path '{PATH}' bad nsid", "PATH", volPath.str);
return nullptr;
}
auto v = volumes.find(nsid);
if (v == volumes.end())
{
- std::cerr << "getVolume nsid " << nsid << " not found\n";
+ lg2::error("getVolume nsid {NSID} not found", "NSID", nsid);
return nullptr;
}
@@ -1230,7 +1223,7 @@
if (!controllers.contains(ctrlId))
{
- std::cerr << "attachedVolumes bad controller " << ctrlId << '\n';
+ lg2::error("attachedVolumes bad controller {CTRLID}", "CTRLID", ctrlId);
return vols;
}
@@ -1262,7 +1255,8 @@
throw std::runtime_error(std::format("attachCtrlVolume bad ns {}", ns));
}
attached[c].insert(ns);
- std::cout << name << " attached insert " << c << " " << ns << "\n";
+ lg2::info("{NAME} attached insert {C} {NS}", "NAME", name, "C", c, "NS",
+ ns);
controllers[c].first->updateAssociation();
}
@@ -1283,7 +1277,7 @@
throw std::runtime_error(std::format("detachCtrlVolume bad ns {}", ns));
}
attached[c].erase(ns);
- std::cout << name << " attached erase " << c << " " << ns << "\n";
+ lg2::info("{NAME} attached erase {C} {NS}", "NAME", name, "C", c, "NS", ns);
controllers[c].first->updateAssociation();
}
@@ -1320,7 +1314,7 @@
{
std::string errMsg = std::string("Internal error, NSID exists " +
std::to_string(ns.namespaceId));
- std::cerr << errMsg << "\n";
+ lg2::error("{ERROR}", "ERROR", errMsg);
throw makeLibNVMeError(errMsg);
}
@@ -1398,15 +1392,15 @@
throw std::runtime_error(std::format("{}: Bad nlbaf {}", name, nlbaf));
}
- std::cerr << name << ": Got nlbaf " << nlbaf << "\n";
+ lg2::debug("{NAME}: Got nlbaf {NLBAF}", "NAME", name, "NLBAF", nlbaf);
std::vector<LBAFormat> formats;
for (size_t i = 0; i < nlbaf; i++)
{
size_t blockSize = 1UL << id.lbaf[i].ds;
size_t metadataSize = id.lbaf[i].ms;
RelPerf rp = relativePerformanceFromRP(id.lbaf[i].rp);
- std::cerr << name << ": lbaf " << i << " blocksize " << blockSize
- << "\n";
+ lg2::debug("{NAME}: lbaf {LBAF} blocksize {BLOCKSIZE}", "NAME", name,
+ "LBAF", i, "BLOCKSIZE", blockSize);
formats.push_back({.index = i,
.blockSize = blockSize,
.metadataSize = metadataSize,
@@ -1476,8 +1470,8 @@
{
if (status != Status::Start)
{
- std::cerr << "Subsystem not in Start state, have "
- << static_cast<int>(status) << '\n';
+ lg2::error("Subsystem not in Start state, have {STATUS}", "STATUS",
+ static_cast<int>(status));
return;
}
diff --git a/src/NVMeUtil.hpp b/src/NVMeUtil.hpp
index bc013e5..0f80f65 100644
--- a/src/NVMeUtil.hpp
+++ b/src/NVMeUtil.hpp
@@ -1,9 +1,9 @@
#pragma once
#include <boost/algorithm/string/join.hpp>
#include <boost/asio.hpp>
+#include <phosphor-logging/lg2.hpp>
#include <filesystem>
-#include <iostream>
#include <optional>
#include <system_error>
@@ -36,7 +36,8 @@
size_t dash = rootName.find('-');
if (dash == std::string::npos)
{
- std::cerr << "Error finding root bus for " << rootName << "\n";
+ lg2::error("Error finding root bus for {ROOT_NAME}", "ROOT_NAME",
+ rootName);
return std::nullopt;
}
@@ -161,12 +162,12 @@
{
if (errorCode == boost::asio::error::operation_aborted || timer.expired())
{
- std::cerr << "poll loop has been cancelled\n";
+ lg2::info("poll loop has been cancelled");
return;
}
if (errorCode)
{
- std::cerr << errorCode.message() << "\n";
+ lg2::error("{ERROR}", "ERROR", errorCode.message());
::pollCtemp(std::move(timer), delay, dataFetcher, dataProcessor);
return;
}
