sensorcommands: Add IPMI reading logging instrumentation
Noteworthy sensor readings, such as the first reading,
a new minimum or maximum value, or ending a good or
bad streak of readings, will now have some useful logging output.
Tested: Example logs
```
root@bmc:~# journalctl --no-pager | grep 'IPMI sensor'
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor0: First reading, value=6 byte=51
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor0: Range min=0 max=30, Coefficients mValue=118 rExp=-3 bValue=0 bExp=0 bSigned=0
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor1: First reading, value=7 byte=59
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor1: Range min=0 max=30, Coefficients mValue=118 rExp=-3 bValue=0 bExp=0 bSigned=0
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor2: First reading, value=1.437 byte=12
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor2: Range min=0 max=30, Coefficients mValue=118 rExp=-3 bValue=0 bExp=0 bSigned=0
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor3: First reading, value=1.437 byte=12
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor3: Range min=0 max=30, Coefficients mValue=118 rExp=-3 bValue=0 bExp=0 bSigned=0
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor4: First reading, value=1.96 byte=17
Jan 01 00:03:16 bmc ipmid[2865]: IPMI sensor sensor4: Range min=0 max=30, Coefficients mValue=118 rExp=-3 bValue=0 bExp=0 bSigned=0
...
```
Machine and sensors names are replaced.
Ported from:
https://gerrit.openbmc-project.xyz/c/openbmc/intel-ipmi-oem/+/40327
Signed-off-by: Josh Lehan <krellan@google.com>
Change-Id: Idf7c8d4285b286fdc0afb3f0e7260c2d4915b326
Signed-off-by: Willy Tu <wltu@google.com>
diff --git a/dbus-sdr/sdrutils.cpp b/dbus-sdr/sdrutils.cpp
index 9172d05..1eadb6f 100644
--- a/dbus-sdr/sdrutils.cpp
+++ b/dbus-sdr/sdrutils.cpp
@@ -66,6 +66,8 @@
}
subtree = sensorTreePtr;
sensorUpdatedIndex++;
+ // The SDR is being regenerated, wipe the old stats
+ sdrStatsTable.wipeTable();
return sensorUpdatedIndex;
}
diff --git a/dbus-sdr/sensorcommands.cpp b/dbus-sdr/sensorcommands.cpp
index b706db2..42fb9de 100644
--- a/dbus-sdr/sensorcommands.cpp
+++ b/dbus-sdr/sensorcommands.cpp
@@ -341,6 +341,35 @@
IPMISensorReadingByte2::readingStateUnavailable);
}
+ if constexpr (details::enableInstrumentation)
+ {
+ int byteValue;
+ if (bSigned)
+ {
+ byteValue = static_cast<int>(static_cast<int8_t>(value));
+ }
+ else
+ {
+ byteValue = static_cast<int>(static_cast<uint8_t>(value));
+ }
+
+ // Keep stats on the reading just obtained, even if it is "NaN"
+ if (details::sdrStatsTable.updateReading(sensnum, reading, byteValue))
+ {
+ // This is the first reading, show the coefficients
+ double step = (max - min) / 255.0;
+ std::cerr << "IPMI sensor "
+ << details::sdrStatsTable.getName(sensnum)
+ << ": Range min=" << min << " max=" << max
+ << ", step=" << step
+ << ", Coefficients mValue=" << static_cast<int>(mValue)
+ << " rExp=" << static_cast<int>(rExp)
+ << " bValue=" << static_cast<int>(bValue)
+ << " bExp=" << static_cast<int>(bExp)
+ << " bSigned=" << static_cast<int>(bSigned) << "\n";
+ }
+ }
+
uint8_t thresholds = 0;
auto warningObject =
@@ -1187,6 +1216,9 @@
std::strncpy(record.body.id_string, name.c_str(),
sizeof(record.body.id_string));
+ // Remember the sensor name, as determined for this sensor number
+ details::sdrStatsTable.updateName(sensornumber, name);
+
IPMIThresholds thresholdData;
try
{
diff --git a/include/dbus-sdr/sdrutils.hpp b/include/dbus-sdr/sdrutils.hpp
index bc983af..e700af6 100644
--- a/include/dbus-sdr/sdrutils.hpp
+++ b/include/dbus-sdr/sdrutils.hpp
@@ -57,6 +57,161 @@
namespace details
{
+// Enable/disable the logging of stats instrumentation
+static constexpr bool enableInstrumentation = false;
+
+class IPMIStatsEntry
+{
+ private:
+ int numReadings = 0;
+ int numMissings = 0;
+ int numStreakRead = 0;
+ int numStreakMiss = 0;
+ double minValue = 0.0;
+ double maxValue = 0.0;
+ std::string sensorName;
+
+ public:
+ const std::string& getName(void) const
+ {
+ return sensorName;
+ }
+
+ void updateName(std::string_view name)
+ {
+ sensorName = name;
+ }
+
+ // Returns true if this is the first successful reading
+ // This is so the caller can log the coefficients used
+ bool updateReading(double reading, int raw)
+ {
+ if constexpr (!enableInstrumentation)
+ {
+ return false;
+ }
+
+ bool first = ((numReadings == 0) && (numMissings == 0));
+
+ // Sensors can use "nan" to indicate unavailable reading
+ if (!(std::isfinite(reading)))
+ {
+ // Only show this if beginning a new streak
+ if (numStreakMiss == 0)
+ {
+ std::cerr << "IPMI sensor " << sensorName
+ << ": Missing reading, byte=" << raw
+ << ", Reading counts good=" << numReadings
+ << " miss=" << numMissings
+ << ", Prior good streak=" << numStreakRead << "\n";
+ }
+
+ numStreakRead = 0;
+ ++numMissings;
+ ++numStreakMiss;
+
+ return first;
+ }
+
+ // Only show this if beginning a new streak and not the first time
+ if ((numStreakRead == 0) && (numReadings != 0))
+ {
+ std::cerr << "IPMI sensor " << sensorName
+ << ": Recovered reading, value=" << reading
+ << " byte=" << raw
+ << ", Reading counts good=" << numReadings
+ << " miss=" << numMissings
+ << ", Prior miss streak=" << numStreakMiss << "\n";
+ }
+
+ // Initialize min/max if the first successful reading
+ if (numReadings == 0)
+ {
+ std::cerr << "IPMI sensor " << sensorName
+ << ": First reading, value=" << reading << " byte=" << raw
+ << "\n";
+
+ minValue = reading;
+ maxValue = reading;
+ }
+
+ numStreakMiss = 0;
+ ++numReadings;
+ ++numStreakRead;
+
+ // Only provide subsequent output if new min/max established
+ if (reading < minValue)
+ {
+ std::cerr << "IPMI sensor " << sensorName
+ << ": Lowest reading, value=" << reading
+ << " byte=" << raw << "\n";
+
+ minValue = reading;
+ }
+
+ if (reading > maxValue)
+ {
+ std::cerr << "IPMI sensor " << sensorName
+ << ": Highest reading, value=" << reading
+ << " byte=" << raw << "\n";
+
+ maxValue = reading;
+ }
+
+ return first;
+ }
+};
+
+class IPMIStatsTable
+{
+ private:
+ std::vector<IPMIStatsEntry> entries;
+
+ private:
+ void padEntries(size_t index)
+ {
+ char hexbuf[16];
+
+ // Pad vector until entries[index] becomes a valid index
+ while (entries.size() <= index)
+ {
+ // As name not known yet, use human-readable hex as name
+ IPMIStatsEntry newEntry;
+ sprintf(hexbuf, "0x%02zX", entries.size());
+ newEntry.updateName(hexbuf);
+
+ entries.push_back(std::move(newEntry));
+ }
+ }
+
+ public:
+ void wipeTable(void)
+ {
+ entries.clear();
+ }
+
+ const std::string& getName(size_t index)
+ {
+ padEntries(index);
+ return entries[index].getName();
+ }
+
+ void updateName(size_t index, std::string_view name)
+ {
+ padEntries(index);
+ entries[index].updateName(name);
+ }
+
+ bool updateReading(size_t index, double reading, int raw)
+ {
+ padEntries(index);
+ return entries[index].updateReading(reading, raw);
+ }
+};
+
+// This object is global singleton, used from a variety of places
+inline IPMIStatsTable sdrStatsTable;
+
uint16_t getSensorSubtree(std::shared_ptr<SensorSubTree>& subtree);
bool getSensorNumMap(std::shared_ptr<SensorNumMap>& sensorNumMap);