blob: 90cf1d4178639558abc7c5ab310dc94e188e9922 [file] [log] [blame]
Patrick Venturef18bf832018-10-26 18:14:00 -07001#include "config.h"
2
3#include "log_manager.hpp"
4
5#include "elog_entry.hpp"
6#include "elog_meta.hpp"
7#include "elog_serialize.hpp"
Matt Spinler99c2b402019-05-23 14:29:16 -05008#include "extensions.hpp"
Matt Spinlerf61f2922020-06-23 11:32:49 -05009#include "util.hpp"
Patrick Venturef18bf832018-10-26 18:14:00 -070010
Adriana Kobylak5f4247f2018-03-15 10:27:05 -050011#include <poll.h>
Adriana Kobylak5f4247f2018-03-15 10:27:05 -050012#include <sys/inotify.h>
Adriana Kobylak1db1bd32016-10-10 11:39:20 -050013#include <systemd/sd-bus.h>
Adriana Kobylakd311bc82016-10-16 09:54:40 -050014#include <systemd/sd-journal.h>
Adriana Kobylak5f4247f2018-03-15 10:27:05 -050015#include <unistd.h>
Patrick Venturef18bf832018-10-26 18:14:00 -070016
Matt Spinler99c2b402019-05-23 14:29:16 -050017#include <cassert>
Patrick Venturef18bf832018-10-26 18:14:00 -070018#include <chrono>
19#include <cstdio>
Patrick Venture30047bf2018-11-01 18:52:15 -070020#include <cstring>
Patrick Venturef18bf832018-10-26 18:14:00 -070021#include <fstream>
Patrick Venture30047bf2018-11-01 18:52:15 -070022#include <functional>
Patrick Venturef18bf832018-10-26 18:14:00 -070023#include <future>
24#include <iostream>
Patrick Venture30047bf2018-11-01 18:52:15 -070025#include <map>
Saqib Khan2bb15192017-02-13 13:19:55 -060026#include <phosphor-logging/log.hpp>
Patrick Venturef18bf832018-10-26 18:14:00 -070027#include <sdbusplus/vtable.hpp>
28#include <set>
29#include <string>
30#include <vector>
Andrew Geisslerf6126a72020-05-08 10:41:09 -050031#include <xyz/openbmc_project/State/Host/server.hpp>
Deepak Kodihallia87c1572017-02-28 07:40:34 -060032
33using namespace phosphor::logging;
Adriana Kobylak5f4247f2018-03-15 10:27:05 -050034using namespace std::chrono;
Andrew Geisslerc0c500e2020-03-26 11:08:56 -050035using sdbusplus::exception::SdBusError;
Deepak Kodihallia87c1572017-02-28 07:40:34 -060036extern const std::map<metadata::Metadata,
Patrick Venturef18bf832018-10-26 18:14:00 -070037 std::function<metadata::associations::Type>>
38 meta;
Adriana Kobylak1db1bd32016-10-10 11:39:20 -050039
Adriana Kobylak8f7941e2016-11-14 14:46:23 -060040namespace phosphor
41{
42namespace logging
43{
Nagaraju Goruganti05aae8b2017-08-30 07:56:12 -050044namespace internal
45{
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050046inline auto getLevel(const std::string& errMsg)
47{
48 auto reqLevel = Entry::Level::Error; // Default to Error
49
50 auto levelmap = g_errLevelMap.find(errMsg);
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -050051 if (levelmap != g_errLevelMap.end())
Marri Devender Rao7656fba2017-08-06 05:42:52 -050052 {
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050053 reqLevel = static_cast<Entry::Level>(levelmap->second);
Marri Devender Rao7656fba2017-08-06 05:42:52 -050054 }
55
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050056 return reqLevel;
57}
58
Nagaraju Goruganti477b7312018-06-25 23:28:58 -050059int Manager::getRealErrSize()
60{
61 return realErrors.size();
62}
63
64int Manager::getInfoErrSize()
65{
66 return infoErrors.size();
67}
68
Lei YUb50c7052021-01-21 16:02:26 +080069uint32_t Manager::commit(uint64_t transactionId, std::string errMsg)
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050070{
71 auto level = getLevel(errMsg);
72 _commit(transactionId, std::move(errMsg), level);
Lei YUb50c7052021-01-21 16:02:26 +080073 return entryId;
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050074}
75
Lei YUb50c7052021-01-21 16:02:26 +080076uint32_t Manager::commitWithLvl(uint64_t transactionId, std::string errMsg,
77 uint32_t errLvl)
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050078{
79 _commit(transactionId, std::move(errMsg),
80 static_cast<Entry::Level>(errLvl));
Lei YUb50c7052021-01-21 16:02:26 +080081 return entryId;
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050082}
83
84void Manager::_commit(uint64_t transactionId, std::string&& errMsg,
85 Entry::Level errLvl)
86{
Adriana Kobylak7298dc22017-01-24 12:21:50 -060087 constexpr const auto transactionIdVar = "TRANSACTION_ID";
Adriana Kobylak27c87d92017-03-06 12:45:09 -060088 // Length of 'TRANSACTION_ID' string.
Patrick Venture30047bf2018-11-01 18:52:15 -070089 constexpr const auto transactionIdVarSize = std::strlen(transactionIdVar);
Adriana Kobylak27c87d92017-03-06 12:45:09 -060090 // Length of 'TRANSACTION_ID=' string.
91 constexpr const auto transactionIdVarOffset = transactionIdVarSize + 1;
Adriana Kobylak1db1bd32016-10-10 11:39:20 -050092
Adriana Kobylak5f4247f2018-03-15 10:27:05 -050093 // Flush all the pending log messages into the journal
94 journalSync();
Adriana Kobylakcfd9a7d2017-06-07 11:57:31 -050095
Patrick Venturef18bf832018-10-26 18:14:00 -070096 sd_journal* j = nullptr;
Adriana Kobylak8f7941e2016-11-14 14:46:23 -060097 int rc = sd_journal_open(&j, SD_JOURNAL_LOCAL_ONLY);
Adriana Kobylakd311bc82016-10-16 09:54:40 -050098 if (rc < 0)
99 {
Patrick Venturef18bf832018-10-26 18:14:00 -0700100 logging::log<logging::level::ERR>(
101 "Failed to open journal",
102 logging::entry("DESCRIPTION=%s", strerror(-rc)));
Adriana Kobylak8f7941e2016-11-14 14:46:23 -0600103 return;
Adriana Kobylakd311bc82016-10-16 09:54:40 -0500104 }
105
Adriana Kobylak7298dc22017-01-24 12:21:50 -0600106 std::string transactionIdStr = std::to_string(transactionId);
Adriana Kobylakd722b3a2017-02-28 12:10:44 -0600107 std::set<std::string> metalist;
108 auto metamap = g_errMetaMap.find(errMsg);
109 if (metamap != g_errMetaMap.end())
110 {
111 metalist.insert(metamap->second.begin(), metamap->second.end());
112 }
Adriana Kobylak7298dc22017-01-24 12:21:50 -0600113
Patrick Venturef18bf832018-10-26 18:14:00 -0700114 // Add _PID field information in AdditionalData.
Jayanth Othayothdb18ebe2017-09-04 00:48:02 -0500115 metalist.insert("_PID");
116
Tom Joseph7a33ee42017-07-25 00:04:20 +0530117 std::vector<std::string> additionalData;
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600118
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600119 // Read the journal from the end to get the most recent entry first.
120 // The result from the sd_journal_get_data() is of the form VARIABLE=value.
121 SD_JOURNAL_FOREACH_BACKWARDS(j)
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600122 {
Patrick Venturef18bf832018-10-26 18:14:00 -0700123 const char* data = nullptr;
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600124 size_t length = 0;
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600125
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600126 // Look for the transaction id metadata variable
Patrick Venturef18bf832018-10-26 18:14:00 -0700127 rc = sd_journal_get_data(j, transactionIdVar, (const void**)&data,
128 &length);
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600129 if (rc < 0)
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600130 {
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600131 // This journal entry does not have the TRANSACTION_ID
132 // metadata variable.
133 continue;
134 }
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600135
Adriana Kobylak27c87d92017-03-06 12:45:09 -0600136 // journald does not guarantee that sd_journal_get_data() returns NULL
137 // terminated strings, so need to specify the size to use to compare,
138 // use the returned length instead of anything that relies on NULL
139 // terminators like strlen().
140 // The data variable is in the form of 'TRANSACTION_ID=1234'. Remove
141 // the TRANSACTION_ID characters plus the (=) sign to do the comparison.
142 // 'data + transactionIdVarOffset' will be in the form of '1234'.
143 // 'length - transactionIdVarOffset' will be the length of '1234'.
144 if ((length <= (transactionIdVarOffset)) ||
Patrick Venturef18bf832018-10-26 18:14:00 -0700145 (transactionIdStr.compare(0, transactionIdStr.size(),
Adriana Kobylak27c87d92017-03-06 12:45:09 -0600146 data + transactionIdVarOffset,
147 length - transactionIdVarOffset) != 0))
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600148 {
149 // The value of the TRANSACTION_ID metadata is not the requested
150 // transaction id number.
151 continue;
152 }
153
154 // Search for all metadata variables in the current journal entry.
155 for (auto i = metalist.cbegin(); i != metalist.cend();)
156 {
Patrick Venturef18bf832018-10-26 18:14:00 -0700157 rc = sd_journal_get_data(j, (*i).c_str(), (const void**)&data,
158 &length);
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600159 if (rc < 0)
160 {
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600161 // Metadata variable not found, check next metadata variable.
162 i++;
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600163 continue;
164 }
165
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600166 // Metadata variable found, save it and remove it from the set.
167 additionalData.emplace_back(data, length);
168 i = metalist.erase(i);
169 }
170 if (metalist.empty())
171 {
172 // All metadata variables found, break out of journal loop.
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600173 break;
174 }
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600175 }
176 if (!metalist.empty())
177 {
178 // Not all the metadata variables were found in the journal.
179 for (auto& metaVarStr : metalist)
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600180 {
Patrick Venturef18bf832018-10-26 18:14:00 -0700181 logging::log<logging::level::INFO>(
182 "Failed to find metadata",
183 logging::entry("META_FIELD=%s", metaVarStr.c_str()));
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600184 }
185 }
186
Adriana Kobylakd311bc82016-10-16 09:54:40 -0500187 sd_journal_close(j);
188
Matt Spinlerb60e7552019-07-24 15:28:08 -0500189 createEntry(errMsg, errLvl, additionalData);
190}
191
192void Manager::createEntry(std::string errMsg, Entry::Level errLvl,
Matt Spinlerc64b7122020-03-26 10:55:01 -0500193 std::vector<std::string> additionalData,
194 const FFDCEntries& ffdc)
Matt Spinlerb60e7552019-07-24 15:28:08 -0500195{
196 if (!Extensions::disableDefaultLogCaps())
197 {
198 if (errLvl < Entry::sevLowerLimit)
199 {
200 if (realErrors.size() >= ERROR_CAP)
201 {
202 erase(realErrors.front());
203 }
204 }
205 else
206 {
207 if (infoErrors.size() >= ERROR_INFO_CAP)
208 {
209 erase(infoErrors.front());
210 }
211 }
212 }
213
Adriana Kobylak4ea7f312017-01-10 12:52:34 -0600214 entryId++;
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -0500215 if (errLvl >= Entry::sevLowerLimit)
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500216 {
217 infoErrors.push_back(entryId);
218 }
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600219 else
220 {
221 realErrors.push_back(entryId);
222 }
Adriana Kobylakc5f0bbd2017-01-22 14:56:04 -0600223 auto ms = std::chrono::duration_cast<std::chrono::milliseconds>(
Patrick Venturef18bf832018-10-26 18:14:00 -0700224 std::chrono::system_clock::now().time_since_epoch())
225 .count();
226 auto objPath = std::string(OBJ_ENTRY) + '/' + std::to_string(entryId);
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600227
Patrick Venturef18bf832018-10-26 18:14:00 -0700228 AssociationList objects{};
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600229 processMetadata(errMsg, additionalData, objects);
230
Patrick Venturef18bf832018-10-26 18:14:00 -0700231 auto e = std::make_unique<Entry>(busLog, objPath, entryId,
232 ms, // Milliseconds since 1970
233 errLvl, std::move(errMsg),
234 std::move(additionalData),
235 std::move(objects), fwVersion, *this);
Adriana Kobylak1ff95ef2020-12-03 13:52:19 -0600236 auto path = serialize(*e);
237 e->path(path);
Matt Spinler99c2b402019-05-23 14:29:16 -0500238
Andrew Geissler32874542020-07-09 09:17:03 -0500239 if (isQuiesceOnErrorEnabled() && isCalloutPresent(*e))
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500240 {
Andrew Geissler32874542020-07-09 09:17:03 -0500241 quiesceOnError(entryId);
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500242 }
243
Adriana Kobylake7d271a2020-12-07 14:32:44 -0600244 // Add entry before calling the extensions so that they have access to it
245 entries.insert(std::make_pair(entryId, std::move(e)));
246
247 doExtensionLogCreate(*entries.find(entryId)->second, ffdc);
Matt Spinlerc64b7122020-03-26 10:55:01 -0500248
249 // Note: No need to close the file descriptors in the FFDC.
Adriana Kobylak1db1bd32016-10-10 11:39:20 -0500250}
251
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500252bool Manager::isQuiesceOnErrorEnabled()
253{
254 std::variant<bool> property;
255
256 auto method = this->busLog.new_method_call(
257 "xyz.openbmc_project.Settings", "/xyz/openbmc_project/logging/settings",
258 "org.freedesktop.DBus.Properties", "Get");
259
260 method.append("xyz.openbmc_project.Logging.Settings", "QuiesceOnHwError");
261
262 try
263 {
264 auto reply = this->busLog.call(method);
265 reply.read(property);
266 }
267 catch (const SdBusError& e)
268 {
269 log<level::ERR>("Error reading QuiesceOnHwError property",
270 entry("ERROR=%s", e.what()));
271 throw;
272 }
273
274 return std::get<bool>(property);
275}
276
Andrew Geisslere4960ee2020-03-30 14:31:52 -0500277bool Manager::isCalloutPresent(const Entry& entry)
278{
279 for (const auto& c : entry.additionalData())
280 {
281 if (c.find("CALLOUT_") != std::string::npos)
282 {
283 return true;
284 }
285 }
286
287 return false;
288}
289
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500290void Manager::findAndRemoveResolvedBlocks()
291{
292 for (auto& entry : entries)
293 {
294 if (entry.second->resolved())
295 {
296 checkAndRemoveBlockingError(entry.first);
297 }
298 }
299}
300
301void Manager::onEntryResolve(sdbusplus::message::message& msg)
302{
303 using Interface = std::string;
304 using Property = std::string;
305 using Value = std::string;
Patrick Williams25acc6c2020-06-02 11:05:34 -0500306 using Properties = std::map<Property, std::variant<Value>>;
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500307
308 Interface interface;
309 Properties properties;
310
311 msg.read(interface, properties);
312
313 for (const auto& p : properties)
314 {
315 if (p.first == "Resolved")
316 {
317 findAndRemoveResolvedBlocks();
318 return;
319 }
320 }
321}
322
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500323void Manager::checkAndQuiesceHost()
324{
325 // First check host state
326 std::variant<std::string> property;
327
328 auto method = this->busLog.new_method_call(
329 "xyz.openbmc_project.State.Host", "/xyz/openbmc_project/state/host0",
330 "org.freedesktop.DBus.Properties", "Get");
331
332 method.append("xyz.openbmc_project.State.Host", "CurrentHostState");
333
334 try
335 {
336 auto reply = this->busLog.call(method);
337 reply.read(property);
338 }
339 catch (const SdBusError& e)
340 {
341 // Quiescing the host is a "best effort" type function. If unable to
342 // read the host state or it comes back empty, just return.
343 // The boot block object will still be created and the associations to
344 // find the log will be present. Don't want a dependency with
345 // phosphor-state-manager service
346 log<level::INFO>("Error reading QuiesceOnHwError property",
347 entry("ERROR=%s", e.what()));
348 return;
349 }
350
351 std::string hostState = std::get<std::string>(property);
352
353 // If host state is empty, do nothing
354 if (hostState.empty())
355 {
356 return;
357 }
358
359 using Host = sdbusplus::xyz::openbmc_project::State::server::Host;
360 auto state = Host::convertHostStateFromString(hostState);
361 if (state != Host::HostState::Running)
362 {
363 return;
364 }
365
366 auto quiesce = this->busLog.new_method_call(
367 "org.freedesktop.systemd1", "/org/freedesktop/systemd1",
368 "org.freedesktop.systemd1.Manager", "StartUnit");
369
370 quiesce.append("obmc-host-quiesce@0.target");
371 quiesce.append("replace");
372
373 this->busLog.call_noreply(quiesce);
374}
375
Andrew Geissler32874542020-07-09 09:17:03 -0500376void Manager::quiesceOnError(const uint32_t entryId)
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500377{
Andrew Geissler72a1cca2020-09-10 16:49:09 -0500378 // Verify we don't already have this entry blocking
379 auto it = find_if(
380 this->blockingErrors.begin(), this->blockingErrors.end(),
381 [&](std::unique_ptr<Block>& obj) { return obj->entryId == entryId; });
382 if (it != this->blockingErrors.end())
383 {
384 // Already recorded so just return
385 logging::log<logging::level::DEBUG>(
386 "QuiesceOnError set and callout present but entry already logged");
387 return;
388 }
Andrew Geisslere4960ee2020-03-30 14:31:52 -0500389
Andrew Geisslere4960ee2020-03-30 14:31:52 -0500390 logging::log<logging::level::INFO>(
391 "QuiesceOnError set and callout present");
Andrew Geissler6a0ef6f2020-04-06 15:06:31 -0500392
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500393 auto blockPath =
Andrew Geissler32874542020-07-09 09:17:03 -0500394 std::string(OBJ_LOGGING) + "/block" + std::to_string(entryId);
395 auto blockObj = std::make_unique<Block>(this->busLog, blockPath, entryId);
Andrew Geissler6a0ef6f2020-04-06 15:06:31 -0500396 this->blockingErrors.push_back(std::move(blockObj));
397
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500398 // Register call back if log is resolved
399 using namespace sdbusplus::bus::match::rules;
Andrew Geissler32874542020-07-09 09:17:03 -0500400 auto entryPath = std::string(OBJ_ENTRY) + '/' + std::to_string(entryId);
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500401 auto callback = std::make_unique<sdbusplus::bus::match::match>(
402 this->busLog,
403 propertiesChanged(entryPath, "xyz.openbmc_project.Logging.Entry"),
404 std::bind(std::mem_fn(&Manager::onEntryResolve), this,
405 std::placeholders::_1));
406
407 propChangedEntryCallback.insert(
Andrew Geissler32874542020-07-09 09:17:03 -0500408 std::make_pair(entryId, std::move(callback)));
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500409
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500410 checkAndQuiesceHost();
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500411}
412
Matt Spinlerc64b7122020-03-26 10:55:01 -0500413void Manager::doExtensionLogCreate(const Entry& entry, const FFDCEntries& ffdc)
Matt Spinler99c2b402019-05-23 14:29:16 -0500414{
415 // Make the association <endpointpath>/<endpointtype> paths
416 std::vector<std::string> assocs;
417 for (const auto& [forwardType, reverseType, endpoint] :
418 entry.associations())
419 {
420 std::string e{endpoint};
421 e += '/' + reverseType;
422 assocs.push_back(e);
423 }
424
425 for (auto& create : Extensions::getCreateFunctions())
426 {
427 try
428 {
429 create(entry.message(), entry.id(), entry.timestamp(),
Matt Spinlerc64b7122020-03-26 10:55:01 -0500430 entry.severity(), entry.additionalData(), assocs, ffdc);
Matt Spinler99c2b402019-05-23 14:29:16 -0500431 }
432 catch (std::exception& e)
433 {
434 log<level::ERR>("An extension's create function threw an exception",
435 phosphor::logging::entry("ERROR=%s", e.what()));
436 }
437 }
438}
439
Patrick Williamsf40323d2021-04-16 15:35:17 -0500440void Manager::processMetadata(const std::string& /*errorName*/,
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600441 const std::vector<std::string>& additionalData,
442 AssociationList& objects) const
443{
444 // additionalData is a list of "metadata=value"
445 constexpr auto separator = '=';
Patrick Venture34438962018-10-30 13:17:37 -0700446 for (const auto& entryItem : additionalData)
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600447 {
Patrick Venture34438962018-10-30 13:17:37 -0700448 auto found = entryItem.find(separator);
Patrick Venturef18bf832018-10-26 18:14:00 -0700449 if (std::string::npos != found)
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600450 {
Patrick Venture34438962018-10-30 13:17:37 -0700451 auto metadata = entryItem.substr(0, found);
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600452 auto iter = meta.find(metadata);
Patrick Venturef18bf832018-10-26 18:14:00 -0700453 if (meta.end() != iter)
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600454 {
455 (iter->second)(metadata, additionalData, objects);
456 }
457 }
458 }
459}
460
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500461void Manager::checkAndRemoveBlockingError(uint32_t entryId)
462{
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500463 // First look for blocking object and remove
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500464 auto it = find_if(
465 blockingErrors.begin(), blockingErrors.end(),
466 [&](std::unique_ptr<Block>& obj) { return obj->entryId == entryId; });
467 if (it != blockingErrors.end())
468 {
469 blockingErrors.erase(it);
470 }
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500471
472 // Now remove the callback looking for the error to be resolved
473 auto resolveFind = propChangedEntryCallback.find(entryId);
474 if (resolveFind != propChangedEntryCallback.end())
475 {
476 propChangedEntryCallback.erase(resolveFind);
477 }
478
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500479 return;
480}
481
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500482void Manager::erase(uint32_t entryId)
483{
Patrick Venture34438962018-10-30 13:17:37 -0700484 auto entryFound = entries.find(entryId);
485 if (entries.end() != entryFound)
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500486 {
Matt Spinler99c2b402019-05-23 14:29:16 -0500487 for (auto& func : Extensions::getDeleteProhibitedFunctions())
488 {
489 try
490 {
491 bool prohibited = false;
492 func(entryId, prohibited);
493 if (prohibited)
494 {
495 // Future work remains to throw an error here.
496 return;
497 }
498 }
499 catch (std::exception& e)
500 {
501 log<level::ERR>(
502 "An extension's deleteProhibited function threw "
503 "an exception",
504 entry("ERROR=%s", e.what()));
505 }
506 }
507
Deepak Kodihalli33887992017-06-13 07:06:49 -0500508 // Delete the persistent representation of this error.
509 fs::path errorPath(ERRLOG_PERSIST_PATH);
Marri Devender Rao8959efc2017-11-17 00:13:41 -0600510 errorPath /= std::to_string(entryId);
Deepak Kodihalli33887992017-06-13 07:06:49 -0500511 fs::remove(errorPath);
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600512
Patrick Venturef18bf832018-10-26 18:14:00 -0700513 auto removeId = [](std::list<uint32_t>& ids, uint32_t id) {
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600514 auto it = std::find(ids.begin(), ids.end(), id);
515 if (it != ids.end())
516 {
517 ids.erase(it);
518 }
519 };
Patrick Venture34438962018-10-30 13:17:37 -0700520 if (entryFound->second->severity() >= Entry::sevLowerLimit)
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500521 {
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600522 removeId(infoErrors, entryId);
523 }
524 else
525 {
526 removeId(realErrors, entryId);
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500527 }
Patrick Venture34438962018-10-30 13:17:37 -0700528 entries.erase(entryFound);
Matt Spinler99c2b402019-05-23 14:29:16 -0500529
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500530 checkAndRemoveBlockingError(entryId);
531
Matt Spinler99c2b402019-05-23 14:29:16 -0500532 for (auto& remove : Extensions::getDeleteFunctions())
533 {
534 try
535 {
536 remove(entryId);
537 }
538 catch (std::exception& e)
539 {
540 log<level::ERR>("An extension's delete function threw an "
541 "exception",
542 entry("ERROR=%s", e.what()));
543 }
544 }
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500545 }
Marri Devender Rao8959efc2017-11-17 00:13:41 -0600546 else
547 {
548 logging::log<level::ERR>("Invalid entry ID to delete",
Patrick Venturef18bf832018-10-26 18:14:00 -0700549 logging::entry("ID=%d", entryId));
Marri Devender Rao8959efc2017-11-17 00:13:41 -0600550 }
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500551}
552
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500553void Manager::restore()
554{
Patrick Venturef18bf832018-10-26 18:14:00 -0700555 auto sanity = [](const auto& id, const auto& restoredId) {
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600556 return id == restoredId;
557 };
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500558 std::vector<uint32_t> errorIds;
559
560 fs::path dir(ERRLOG_PERSIST_PATH);
561 if (!fs::exists(dir) || fs::is_empty(dir))
562 {
563 return;
564 }
565
Patrick Venturef18bf832018-10-26 18:14:00 -0700566 for (auto& file : fs::directory_iterator(dir))
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500567 {
568 auto id = file.path().filename().c_str();
569 auto idNum = std::stol(id);
570 auto e = std::make_unique<Entry>(
Patrick Venturef18bf832018-10-26 18:14:00 -0700571 busLog, std::string(OBJ_ENTRY) + '/' + id, idNum, *this);
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500572 if (deserialize(file.path(), *e))
573 {
Patrick Venturef18bf832018-10-26 18:14:00 -0700574 // validate the restored error entry id
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600575 if (sanity(static_cast<uint32_t>(idNum), e->id()))
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500576 {
Adriana Kobylak1ff95ef2020-12-03 13:52:19 -0600577 e->path(file.path());
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600578 e->emit_object_added();
579 if (e->severity() >= Entry::sevLowerLimit)
580 {
581 infoErrors.push_back(idNum);
582 }
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600583 else
584 {
585 realErrors.push_back(idNum);
586 }
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600587
588 entries.insert(std::make_pair(idNum, std::move(e)));
589 errorIds.push_back(idNum);
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500590 }
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600591 else
592 {
593 logging::log<logging::level::ERR>(
594 "Failed in sanity check while restoring error entry. "
595 "Ignoring error entry",
596 logging::entry("ID_NUM=%d", idNum),
597 logging::entry("ENTRY_ID=%d", e->id()));
598 }
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500599 }
600 }
601
Vishwanatha Subbanna37af9ba2017-09-28 16:33:53 +0530602 if (!errorIds.empty())
603 {
604 entryId = *(std::max_element(errorIds.begin(), errorIds.end()));
605 }
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500606}
607
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500608void Manager::journalSync()
609{
610 bool syncRequested = false;
611 auto fd = -1;
612 auto rc = -1;
613 auto wd = -1;
614 auto bus = sdbusplus::bus::new_default();
615
616 auto start =
617 duration_cast<microseconds>(steady_clock::now().time_since_epoch())
618 .count();
619
Matthew Barth59913892019-08-27 15:43:48 -0500620 // Each time an error log is committed, a request to sync the journal
621 // must occur and block that error log commit until it completes. A 5sec
622 // block is done to allow sufficient time for the journal to be synced.
623 //
624 // Number of loop iterations = 3 for the following reasons:
625 // Iteration #1: Requests a journal sync by killing the journald service.
626 // Iteration #2: Setup an inotify watch to monitor the synced file that
627 // journald updates with the timestamp the last time the
628 // journal was flushed.
629 // Iteration #3: Poll to wait until inotify reports an event which blocks
630 // the error log from being commited until the sync completes.
631 constexpr auto maxRetry = 3;
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500632 for (int i = 0; i < maxRetry; i++)
633 {
634 // Read timestamp from synced file
635 constexpr auto syncedPath = "/run/systemd/journal/synced";
636 std::ifstream syncedFile(syncedPath);
637 if (syncedFile.fail())
638 {
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500639 // If the synced file doesn't exist, a sync request will create it.
640 if (errno != ENOENT)
641 {
642 log<level::ERR>("Failed to open journal synced file",
643 entry("FILENAME=%s", syncedPath),
644 entry("ERRNO=%d", errno));
645 return;
646 }
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500647 }
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500648 else
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500649 {
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500650 // Only read the synced file if it exists.
651 // See if a sync happened by now
652 std::string timestampStr;
653 std::getline(syncedFile, timestampStr);
Patrick Venture30047bf2018-11-01 18:52:15 -0700654 auto timestamp = std::stoll(timestampStr);
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500655 if (timestamp >= start)
656 {
Troy Leeb7f392a2019-11-19 14:34:56 +0800657 break;
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500658 }
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500659 }
660
661 // Let's ask for a sync, but only once
662 if (!syncRequested)
663 {
664 syncRequested = true;
665
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500666 constexpr auto JOURNAL_UNIT = "systemd-journald.service";
667 auto signal = SIGRTMIN + 1;
668
669 auto method = bus.new_method_call(SYSTEMD_BUSNAME, SYSTEMD_PATH,
670 SYSTEMD_INTERFACE, "KillUnit");
671 method.append(JOURNAL_UNIT, "main", signal);
672 bus.call(method);
673 if (method.is_method_error())
674 {
675 log<level::ERR>("Failed to kill journal service");
Troy Leeb7f392a2019-11-19 14:34:56 +0800676 break;
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500677 }
678 continue;
679 }
680
681 // Let's install the inotify watch, if we didn't do that yet. This watch
682 // monitors the syncedFile for when journald updates it with a newer
683 // timestamp. This means the journal has been flushed.
684 if (fd < 0)
685 {
686 fd = inotify_init1(IN_NONBLOCK | IN_CLOEXEC);
687 if (fd < 0)
688 {
689 log<level::ERR>("Failed to create inotify watch",
690 entry("ERRNO=%d", errno));
691 return;
692 }
693
694 constexpr auto JOURNAL_RUN_PATH = "/run/systemd/journal";
695 wd = inotify_add_watch(fd, JOURNAL_RUN_PATH,
696 IN_MOVED_TO | IN_DONT_FOLLOW | IN_ONLYDIR);
697 if (wd < 0)
698 {
699 log<level::ERR>("Failed to watch journal directory",
700 entry("PATH=%s", JOURNAL_RUN_PATH),
701 entry("ERRNO=%d", errno));
702 close(fd);
703 return;
704 }
705 continue;
706 }
707
708 // Let's wait until inotify reports an event
709 struct pollfd fds = {
710 .fd = fd,
711 .events = POLLIN,
Patrick Williamsf40323d2021-04-16 15:35:17 -0500712 .revents = 0,
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500713 };
714 constexpr auto pollTimeout = 5; // 5 seconds
715 rc = poll(&fds, 1, pollTimeout * 1000);
716 if (rc < 0)
717 {
718 log<level::ERR>("Failed to add event", entry("ERRNO=%d", errno),
719 entry("ERR=%s", strerror(-rc)));
720 inotify_rm_watch(fd, wd);
721 close(fd);
722 return;
723 }
724 else if (rc == 0)
725 {
726 log<level::INFO>("Poll timeout, no new journal synced data",
727 entry("TIMEOUT=%d", pollTimeout));
728 break;
729 }
730
731 // Read from the specified file descriptor until there is no new data,
732 // throwing away everything read since the timestamp will be read at the
733 // beginning of the loop.
734 constexpr auto maxBytes = 64;
735 uint8_t buffer[maxBytes];
736 while (read(fd, buffer, maxBytes) > 0)
737 ;
738 }
739
Adriana Kobylak4a029f22018-05-23 12:58:19 -0500740 if (fd != -1)
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500741 {
Adriana Kobylak4a029f22018-05-23 12:58:19 -0500742 if (wd != -1)
743 {
744 inotify_rm_watch(fd, wd);
745 }
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500746 close(fd);
747 }
748
749 return;
750}
751
Matt Spinler1275bd12018-05-01 15:13:53 -0500752std::string Manager::readFWVersion()
753{
Matt Spinlerf61f2922020-06-23 11:32:49 -0500754 auto version = util::getOSReleaseValue("VERSION_ID");
Matt Spinler1275bd12018-05-01 15:13:53 -0500755
Matt Spinlerf61f2922020-06-23 11:32:49 -0500756 if (!version)
Matt Spinler1275bd12018-05-01 15:13:53 -0500757 {
758 log<level::ERR>("Unable to read BMC firmware version");
759 }
760
Matt Spinlerf61f2922020-06-23 11:32:49 -0500761 return version.value_or("");
Matt Spinler1275bd12018-05-01 15:13:53 -0500762}
763
Matt Spinler3fb83b32019-07-26 11:22:44 -0500764void Manager::create(const std::string& message, Entry::Level severity,
765 const std::map<std::string, std::string>& additionalData)
766{
767 // Convert the map into a vector of "key=value" strings
768 std::vector<std::string> ad;
769 metadata::associations::combine(additionalData, ad);
770
771 createEntry(message, severity, ad);
772}
773
Matt Spinlerc64b7122020-03-26 10:55:01 -0500774void Manager::createWithFFDC(
775 const std::string& message, Entry::Level severity,
776 const std::map<std::string, std::string>& additionalData,
777 const FFDCEntries& ffdc)
778{
779 // Convert the map into a vector of "key=value" strings
780 std::vector<std::string> ad;
781 metadata::associations::combine(additionalData, ad);
782
783 createEntry(message, severity, ad, ffdc);
784}
785
Nagaraju Goruganti05aae8b2017-08-30 07:56:12 -0500786} // namespace internal
Adriana Kobylak8f7941e2016-11-14 14:46:23 -0600787} // namespace logging
Patrick Venturef18bf832018-10-26 18:14:00 -0700788} // namespace phosphor