blob: 841a514f9a563083bae3edf2d61d0773744ea046 [file] [log] [blame]
Matt Spinler711d51d2019-11-06 09:36:51 -06001/**
2 * Copyright © 2019 IBM Corporation
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
Matt Spinler4e8078c2019-07-09 13:22:32 -050016#include "manager.hpp"
17
18#include "additional_data.hpp"
Matt Spinler05c2c6c2019-12-18 14:02:09 -060019#include "json_utils.hpp"
Matt Spinler89fa0822019-07-17 13:54:30 -050020#include "pel.hpp"
Matt Spinler1962e082020-08-05 13:44:53 -050021#include "service_indicators.hpp"
Matt Spinler89fa0822019-07-17 13:54:30 -050022
Matt Spinler22421b92020-07-17 09:41:08 -050023#include <fmt/format.h>
Matt Spinlerff9cec22020-07-15 13:06:35 -050024#include <sys/inotify.h>
Matt Spinler6b1a5c82020-01-07 08:48:53 -060025#include <unistd.h>
26
Matt Spinler89fa0822019-07-17 13:54:30 -050027#include <filesystem>
28#include <fstream>
Matt Spinlera34ab722019-12-16 10:39:32 -060029#include <xyz/openbmc_project/Common/error.hpp>
Matt Spinler56ad2a02020-03-26 14:00:52 -050030#include <xyz/openbmc_project/Logging/Create/server.hpp>
Matt Spinler4e8078c2019-07-09 13:22:32 -050031
32namespace openpower
33{
34namespace pels
35{
36
37using namespace phosphor::logging;
Matt Spinler89fa0822019-07-17 13:54:30 -050038namespace fs = std::filesystem;
Harisuddin Mohamed Isa0f717e12020-01-15 20:05:33 +080039namespace rg = openpower::pels::message;
Matt Spinler4e8078c2019-07-09 13:22:32 -050040
Matt Spinlera34ab722019-12-16 10:39:32 -060041namespace common_error = sdbusplus::xyz::openbmc_project::Common::Error;
42
Matt Spinler56ad2a02020-03-26 14:00:52 -050043using Create = sdbusplus::xyz::openbmc_project::Logging::server::Create;
44
Matt Spinler4e8078c2019-07-09 13:22:32 -050045namespace additional_data
46{
47constexpr auto rawPEL = "RAWPEL";
Matt Spinler19e72902020-01-24 11:05:20 -060048constexpr auto esel = "ESEL";
Matt Spinler30ddc9f2020-07-16 15:39:59 -050049constexpr auto error = "ERROR_NAME";
Matt Spinler19e72902020-01-24 11:05:20 -060050} // namespace additional_data
Matt Spinler4e8078c2019-07-09 13:22:32 -050051
Matt Spinler30ddc9f2020-07-16 15:39:59 -050052constexpr auto defaultLogMessage = "xyz.openbmc_project.Logging.Error.Default";
53
Matt Spinlerff9cec22020-07-15 13:06:35 -050054Manager::~Manager()
55{
56 if (_pelFileDeleteFD != -1)
57 {
58 if (_pelFileDeleteWatchFD != -1)
59 {
60 inotify_rm_watch(_pelFileDeleteFD, _pelFileDeleteWatchFD);
61 }
62 close(_pelFileDeleteFD);
63 }
64}
65
Matt Spinler4e8078c2019-07-09 13:22:32 -050066void Manager::create(const std::string& message, uint32_t obmcLogID,
67 uint64_t timestamp, Entry::Level severity,
68 const std::vector<std::string>& additionalData,
Matt Spinler56ad2a02020-03-26 14:00:52 -050069 const std::vector<std::string>& associations,
70 const FFDCEntries& ffdc)
Matt Spinler4e8078c2019-07-09 13:22:32 -050071{
72 AdditionalData ad{additionalData};
73
Matt Spinler19e72902020-01-24 11:05:20 -060074 // If a PEL was passed in via a filename or in an ESEL,
75 // use that. Otherwise, create one.
Matt Spinler4e8078c2019-07-09 13:22:32 -050076 auto rawPelPath = ad.getValue(additional_data::rawPEL);
77 if (rawPelPath)
78 {
79 addRawPEL(*rawPelPath, obmcLogID);
80 }
81 else
82 {
Matt Spinler19e72902020-01-24 11:05:20 -060083 auto esel = ad.getValue(additional_data::esel);
84 if (esel)
85 {
86 addESELPEL(*esel, obmcLogID);
87 }
88 else
89 {
90 createPEL(message, obmcLogID, timestamp, severity, additionalData,
Matt Spinler56ad2a02020-03-26 14:00:52 -050091 associations, ffdc);
Matt Spinler19e72902020-01-24 11:05:20 -060092 }
Matt Spinler4e8078c2019-07-09 13:22:32 -050093 }
94}
95
96void Manager::addRawPEL(const std::string& rawPelPath, uint32_t obmcLogID)
97{
Matt Spinler89fa0822019-07-17 13:54:30 -050098 if (fs::exists(rawPelPath))
99 {
100 std::ifstream file(rawPelPath, std::ios::in | std::ios::binary);
101
102 auto data = std::vector<uint8_t>(std::istreambuf_iterator<char>(file),
103 std::istreambuf_iterator<char>());
104 if (file.fail())
105 {
106 log<level::ERR>("Filesystem error reading a raw PEL",
107 entry("PELFILE=%s", rawPelPath.c_str()),
108 entry("OBMCLOGID=%d", obmcLogID));
109 // TODO, Decide what to do here. Maybe nothing.
110 return;
111 }
112
113 file.close();
114
Matt Spinler19e72902020-01-24 11:05:20 -0600115 addPEL(data, obmcLogID);
Matt Spinler89fa0822019-07-17 13:54:30 -0500116 }
117 else
118 {
119 log<level::ERR>("Raw PEL file from BMC event log does not exist",
120 entry("PELFILE=%s", (rawPelPath).c_str()),
121 entry("OBMCLOGID=%d", obmcLogID));
122 }
Matt Spinler4e8078c2019-07-09 13:22:32 -0500123}
124
Matt Spinler19e72902020-01-24 11:05:20 -0600125void Manager::addPEL(std::vector<uint8_t>& pelData, uint32_t obmcLogID)
126{
127
128 auto pel = std::make_unique<openpower::pels::PEL>(pelData, obmcLogID);
129 if (pel->valid())
130 {
131 // PELs created by others still need these fields set by us.
132 pel->assignID();
133 pel->setCommitTime();
134
135 try
136 {
Matt Spinler6321ba32020-07-17 09:58:19 -0500137 log<level::INFO>(
138 fmt::format("Adding external PEL {:#x} (BMC ID {}) to repo",
139 pel->id(), obmcLogID)
140 .c_str());
Matt Spinler5f5352e2020-03-05 16:23:27 -0600141
Matt Spinler19e72902020-01-24 11:05:20 -0600142 _repo.add(pel);
Matt Spinler7e727a32020-07-07 15:00:17 -0500143
144 if (_repo.sizeWarning())
145 {
146 scheduleRepoPrune();
147 }
Matt Spinler1962e082020-08-05 13:44:53 -0500148
149 // Activate any resulting service indicators if necessary
150 auto policy = service_indicators::getPolicy(*_dataIface);
151 policy->activate(*pel);
Matt Spinler19e72902020-01-24 11:05:20 -0600152 }
153 catch (std::exception& e)
154 {
155 // Probably a full or r/o filesystem, not much we can do.
156 log<level::ERR>("Unable to add PEL to Repository",
157 entry("PEL_ID=0x%X", pel->id()));
158 }
159 }
160 else
161 {
162 log<level::ERR>("Invalid PEL received from the host",
163 entry("OBMCLOGID=%d", obmcLogID));
164
165 AdditionalData ad;
166 ad.add("PLID", getNumberString("0x%08X", pel->plid()));
167 ad.add("OBMC_LOG_ID", std::to_string(obmcLogID));
168 ad.add("PEL_SIZE", std::to_string(pelData.size()));
169
170 std::string asciiString;
171 auto src = pel->primarySRC();
172 if (src)
173 {
174 asciiString = (*src)->asciiString();
175 }
176
177 ad.add("SRC", asciiString);
178
179 _eventLogger.log("org.open_power.Logging.Error.BadHostPEL",
180 Entry::Level::Error, ad);
Matt Spinlerfe721892020-04-02 10:28:08 -0500181
182 // Save it to a file for debug in the lab. Just keep the latest.
183 // Not adding it to the PEL because it could already be max size
184 // and don't want to truncate an already invalid PEL.
185 std::ofstream pelFile{getPELRepoPath() / "badPEL"};
186 pelFile.write(reinterpret_cast<const char*>(pelData.data()),
187 pelData.size());
Matt Spinler19e72902020-01-24 11:05:20 -0600188 }
189}
190
191void Manager::addESELPEL(const std::string& esel, uint32_t obmcLogID)
192{
193 std::vector<uint8_t> data;
194
Matt Spinler5f5352e2020-03-05 16:23:27 -0600195 log<level::DEBUG>("Adding PEL from ESEL",
196 entry("OBMC_LOG_ID=%d", obmcLogID));
197
Matt Spinler19e72902020-01-24 11:05:20 -0600198 try
199 {
200 data = std::move(eselToRawData(esel));
201 }
202 catch (std::exception& e)
203 {
204 // Try to add it below anyway, so it follows the usual bad data path.
205 log<level::ERR>("Problems converting ESEL string to a byte vector");
206 }
207
208 addPEL(data, obmcLogID);
209}
210
211std::vector<uint8_t> Manager::eselToRawData(const std::string& esel)
212{
213 std::vector<uint8_t> data;
214 std::string byteString;
215
216 // As the eSEL string looks like: "50 48 00 ab ..." there are 3
217 // characters per raw byte, and since the actual PEL data starts
218 // at the 16th byte, the code will grab the PEL data starting at
219 // offset 48 in the string.
220 static constexpr size_t pelStart = 16 * 3;
221
222 if (esel.size() <= pelStart)
223 {
224 log<level::ERR>("ESEL data too short",
225 entry("ESEL_SIZE=%d", esel.size()));
226
227 throw std::length_error("ESEL data too short");
228 }
229
230 for (size_t i = pelStart; i < esel.size(); i += 3)
231 {
232 if (i + 1 < esel.size())
233 {
234 byteString = esel.substr(i, 2);
235 data.push_back(std::stoi(byteString, nullptr, 16));
236 }
237 else
238 {
239 log<level::ERR>("ESEL data too short",
240 entry("ESEL_SIZE=%d", esel.size()));
241 throw std::length_error("ESEL data too short");
242 }
243 }
244
245 return data;
246}
247
Matt Spinler4e8078c2019-07-09 13:22:32 -0500248void Manager::erase(uint32_t obmcLogID)
249{
Matt Spinler475e5742019-07-18 16:09:49 -0500250 Repository::LogID id{Repository::LogID::Obmc(obmcLogID)};
251
252 _repo.remove(id);
Matt Spinler4e8078c2019-07-09 13:22:32 -0500253}
254
255bool Manager::isDeleteProhibited(uint32_t obmcLogID)
256{
257 return false;
258}
259
Matt Spinler56ad2a02020-03-26 14:00:52 -0500260PelFFDC Manager::convertToPelFFDC(const FFDCEntries& ffdc)
261{
262 PelFFDC pelFFDC;
263
264 std::for_each(ffdc.begin(), ffdc.end(), [&pelFFDC](const auto& f) {
265 PelFFDCfile pf;
266 pf.subType = std::get<ffdcSubtypePos>(f);
267 pf.version = std::get<ffdcVersionPos>(f);
268 pf.fd = std::get<ffdcFDPos>(f);
269
270 switch (std::get<ffdcFormatPos>(f))
271 {
272 case Create::FFDCFormat::JSON:
273 pf.format = UserDataFormat::json;
274 break;
275 case Create::FFDCFormat::CBOR:
276 pf.format = UserDataFormat::cbor;
277 break;
278 case Create::FFDCFormat::Text:
279 pf.format = UserDataFormat::text;
280 break;
281 case Create::FFDCFormat::Custom:
282 pf.format = UserDataFormat::custom;
283 break;
284 }
285
286 pelFFDC.push_back(pf);
287 });
288
289 return pelFFDC;
290}
291
Matt Spinler4e8078c2019-07-09 13:22:32 -0500292void Manager::createPEL(const std::string& message, uint32_t obmcLogID,
293 uint64_t timestamp,
294 phosphor::logging::Entry::Level severity,
295 const std::vector<std::string>& additionalData,
Matt Spinler56ad2a02020-03-26 14:00:52 -0500296 const std::vector<std::string>& associations,
297 const FFDCEntries& ffdc)
Matt Spinler4e8078c2019-07-09 13:22:32 -0500298{
Harisuddin Mohamed Isa0f717e12020-01-15 20:05:33 +0800299 auto entry = _registry.lookup(message, rg::LookupType::name);
Matt Spinler30ddc9f2020-07-16 15:39:59 -0500300 auto pelFFDC = convertToPelFFDC(ffdc);
301 AdditionalData ad{additionalData};
Matt Spinler1d4c74a2019-12-16 14:40:21 -0600302 std::string msg;
Matt Spinler67456c22019-10-21 12:22:49 -0500303
Matt Spinler30ddc9f2020-07-16 15:39:59 -0500304 if (!entry)
Matt Spinler67456c22019-10-21 12:22:49 -0500305 {
Matt Spinler30ddc9f2020-07-16 15:39:59 -0500306 // Instead, get the default entry that means there is no
307 // other matching entry. This error will still use the
308 // AdditionalData values of the original error, and this
309 // code will add the error message value that wasn't found
310 // to this AD. This way, there will at least be a PEL,
311 // possibly with callouts, to allow users to debug the
312 // issue that caused the error even without its own PEL.
Matt Spinler1d4c74a2019-12-16 14:40:21 -0600313 msg = "Event not found in PEL message registry: " + message;
314 log<level::INFO>(msg.c_str());
Matt Spinler30ddc9f2020-07-16 15:39:59 -0500315
316 entry = _registry.lookup(defaultLogMessage, rg::LookupType::name);
317 if (!entry)
318 {
319 log<level::ERR>("Default event not found in PEL message registry");
320 return;
321 }
322
323 ad.add(additional_data::error, message);
324 }
325
326 auto pel = std::make_unique<openpower::pels::PEL>(
327 *entry, obmcLogID, timestamp, severity, ad, pelFFDC, *_dataIface);
328
329 _repo.add(pel);
330
331 if (_repo.sizeWarning())
332 {
333 scheduleRepoPrune();
334 }
335
336 auto src = pel->primarySRC();
337 if (src)
338 {
Matt Spinler22421b92020-07-17 09:41:08 -0500339 auto msg =
340 fmt::format("Created PEL {:#x} (BMC ID {}) with SRC {}", pel->id(),
341 pel->obmcLogID(), (*src)->asciiString());
Matt Spinler30ddc9f2020-07-16 15:39:59 -0500342 while (msg.back() == ' ')
343 {
344 msg.pop_back();
345 }
346 log<level::INFO>(msg.c_str());
Matt Spinler1d4c74a2019-12-16 14:40:21 -0600347 }
Matt Spinler1962e082020-08-05 13:44:53 -0500348
349 // Activate any resulting service indicators if necessary
350 auto policy = service_indicators::getPolicy(*_dataIface);
351 policy->activate(*pel);
Matt Spinler4e8078c2019-07-09 13:22:32 -0500352}
353
Matt Spinlera34ab722019-12-16 10:39:32 -0600354sdbusplus::message::unix_fd Manager::getPEL(uint32_t pelID)
355{
356 Repository::LogID id{Repository::LogID::Pel(pelID)};
357 std::optional<int> fd;
358
Matt Spinler5f5352e2020-03-05 16:23:27 -0600359 log<level::DEBUG>("getPEL", entry("PEL_ID=0x%X", pelID));
360
Matt Spinlera34ab722019-12-16 10:39:32 -0600361 try
362 {
363 fd = _repo.getPELFD(id);
364 }
365 catch (std::exception& e)
366 {
367 throw common_error::InternalFailure();
368 }
369
370 if (!fd)
371 {
372 throw common_error::InvalidArgument();
373 }
374
Matt Spinler6b1a5c82020-01-07 08:48:53 -0600375 scheduleFDClose(*fd);
376
Matt Spinlera34ab722019-12-16 10:39:32 -0600377 return *fd;
378}
379
Matt Spinler6b1a5c82020-01-07 08:48:53 -0600380void Manager::scheduleFDClose(int fd)
381{
382 _fdCloserEventSource = std::make_unique<sdeventplus::source::Defer>(
Matt Spinlerff9cec22020-07-15 13:06:35 -0500383 _event, std::bind(std::mem_fn(&Manager::closeFD), this, fd,
384 std::placeholders::_1));
Matt Spinler6b1a5c82020-01-07 08:48:53 -0600385}
386
387void Manager::closeFD(int fd, sdeventplus::source::EventBase& source)
388{
389 close(fd);
390 _fdCloserEventSource.reset();
391}
392
Matt Spinlera34ab722019-12-16 10:39:32 -0600393std::vector<uint8_t> Manager::getPELFromOBMCID(uint32_t obmcLogID)
394{
395 Repository::LogID id{Repository::LogID::Obmc(obmcLogID)};
396 std::optional<std::vector<uint8_t>> data;
397
Matt Spinler5f5352e2020-03-05 16:23:27 -0600398 log<level::DEBUG>("getPELFromOBMCID", entry("OBMC_LOG_ID=%d", obmcLogID));
399
Matt Spinlera34ab722019-12-16 10:39:32 -0600400 try
401 {
402 data = _repo.getPELData(id);
403 }
404 catch (std::exception& e)
405 {
406 throw common_error::InternalFailure();
407 }
408
409 if (!data)
410 {
411 throw common_error::InvalidArgument();
412 }
413
414 return *data;
415}
416
417void Manager::hostAck(uint32_t pelID)
418{
419 Repository::LogID id{Repository::LogID::Pel(pelID)};
420
Matt Spinler5f5352e2020-03-05 16:23:27 -0600421 log<level::DEBUG>("HostAck", entry("PEL_ID=0x%X", pelID));
422
Matt Spinlera34ab722019-12-16 10:39:32 -0600423 if (!_repo.hasPEL(id))
424 {
425 throw common_error::InvalidArgument();
426 }
427
428 if (_hostNotifier)
429 {
430 _hostNotifier->ackPEL(pelID);
431 }
432}
433
434void Manager::hostReject(uint32_t pelID, RejectionReason reason)
435{
436 Repository::LogID id{Repository::LogID::Pel(pelID)};
437
Matt Spinler5f5352e2020-03-05 16:23:27 -0600438 log<level::DEBUG>("HostReject", entry("PEL_ID=0x%X", pelID),
439 entry("REASON=%d", static_cast<int>(reason)));
440
Matt Spinlera34ab722019-12-16 10:39:32 -0600441 if (!_repo.hasPEL(id))
442 {
443 throw common_error::InvalidArgument();
444 }
445
Matt Spinler05c2c6c2019-12-18 14:02:09 -0600446 if (reason == RejectionReason::BadPEL)
Matt Spinlera34ab722019-12-16 10:39:32 -0600447 {
Matt Spinler05c2c6c2019-12-18 14:02:09 -0600448 AdditionalData data;
449 data.add("BAD_ID", getNumberString("0x%08X", pelID));
450 _eventLogger.log("org.open_power.Logging.Error.SentBadPELToHost",
451 Entry::Level::Informational, data);
452 if (_hostNotifier)
Matt Spinlera34ab722019-12-16 10:39:32 -0600453 {
454 _hostNotifier->setBadPEL(pelID);
455 }
Matt Spinler05c2c6c2019-12-18 14:02:09 -0600456 }
457 else if ((reason == RejectionReason::HostFull) && _hostNotifier)
458 {
459 _hostNotifier->setHostFull(pelID);
Matt Spinlera34ab722019-12-16 10:39:32 -0600460 }
461}
462
Matt Spinler7e727a32020-07-07 15:00:17 -0500463void Manager::scheduleRepoPrune()
464{
Matt Spinler7e727a32020-07-07 15:00:17 -0500465 _repoPrunerEventSource = std::make_unique<sdeventplus::source::Defer>(
Matt Spinlerff9cec22020-07-15 13:06:35 -0500466 _event, std::bind(std::mem_fn(&Manager::pruneRepo), this,
467 std::placeholders::_1));
Matt Spinler7e727a32020-07-07 15:00:17 -0500468}
469
470void Manager::pruneRepo(sdeventplus::source::EventBase& source)
471{
472 auto idsToDelete = _repo.prune();
473
474 // Remove the OpenBMC event logs for the PELs that were just removed.
475 std::for_each(idsToDelete.begin(), idsToDelete.end(),
476 [this](auto id) { this->_logManager.erase(id); });
477
478 _repoPrunerEventSource.reset();
479}
480
Matt Spinlerff9cec22020-07-15 13:06:35 -0500481void Manager::setupPELDeleteWatch()
482{
483 _pelFileDeleteFD = inotify_init1(IN_NONBLOCK);
484 if (-1 == _pelFileDeleteFD)
485 {
486 auto e = errno;
487 std::string msg =
488 "inotify_init1 failed with errno " + std::to_string(e);
489 log<level::ERR>(msg.c_str());
490 abort();
491 }
492
493 _pelFileDeleteWatchFD = inotify_add_watch(
494 _pelFileDeleteFD, _repo.repoPath().c_str(), IN_DELETE);
495 if (-1 == _pelFileDeleteWatchFD)
496 {
497 auto e = errno;
498 std::string msg =
499 "inotify_add_watch failed with error " + std::to_string(e);
500 log<level::ERR>(msg.c_str());
501 abort();
502 }
503
504 _pelFileDeleteEventSource = std::make_unique<sdeventplus::source::IO>(
505 _event, _pelFileDeleteFD, EPOLLIN,
506 std::bind(std::mem_fn(&Manager::pelFileDeleted), this,
507 std::placeholders::_1, std::placeholders::_2,
508 std::placeholders::_3));
509}
510
511void Manager::pelFileDeleted(sdeventplus::source::IO& io, int fd,
512 uint32_t revents)
513{
514 if (!(revents & EPOLLIN))
515 {
516 return;
517 }
518
519 // An event for 1 PEL uses 48B. When all PELs are deleted at once,
520 // as many events as there is room for can be handled in one callback.
521 // A size of 2000 will allow 41 to be processed, with additional
522 // callbacks being needed to process the remaining ones.
523 std::array<uint8_t, 2000> data;
524 auto bytesRead = read(_pelFileDeleteFD, data.data(), data.size());
525 if (bytesRead < 0)
526 {
527 auto e = errno;
528 std::string msg = "Failed reading data from inotify event, errno = " +
529 std::to_string(e);
530 log<level::ERR>(msg.c_str());
531 abort();
532 }
533
534 auto offset = 0;
535 while (offset < bytesRead)
536 {
537 auto event = reinterpret_cast<inotify_event*>(&data[offset]);
538 if (event->mask & IN_DELETE)
539 {
540 std::string filename{event->name};
541
542 // Get the PEL ID from the filename and tell the
543 // repo it's been removed, and then delete the BMC
544 // event log if it's there.
545 auto pos = filename.find_first_of('_');
546 if (pos != std::string::npos)
547 {
548 try
549 {
550 auto idString = filename.substr(pos + 1);
551 auto pelID = std::stoul(idString, nullptr, 16);
552
553 Repository::LogID id{Repository::LogID::Pel(pelID)};
554 auto removedLogID = _repo.remove(id);
555 if (removedLogID)
556 {
557 _logManager.erase(removedLogID->obmcID.id);
558 }
559 }
560 catch (const std::exception& e)
561 {
562 log<level::INFO>("Could not find PEL ID from its filename",
563 entry("FILENAME=%s", filename.c_str()));
564 }
565 }
566 }
567
568 offset += offsetof(inotify_event, name) + event->len;
569 }
570}
Matt Spinler4e8078c2019-07-09 13:22:32 -0500571} // namespace pels
572} // namespace openpower