blob: 75bab7df2b1569b8efbebd9494a4365b93914889 [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>
Patrick Williams5f285c52021-07-27 21:25:38 -050026#include <phosphor-logging/lg2.hpp>
Patrick Venturef18bf832018-10-26 18:14:00 -070027#include <sdbusplus/vtable.hpp>
28#include <set>
29#include <string>
Patrick Williamsb01a5b42021-08-28 15:11:45 -050030#include <string_view>
Patrick Venturef18bf832018-10-26 18:14:00 -070031#include <vector>
Andrew Geisslerf6126a72020-05-08 10:41:09 -050032#include <xyz/openbmc_project/State/Host/server.hpp>
Deepak Kodihallia87c1572017-02-28 07:40:34 -060033
Adriana Kobylak5f4247f2018-03-15 10:27:05 -050034using namespace std::chrono;
Patrick Williams5f285c52021-07-27 21:25:38 -050035extern const std::map<
36 phosphor::logging::metadata::Metadata,
37 std::function<phosphor::logging::metadata::associations::Type>>
Patrick Venturef18bf832018-10-26 18:14:00 -070038 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
Patrick Williamsa5171972021-04-16 20:10:01 -050084void Manager::_commit(uint64_t transactionId [[maybe_unused]],
85 std::string&& errMsg, Entry::Level errLvl)
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -050086{
Patrick Williamsa5171972021-04-16 20:10:01 -050087 std::vector<std::string> additionalData{};
88
89 // When running as a test-case, the system may have a LOT of journal
90 // data and we may not have permissions to do some of the journal sync
91 // operations. Just skip over them.
William A. Kennington IIIb6b25572021-05-19 17:09:41 -070092 if (!IS_UNIT_TEST)
Adriana Kobylakd311bc82016-10-16 09:54:40 -050093 {
Patrick Williamsb01a5b42021-08-28 15:11:45 -050094 static constexpr auto transactionIdVar =
95 std::string_view{"TRANSACTION_ID"};
William A. Kennington IIIb6b25572021-05-19 17:09:41 -070096 // Length of 'TRANSACTION_ID' string.
Patrick Williamsb01a5b42021-08-28 15:11:45 -050097 static constexpr auto transactionIdVarSize = transactionIdVar.size();
William A. Kennington IIIb6b25572021-05-19 17:09:41 -070098 // Length of 'TRANSACTION_ID=' string.
Patrick Williamsb01a5b42021-08-28 15:11:45 -050099 static constexpr auto transactionIdVarOffset = transactionIdVarSize + 1;
Adriana Kobylakd311bc82016-10-16 09:54:40 -0500100
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700101 // Flush all the pending log messages into the journal
102 journalSync();
Adriana Kobylak7298dc22017-01-24 12:21:50 -0600103
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700104 sd_journal* j = nullptr;
105 int rc = sd_journal_open(&j, SD_JOURNAL_LOCAL_ONLY);
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600106 if (rc < 0)
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600107 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500108 lg2::error("Failed to open journal: {ERROR}", "ERROR",
109 strerror(-rc));
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700110 return;
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600111 }
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600112
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700113 std::string transactionIdStr = std::to_string(transactionId);
114 std::set<std::string> metalist;
115 auto metamap = g_errMetaMap.find(errMsg);
116 if (metamap != g_errMetaMap.end())
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600117 {
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700118 metalist.insert(metamap->second.begin(), metamap->second.end());
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600119 }
120
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700121 // Add _PID field information in AdditionalData.
122 metalist.insert("_PID");
123
124 // Read the journal from the end to get the most recent entry first.
125 // The result from the sd_journal_get_data() is of the form
126 // VARIABLE=value.
127 SD_JOURNAL_FOREACH_BACKWARDS(j)
Adriana Kobylakfbe88722017-02-22 16:49:59 -0600128 {
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700129 const char* data = nullptr;
130 size_t length = 0;
131
132 // Look for the transaction id metadata variable
Patrick Williamsb01a5b42021-08-28 15:11:45 -0500133 rc = sd_journal_get_data(j, transactionIdVar.data(),
134 (const void**)&data, &length);
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600135 if (rc < 0)
136 {
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700137 // This journal entry does not have the TRANSACTION_ID
138 // metadata variable.
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600139 continue;
140 }
141
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700142 // journald does not guarantee that sd_journal_get_data() returns
143 // NULL terminated strings, so need to specify the size to use to
144 // compare, use the returned length instead of anything that relies
145 // on NULL terminators like strlen(). The data variable is in the
146 // form of 'TRANSACTION_ID=1234'. Remove the TRANSACTION_ID
147 // characters plus the (=) sign to do the comparison. 'data +
148 // transactionIdVarOffset' will be in the form of '1234'. 'length -
149 // transactionIdVarOffset' will be the length of '1234'.
150 if ((length <= (transactionIdVarOffset)) ||
151 (transactionIdStr.compare(
152 0, transactionIdStr.size(), data + transactionIdVarOffset,
153 length - transactionIdVarOffset) != 0))
154 {
155 // The value of the TRANSACTION_ID metadata is not the requested
156 // transaction id number.
157 continue;
158 }
Adriana Kobylak9aa7d782017-02-18 09:20:49 -0600159
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700160 // Search for all metadata variables in the current journal entry.
161 for (auto i = metalist.cbegin(); i != metalist.cend();)
162 {
163 rc = sd_journal_get_data(j, (*i).c_str(), (const void**)&data,
164 &length);
165 if (rc < 0)
166 {
167 // Metadata variable not found, check next metadata
168 // variable.
169 i++;
170 continue;
171 }
Adriana Kobylakd311bc82016-10-16 09:54:40 -0500172
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700173 // Metadata variable found, save it and remove it from the set.
174 additionalData.emplace_back(data, length);
175 i = metalist.erase(i);
176 }
177 if (metalist.empty())
178 {
179 // All metadata variables found, break out of journal loop.
180 break;
181 }
182 }
183 if (!metalist.empty())
184 {
185 // Not all the metadata variables were found in the journal.
186 for (auto& metaVarStr : metalist)
187 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500188 lg2::info("Failed to find metadata: {META_FIELD}", "META_FIELD",
189 metaVarStr);
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700190 }
191 }
192
193 sd_journal_close(j);
194 }
Matt Spinlerb60e7552019-07-24 15:28:08 -0500195 createEntry(errMsg, errLvl, additionalData);
196}
197
198void Manager::createEntry(std::string errMsg, Entry::Level errLvl,
Matt Spinlerc64b7122020-03-26 10:55:01 -0500199 std::vector<std::string> additionalData,
200 const FFDCEntries& ffdc)
Matt Spinlerb60e7552019-07-24 15:28:08 -0500201{
202 if (!Extensions::disableDefaultLogCaps())
203 {
204 if (errLvl < Entry::sevLowerLimit)
205 {
206 if (realErrors.size() >= ERROR_CAP)
207 {
208 erase(realErrors.front());
209 }
210 }
211 else
212 {
213 if (infoErrors.size() >= ERROR_INFO_CAP)
214 {
215 erase(infoErrors.front());
216 }
217 }
218 }
219
Adriana Kobylak4ea7f312017-01-10 12:52:34 -0600220 entryId++;
Deepak Kodihalli6fd9dc42018-04-03 02:08:42 -0500221 if (errLvl >= Entry::sevLowerLimit)
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500222 {
223 infoErrors.push_back(entryId);
224 }
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600225 else
226 {
227 realErrors.push_back(entryId);
228 }
Adriana Kobylakc5f0bbd2017-01-22 14:56:04 -0600229 auto ms = std::chrono::duration_cast<std::chrono::milliseconds>(
Patrick Venturef18bf832018-10-26 18:14:00 -0700230 std::chrono::system_clock::now().time_since_epoch())
231 .count();
232 auto objPath = std::string(OBJ_ENTRY) + '/' + std::to_string(entryId);
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600233
Patrick Venturef18bf832018-10-26 18:14:00 -0700234 AssociationList objects{};
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600235 processMetadata(errMsg, additionalData, objects);
236
Matt Spinlerfb978da2022-01-21 08:42:24 -0600237 auto e = std::make_unique<Entry>(
238 busLog, objPath, entryId,
239 ms, // Milliseconds since 1970
240 errLvl, std::move(errMsg), std::move(additionalData),
241 std::move(objects), fwVersion, getEntrySerializePath(entryId), *this);
242
243 serialize(*e);
Matt Spinler99c2b402019-05-23 14:29:16 -0500244
Matt Spinler601b8112022-01-26 13:18:04 -0600245 if (isQuiesceOnErrorEnabled() && (errLvl < Entry::sevLowerLimit) &&
246 isCalloutPresent(*e))
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500247 {
Andrew Geissler32874542020-07-09 09:17:03 -0500248 quiesceOnError(entryId);
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500249 }
250
Adriana Kobylake7d271a2020-12-07 14:32:44 -0600251 // Add entry before calling the extensions so that they have access to it
252 entries.insert(std::make_pair(entryId, std::move(e)));
253
254 doExtensionLogCreate(*entries.find(entryId)->second, ffdc);
Matt Spinlerc64b7122020-03-26 10:55:01 -0500255
256 // Note: No need to close the file descriptors in the FFDC.
Adriana Kobylak1db1bd32016-10-10 11:39:20 -0500257}
258
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500259bool Manager::isQuiesceOnErrorEnabled()
260{
Patrick Williamsa5171972021-04-16 20:10:01 -0500261 // When running under tests, the Logging.Settings service will not be
262 // present. Assume false.
William A. Kennington IIIb6b25572021-05-19 17:09:41 -0700263 if (IS_UNIT_TEST)
264 {
265 return false;
266 }
Patrick Williamsa5171972021-04-16 20:10:01 -0500267
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500268 std::variant<bool> property;
269
270 auto method = this->busLog.new_method_call(
271 "xyz.openbmc_project.Settings", "/xyz/openbmc_project/logging/settings",
272 "org.freedesktop.DBus.Properties", "Get");
273
274 method.append("xyz.openbmc_project.Logging.Settings", "QuiesceOnHwError");
275
276 try
277 {
278 auto reply = this->busLog.call(method);
279 reply.read(property);
280 }
Patrick Williamse99a4fd2021-09-02 09:44:53 -0500281 catch (const sdbusplus::exception::exception& e)
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500282 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500283 lg2::error("Error reading QuiesceOnHwError property: {ERROR}", "ERROR",
284 e);
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500285 throw;
286 }
287
288 return std::get<bool>(property);
289}
290
Andrew Geisslere4960ee2020-03-30 14:31:52 -0500291bool Manager::isCalloutPresent(const Entry& entry)
292{
293 for (const auto& c : entry.additionalData())
294 {
295 if (c.find("CALLOUT_") != std::string::npos)
296 {
297 return true;
298 }
299 }
300
301 return false;
302}
303
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500304void Manager::findAndRemoveResolvedBlocks()
305{
306 for (auto& entry : entries)
307 {
308 if (entry.second->resolved())
309 {
310 checkAndRemoveBlockingError(entry.first);
311 }
312 }
313}
314
315void Manager::onEntryResolve(sdbusplus::message::message& msg)
316{
317 using Interface = std::string;
318 using Property = std::string;
319 using Value = std::string;
Patrick Williams25acc6c2020-06-02 11:05:34 -0500320 using Properties = std::map<Property, std::variant<Value>>;
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500321
322 Interface interface;
323 Properties properties;
324
325 msg.read(interface, properties);
326
327 for (const auto& p : properties)
328 {
329 if (p.first == "Resolved")
330 {
331 findAndRemoveResolvedBlocks();
332 return;
333 }
334 }
335}
336
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500337void Manager::checkAndQuiesceHost()
338{
Patrick Williamsa144a272021-07-16 17:03:55 -0500339 using Host = sdbusplus::xyz::openbmc_project::State::server::Host;
340
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500341 // First check host state
Patrick Williamsa144a272021-07-16 17:03:55 -0500342 std::variant<Host::HostState> property;
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500343
344 auto method = this->busLog.new_method_call(
345 "xyz.openbmc_project.State.Host", "/xyz/openbmc_project/state/host0",
346 "org.freedesktop.DBus.Properties", "Get");
347
348 method.append("xyz.openbmc_project.State.Host", "CurrentHostState");
349
350 try
351 {
352 auto reply = this->busLog.call(method);
353 reply.read(property);
354 }
Patrick Williamse99a4fd2021-09-02 09:44:53 -0500355 catch (const sdbusplus::exception::exception& e)
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500356 {
357 // Quiescing the host is a "best effort" type function. If unable to
358 // read the host state or it comes back empty, just return.
359 // The boot block object will still be created and the associations to
360 // find the log will be present. Don't want a dependency with
361 // phosphor-state-manager service
Patrick Williams5f285c52021-07-27 21:25:38 -0500362 lg2::info("Error reading QuiesceOnHwError property: {ERROR}", "ERROR",
363 e);
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500364 return;
365 }
366
Patrick Williamsa144a272021-07-16 17:03:55 -0500367 auto hostState = std::get<Host::HostState>(property);
368 if (hostState != Host::HostState::Running)
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500369 {
370 return;
371 }
372
373 auto quiesce = this->busLog.new_method_call(
374 "org.freedesktop.systemd1", "/org/freedesktop/systemd1",
375 "org.freedesktop.systemd1.Manager", "StartUnit");
376
Andrew Geissler86a60e92022-04-15 14:36:02 -0500377 quiesce.append("obmc-host-graceful-quiesce@0.target");
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500378 quiesce.append("replace");
379
380 this->busLog.call_noreply(quiesce);
381}
382
Andrew Geissler32874542020-07-09 09:17:03 -0500383void Manager::quiesceOnError(const uint32_t entryId)
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500384{
Andrew Geissler72a1cca2020-09-10 16:49:09 -0500385 // Verify we don't already have this entry blocking
386 auto it = find_if(
387 this->blockingErrors.begin(), this->blockingErrors.end(),
388 [&](std::unique_ptr<Block>& obj) { return obj->entryId == entryId; });
389 if (it != this->blockingErrors.end())
390 {
391 // Already recorded so just return
Patrick Williams5f285c52021-07-27 21:25:38 -0500392 lg2::debug(
Andrew Geissler72a1cca2020-09-10 16:49:09 -0500393 "QuiesceOnError set and callout present but entry already logged");
394 return;
395 }
Andrew Geisslere4960ee2020-03-30 14:31:52 -0500396
Patrick Williams5f285c52021-07-27 21:25:38 -0500397 lg2::info("QuiesceOnError set and callout present");
Andrew Geissler6a0ef6f2020-04-06 15:06:31 -0500398
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500399 auto blockPath =
Andrew Geissler32874542020-07-09 09:17:03 -0500400 std::string(OBJ_LOGGING) + "/block" + std::to_string(entryId);
401 auto blockObj = std::make_unique<Block>(this->busLog, blockPath, entryId);
Andrew Geissler6a0ef6f2020-04-06 15:06:31 -0500402 this->blockingErrors.push_back(std::move(blockObj));
403
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500404 // Register call back if log is resolved
405 using namespace sdbusplus::bus::match::rules;
Andrew Geissler32874542020-07-09 09:17:03 -0500406 auto entryPath = std::string(OBJ_ENTRY) + '/' + std::to_string(entryId);
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500407 auto callback = std::make_unique<sdbusplus::bus::match::match>(
408 this->busLog,
409 propertiesChanged(entryPath, "xyz.openbmc_project.Logging.Entry"),
410 std::bind(std::mem_fn(&Manager::onEntryResolve), this,
411 std::placeholders::_1));
412
413 propChangedEntryCallback.insert(
Andrew Geissler32874542020-07-09 09:17:03 -0500414 std::make_pair(entryId, std::move(callback)));
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500415
Andrew Geisslerf6126a72020-05-08 10:41:09 -0500416 checkAndQuiesceHost();
Andrew Geisslerc0c500e2020-03-26 11:08:56 -0500417}
418
Matt Spinlerc64b7122020-03-26 10:55:01 -0500419void Manager::doExtensionLogCreate(const Entry& entry, const FFDCEntries& ffdc)
Matt Spinler99c2b402019-05-23 14:29:16 -0500420{
421 // Make the association <endpointpath>/<endpointtype> paths
422 std::vector<std::string> assocs;
423 for (const auto& [forwardType, reverseType, endpoint] :
424 entry.associations())
425 {
426 std::string e{endpoint};
427 e += '/' + reverseType;
428 assocs.push_back(e);
429 }
430
431 for (auto& create : Extensions::getCreateFunctions())
432 {
433 try
434 {
435 create(entry.message(), entry.id(), entry.timestamp(),
Matt Spinlerc64b7122020-03-26 10:55:01 -0500436 entry.severity(), entry.additionalData(), assocs, ffdc);
Matt Spinler99c2b402019-05-23 14:29:16 -0500437 }
Patrick Williams66491c62021-10-06 12:23:37 -0500438 catch (const std::exception& e)
Matt Spinler99c2b402019-05-23 14:29:16 -0500439 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500440 lg2::error(
441 "An extension's create function threw an exception: {ERROR}",
442 "ERROR", e);
Matt Spinler99c2b402019-05-23 14:29:16 -0500443 }
444 }
445}
446
Patrick Williamsf40323d2021-04-16 15:35:17 -0500447void Manager::processMetadata(const std::string& /*errorName*/,
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600448 const std::vector<std::string>& additionalData,
449 AssociationList& objects) const
450{
451 // additionalData is a list of "metadata=value"
452 constexpr auto separator = '=';
Patrick Venture34438962018-10-30 13:17:37 -0700453 for (const auto& entryItem : additionalData)
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600454 {
Patrick Venture34438962018-10-30 13:17:37 -0700455 auto found = entryItem.find(separator);
Patrick Venturef18bf832018-10-26 18:14:00 -0700456 if (std::string::npos != found)
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600457 {
Patrick Venture34438962018-10-30 13:17:37 -0700458 auto metadata = entryItem.substr(0, found);
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600459 auto iter = meta.find(metadata);
Patrick Venturef18bf832018-10-26 18:14:00 -0700460 if (meta.end() != iter)
Deepak Kodihallia87c1572017-02-28 07:40:34 -0600461 {
462 (iter->second)(metadata, additionalData, objects);
463 }
464 }
465 }
466}
467
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500468void Manager::checkAndRemoveBlockingError(uint32_t entryId)
469{
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500470 // First look for blocking object and remove
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500471 auto it = find_if(
472 blockingErrors.begin(), blockingErrors.end(),
473 [&](std::unique_ptr<Block>& obj) { return obj->entryId == entryId; });
474 if (it != blockingErrors.end())
475 {
476 blockingErrors.erase(it);
477 }
Andrew Geissler7f6d4bc2020-04-16 14:47:34 -0500478
479 // Now remove the callback looking for the error to be resolved
480 auto resolveFind = propChangedEntryCallback.find(entryId);
481 if (resolveFind != propChangedEntryCallback.end())
482 {
483 propChangedEntryCallback.erase(resolveFind);
484 }
485
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500486 return;
487}
488
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500489void Manager::erase(uint32_t entryId)
490{
Patrick Venture34438962018-10-30 13:17:37 -0700491 auto entryFound = entries.find(entryId);
492 if (entries.end() != entryFound)
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500493 {
Matt Spinler99c2b402019-05-23 14:29:16 -0500494 for (auto& func : Extensions::getDeleteProhibitedFunctions())
495 {
496 try
497 {
498 bool prohibited = false;
499 func(entryId, prohibited);
500 if (prohibited)
501 {
502 // Future work remains to throw an error here.
503 return;
504 }
505 }
Patrick Williams66491c62021-10-06 12:23:37 -0500506 catch (const std::exception& e)
Matt Spinler99c2b402019-05-23 14:29:16 -0500507 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500508 lg2::error("An extension's deleteProhibited function threw an "
509 "exception: {ERROR}",
510 "ERROR", e);
Matt Spinler99c2b402019-05-23 14:29:16 -0500511 }
512 }
513
Deepak Kodihalli33887992017-06-13 07:06:49 -0500514 // Delete the persistent representation of this error.
515 fs::path errorPath(ERRLOG_PERSIST_PATH);
Marri Devender Rao8959efc2017-11-17 00:13:41 -0600516 errorPath /= std::to_string(entryId);
Deepak Kodihalli33887992017-06-13 07:06:49 -0500517 fs::remove(errorPath);
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600518
Patrick Venturef18bf832018-10-26 18:14:00 -0700519 auto removeId = [](std::list<uint32_t>& ids, uint32_t id) {
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600520 auto it = std::find(ids.begin(), ids.end(), id);
521 if (it != ids.end())
522 {
523 ids.erase(it);
524 }
525 };
Patrick Venture34438962018-10-30 13:17:37 -0700526 if (entryFound->second->severity() >= Entry::sevLowerLimit)
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500527 {
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600528 removeId(infoErrors, entryId);
529 }
530 else
531 {
532 removeId(realErrors, entryId);
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500533 }
Patrick Venture34438962018-10-30 13:17:37 -0700534 entries.erase(entryFound);
Matt Spinler99c2b402019-05-23 14:29:16 -0500535
Andrew Geisslerced6e2a2020-04-07 16:15:29 -0500536 checkAndRemoveBlockingError(entryId);
537
Matt Spinler99c2b402019-05-23 14:29:16 -0500538 for (auto& remove : Extensions::getDeleteFunctions())
539 {
540 try
541 {
542 remove(entryId);
543 }
Patrick Williams66491c62021-10-06 12:23:37 -0500544 catch (const std::exception& e)
Matt Spinler99c2b402019-05-23 14:29:16 -0500545 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500546 lg2::error("An extension's delete function threw an exception: "
547 "{ERROR}",
548 "ERROR", e);
Matt Spinler99c2b402019-05-23 14:29:16 -0500549 }
550 }
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500551 }
Marri Devender Rao8959efc2017-11-17 00:13:41 -0600552 else
553 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500554 lg2::error("Invalid entry ID ({ID}) to delete", "ID", entryId);
Marri Devender Rao8959efc2017-11-17 00:13:41 -0600555 }
Deepak Kodihalli99a85492017-03-31 06:01:57 -0500556}
557
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500558void Manager::restore()
559{
Patrick Venturef18bf832018-10-26 18:14:00 -0700560 auto sanity = [](const auto& id, const auto& restoredId) {
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600561 return id == restoredId;
562 };
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500563
564 fs::path dir(ERRLOG_PERSIST_PATH);
565 if (!fs::exists(dir) || fs::is_empty(dir))
566 {
567 return;
568 }
569
Patrick Venturef18bf832018-10-26 18:14:00 -0700570 for (auto& file : fs::directory_iterator(dir))
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500571 {
572 auto id = file.path().filename().c_str();
573 auto idNum = std::stol(id);
574 auto e = std::make_unique<Entry>(
Patrick Venturef18bf832018-10-26 18:14:00 -0700575 busLog, std::string(OBJ_ENTRY) + '/' + id, idNum, *this);
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500576 if (deserialize(file.path(), *e))
577 {
Patrick Venturef18bf832018-10-26 18:14:00 -0700578 // validate the restored error entry id
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600579 if (sanity(static_cast<uint32_t>(idNum), e->id()))
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500580 {
Matt Spinleref952af2021-08-19 10:23:05 -0500581 e->path(file.path(), true);
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600582 if (e->severity() >= Entry::sevLowerLimit)
583 {
584 infoErrors.push_back(idNum);
585 }
Nagaraju Gorugantie4b0b772017-11-30 02:12:45 -0600586 else
587 {
588 realErrors.push_back(idNum);
589 }
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600590
591 entries.insert(std::make_pair(idNum, std::move(e)));
Nagaraju Gorugantif8a5a792017-10-13 08:09:52 -0500592 }
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600593 else
594 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500595 lg2::error(
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600596 "Failed in sanity check while restoring error entry. "
Patrick Williams5f285c52021-07-27 21:25:38 -0500597 "Ignoring error entry {ID_NUM}/{ENTRY_ID}.",
598 "ID_NUM", idNum, "ENTRY_ID", e->id());
Marri Devender Rao979ed1c2017-11-17 05:06:25 -0600599 }
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500600 }
601 }
602
Lei YU01bf5c42022-05-23 15:33:23 +0800603 if (!entries.empty())
Vishwanatha Subbanna37af9ba2017-09-28 16:33:53 +0530604 {
Lei YU01bf5c42022-05-23 15:33:23 +0800605 entryId = entries.rbegin()->first;
Vishwanatha Subbanna37af9ba2017-09-28 16:33:53 +0530606 }
Deepak Kodihalli72654f12017-06-12 04:33:29 -0500607}
608
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500609void Manager::journalSync()
610{
611 bool syncRequested = false;
612 auto fd = -1;
613 auto rc = -1;
614 auto wd = -1;
615 auto bus = sdbusplus::bus::new_default();
616
617 auto start =
618 duration_cast<microseconds>(steady_clock::now().time_since_epoch())
619 .count();
620
Matthew Barth59913892019-08-27 15:43:48 -0500621 // Each time an error log is committed, a request to sync the journal
622 // must occur and block that error log commit until it completes. A 5sec
623 // block is done to allow sufficient time for the journal to be synced.
624 //
625 // Number of loop iterations = 3 for the following reasons:
626 // Iteration #1: Requests a journal sync by killing the journald service.
627 // Iteration #2: Setup an inotify watch to monitor the synced file that
628 // journald updates with the timestamp the last time the
629 // journal was flushed.
630 // Iteration #3: Poll to wait until inotify reports an event which blocks
631 // the error log from being commited until the sync completes.
632 constexpr auto maxRetry = 3;
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500633 for (int i = 0; i < maxRetry; i++)
634 {
635 // Read timestamp from synced file
636 constexpr auto syncedPath = "/run/systemd/journal/synced";
637 std::ifstream syncedFile(syncedPath);
638 if (syncedFile.fail())
639 {
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500640 // If the synced file doesn't exist, a sync request will create it.
641 if (errno != ENOENT)
642 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500643 lg2::error(
644 "Failed to open journal synced file {FILENAME}: {ERROR}",
645 "FILENAME", syncedPath, "ERROR", strerror(errno));
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500646 return;
647 }
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500648 }
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500649 else
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500650 {
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500651 // Only read the synced file if it exists.
652 // See if a sync happened by now
653 std::string timestampStr;
654 std::getline(syncedFile, timestampStr);
Patrick Venture30047bf2018-11-01 18:52:15 -0700655 auto timestamp = std::stoll(timestampStr);
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500656 if (timestamp >= start)
657 {
Troy Leeb7f392a2019-11-19 14:34:56 +0800658 break;
Adriana Kobylak7d111a82018-09-04 10:14:24 -0500659 }
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500660 }
661
662 // Let's ask for a sync, but only once
663 if (!syncRequested)
664 {
665 syncRequested = true;
666
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500667 constexpr auto JOURNAL_UNIT = "systemd-journald.service";
668 auto signal = SIGRTMIN + 1;
669
670 auto method = bus.new_method_call(SYSTEMD_BUSNAME, SYSTEMD_PATH,
671 SYSTEMD_INTERFACE, "KillUnit");
672 method.append(JOURNAL_UNIT, "main", signal);
673 bus.call(method);
674 if (method.is_method_error())
675 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500676 lg2::error("Failed to kill journal service");
Troy Leeb7f392a2019-11-19 14:34:56 +0800677 break;
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500678 }
Patrick Williamsa5171972021-04-16 20:10:01 -0500679
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500680 continue;
681 }
682
683 // Let's install the inotify watch, if we didn't do that yet. This watch
684 // monitors the syncedFile for when journald updates it with a newer
685 // timestamp. This means the journal has been flushed.
686 if (fd < 0)
687 {
688 fd = inotify_init1(IN_NONBLOCK | IN_CLOEXEC);
689 if (fd < 0)
690 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500691 lg2::error("Failed to create inotify watch: {ERROR}", "ERROR",
692 strerror(errno));
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500693 return;
694 }
695
696 constexpr auto JOURNAL_RUN_PATH = "/run/systemd/journal";
697 wd = inotify_add_watch(fd, JOURNAL_RUN_PATH,
698 IN_MOVED_TO | IN_DONT_FOLLOW | IN_ONLYDIR);
699 if (wd < 0)
700 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500701 lg2::error("Failed to watch journal directory: {PATH}: {ERROR}",
702 "PATH", JOURNAL_RUN_PATH, "ERROR", strerror(errno));
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500703 close(fd);
704 return;
705 }
706 continue;
707 }
708
709 // Let's wait until inotify reports an event
710 struct pollfd fds = {
Andrew Jefferyeb0aec42021-06-15 11:36:04 +0930711 fd,
712 POLLIN,
713 0,
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500714 };
715 constexpr auto pollTimeout = 5; // 5 seconds
716 rc = poll(&fds, 1, pollTimeout * 1000);
717 if (rc < 0)
718 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500719 lg2::error("Failed to add event: {ERROR}", "ERROR",
720 strerror(errno));
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500721 inotify_rm_watch(fd, wd);
722 close(fd);
723 return;
724 }
725 else if (rc == 0)
726 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500727 lg2::info("Poll timeout ({TIMEOUT}), no new journal synced data",
728 "TIMEOUT", pollTimeout);
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500729 break;
730 }
731
732 // Read from the specified file descriptor until there is no new data,
733 // throwing away everything read since the timestamp will be read at the
734 // beginning of the loop.
735 constexpr auto maxBytes = 64;
736 uint8_t buffer[maxBytes];
737 while (read(fd, buffer, maxBytes) > 0)
738 ;
739 }
740
Adriana Kobylak4a029f22018-05-23 12:58:19 -0500741 if (fd != -1)
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500742 {
Adriana Kobylak4a029f22018-05-23 12:58:19 -0500743 if (wd != -1)
744 {
745 inotify_rm_watch(fd, wd);
746 }
Adriana Kobylak5f4247f2018-03-15 10:27:05 -0500747 close(fd);
748 }
749
750 return;
751}
752
Matt Spinler1275bd12018-05-01 15:13:53 -0500753std::string Manager::readFWVersion()
754{
Matt Spinlerf61f2922020-06-23 11:32:49 -0500755 auto version = util::getOSReleaseValue("VERSION_ID");
Matt Spinler1275bd12018-05-01 15:13:53 -0500756
Matt Spinlerf61f2922020-06-23 11:32:49 -0500757 if (!version)
Matt Spinler1275bd12018-05-01 15:13:53 -0500758 {
Patrick Williams5f285c52021-07-27 21:25:38 -0500759 lg2::error("Unable to read BMC firmware version");
Matt Spinler1275bd12018-05-01 15:13:53 -0500760 }
761
Matt Spinlerf61f2922020-06-23 11:32:49 -0500762 return version.value_or("");
Matt Spinler1275bd12018-05-01 15:13:53 -0500763}
764
Matt Spinler3fb83b32019-07-26 11:22:44 -0500765void Manager::create(const std::string& message, Entry::Level severity,
766 const std::map<std::string, std::string>& additionalData)
767{
768 // Convert the map into a vector of "key=value" strings
769 std::vector<std::string> ad;
770 metadata::associations::combine(additionalData, ad);
771
772 createEntry(message, severity, ad);
773}
774
Matt Spinlerc64b7122020-03-26 10:55:01 -0500775void Manager::createWithFFDC(
776 const std::string& message, Entry::Level severity,
777 const std::map<std::string, std::string>& additionalData,
778 const FFDCEntries& ffdc)
779{
780 // Convert the map into a vector of "key=value" strings
781 std::vector<std::string> ad;
782 metadata::associations::combine(additionalData, ad);
783
784 createEntry(message, severity, ad, ffdc);
785}
786
Nagaraju Goruganti05aae8b2017-08-30 07:56:12 -0500787} // namespace internal
Adriana Kobylak8f7941e2016-11-14 14:46:23 -0600788} // namespace logging
Patrick Venturef18bf832018-10-26 18:14:00 -0700789} // namespace phosphor