Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 1 | #include <unistd.h> |
| 2 | |
Ben Tyner | b797b3e | 2020-06-29 10:12:05 -0500 | [diff] [blame] | 3 | #include <attn/attn_logging.hpp> |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 4 | #include <phosphor-logging/log.hpp> |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 5 | namespace attn |
| 6 | { |
| 7 | |
| 8 | /** @brief journal entry of type INFO using phosphor logging */ |
| 9 | template <> |
| 10 | void trace<INFO>(const char* i_message) |
| 11 | { |
| 12 | phosphor::logging::log<phosphor::logging::level::INFO>(i_message); |
| 13 | } |
| 14 | |
| 15 | /** @brief add an event to the log for PEL generation */ |
| 16 | void event(EventType i_event, std::map<std::string, std::string>& i_additional) |
| 17 | { |
| 18 | bool eventValid = false; // assume no event created |
| 19 | |
| 20 | std::string eventName; |
| 21 | |
| 22 | switch (i_event) |
| 23 | { |
| 24 | case EventType::Checkstop: |
| 25 | eventName = "org.open_power.HwDiags.Error.Checkstop"; |
| 26 | eventValid = true; |
| 27 | break; |
| 28 | case EventType::Terminate: |
| 29 | eventName = "org.open_power.Attn.Error.Terminate"; |
| 30 | eventValid = true; |
| 31 | break; |
| 32 | case EventType::Vital: |
| 33 | eventName = "org.open_power.Attn.Error.Vital"; |
| 34 | eventValid = true; |
| 35 | break; |
| 36 | case EventType::HwDiagsFail: |
| 37 | eventName = "org.open_power.HwDiags.Error.Fail"; |
| 38 | eventValid = true; |
| 39 | break; |
| 40 | case EventType::AttentionFail: |
| 41 | eventName = "org.open_power.Attn.Error.Fail"; |
| 42 | eventValid = true; |
| 43 | break; |
| 44 | default: |
| 45 | eventValid = false; |
| 46 | break; |
| 47 | } |
| 48 | |
| 49 | if (true == eventValid) |
| 50 | { |
| 51 | // Get access to logging interface and method for creating log |
| 52 | auto bus = sdbusplus::bus::new_default_system(); |
| 53 | |
| 54 | // using direct create method (for additional data) |
| 55 | auto method = bus.new_method_call( |
| 56 | "xyz.openbmc_project.Logging", "/xyz/openbmc_project/logging", |
Ben Tyner | 1b1915e | 2020-10-23 15:13:38 -0500 | [diff] [blame] | 57 | "xyz.openbmc_project.Logging.Create", "CreateWithFFDCFiles"); |
| 58 | |
| 59 | // Create FFDC files containing debug data to store in error log |
| 60 | std::vector<util::FFDCFile> files{createFFDCFiles()}; |
| 61 | |
| 62 | // Create FFDC tuples used to pass FFDC files to D-Bus method |
| 63 | std::vector<FFDCTuple> ffdcTuples{createFFDCTuples(files)}; |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 64 | |
| 65 | // attach additional data |
| 66 | method.append(eventName, |
| 67 | "xyz.openbmc_project.Logging.Entry.Level.Error", |
Ben Tyner | 1b1915e | 2020-10-23 15:13:38 -0500 | [diff] [blame] | 68 | i_additional, ffdcTuples); |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 69 | |
| 70 | // log the event |
Ben Tyner | 1c4b02e | 2020-11-09 14:00:29 -0600 | [diff] [blame] | 71 | bus.call_noreply(method); |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 72 | } |
| 73 | } |
| 74 | |
| 75 | /** @brief commit checkstop event to log */ |
| 76 | void eventCheckstop(std::map<std::string, std::string>& i_errors) |
| 77 | { |
| 78 | std::map<std::string, std::string> additionalData; |
| 79 | |
| 80 | // TODO need multi-error/multi-callout stuff here |
| 81 | |
| 82 | // if analyzer isolated errors |
| 83 | if (!(i_errors.empty())) |
| 84 | { |
| 85 | // FIXME TEMP CODE - begin |
| 86 | |
| 87 | std::string signature = i_errors.begin()->first; |
| 88 | std::string chip = i_errors.begin()->second; |
| 89 | |
| 90 | additionalData["_PID"] = std::to_string(getpid()); |
| 91 | additionalData["SIGNATURE"] = signature; |
| 92 | additionalData["CHIP_ID"] = chip; |
| 93 | |
| 94 | // FIXME TEMP CODE -end |
| 95 | |
| 96 | event(EventType::Checkstop, additionalData); |
| 97 | } |
| 98 | } |
| 99 | |
| 100 | /** @brief commit special attention TI event to log */ |
Ben Tyner | 4071772 | 2020-09-23 09:43:20 -0500 | [diff] [blame] | 101 | void eventTerminate(std::map<std::string, std::string> i_additionalData) |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 102 | { |
Ben Tyner | 4071772 | 2020-09-23 09:43:20 -0500 | [diff] [blame] | 103 | event(EventType::Terminate, i_additionalData); |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 104 | } |
| 105 | |
| 106 | /** @brief commit SBE vital event to log */ |
| 107 | void eventVital() |
| 108 | { |
| 109 | std::map<std::string, std::string> additionalData; |
| 110 | |
| 111 | additionalData["_PID"] = std::to_string(getpid()); |
| 112 | |
| 113 | event(EventType::Vital, additionalData); |
| 114 | } |
| 115 | |
| 116 | /** @brief commit analyzer failure event to log */ |
| 117 | void eventHwDiagsFail(int i_error) |
| 118 | { |
| 119 | std::map<std::string, std::string> additionalData; |
| 120 | |
| 121 | additionalData["_PID"] = std::to_string(getpid()); |
| 122 | |
| 123 | event(EventType::HwDiagsFail, additionalData); |
| 124 | } |
| 125 | |
| 126 | /** @brief commit attention handler failure event to log */ |
| 127 | void eventAttentionFail(int i_error) |
| 128 | { |
| 129 | std::map<std::string, std::string> additionalData; |
| 130 | |
| 131 | additionalData["_PID"] = std::to_string(getpid()); |
| 132 | additionalData["ERROR_CODE"] = std::to_string(i_error); |
| 133 | |
| 134 | event(EventType::AttentionFail, additionalData); |
| 135 | } |
| 136 | |
Ben Tyner | 1b1915e | 2020-10-23 15:13:38 -0500 | [diff] [blame] | 137 | /** @brief parse systemd journal message field */ |
| 138 | std::string sdjGetFieldValue(sd_journal* journal, const char* field) |
| 139 | { |
| 140 | const char* data{nullptr}; |
| 141 | size_t length{0}; |
| 142 | size_t prefix{0}; |
| 143 | |
| 144 | // get field value |
| 145 | if (0 == sd_journal_get_data(journal, field, (const void**)&data, &length)) |
| 146 | { |
| 147 | // The data returned by sd_journal_get_data will be prefixed with the |
| 148 | // field name and "=" |
| 149 | const void* eq = memchr(data, '=', length); |
| 150 | if (nullptr != eq) |
| 151 | { |
| 152 | // get just data following the "=" |
| 153 | prefix = (const char*)eq - data + 1; |
| 154 | } |
| 155 | else |
| 156 | { |
| 157 | // all the data (should not happen) |
| 158 | prefix = 0; |
| 159 | std::string value{}; // empty string |
| 160 | } |
| 161 | |
| 162 | return std::string{data + prefix, length - prefix}; |
| 163 | } |
| 164 | else |
| 165 | { |
| 166 | return std::string{}; // empty string |
| 167 | } |
| 168 | } |
| 169 | |
| 170 | /** @brief get messages from systemd journal */ |
| 171 | std::vector<std::string> sdjGetMessages(const std::string& field, |
| 172 | const std::string& fieldValue, |
| 173 | unsigned int max) |
| 174 | { |
| 175 | sd_journal* journal; |
| 176 | std::vector<std::string> messages; |
| 177 | |
| 178 | if (0 == sd_journal_open(&journal, SD_JOURNAL_LOCAL_ONLY)) |
| 179 | { |
| 180 | SD_JOURNAL_FOREACH_BACKWARDS(journal) |
| 181 | { |
| 182 | // Get input field |
| 183 | std::string value = sdjGetFieldValue(journal, field.c_str()); |
| 184 | |
| 185 | // Compare field value and read data |
| 186 | if (value == fieldValue) |
| 187 | { |
| 188 | // Get SYSLOG_IDENTIFIER field (process that logged message) |
| 189 | std::string syslog = |
| 190 | sdjGetFieldValue(journal, "SYSLOG_IDENTIFIER"); |
| 191 | |
| 192 | // Get _PID field |
| 193 | std::string pid = sdjGetFieldValue(journal, "_PID"); |
| 194 | |
| 195 | // Get MESSAGE field |
| 196 | std::string message = sdjGetFieldValue(journal, "MESSAGE"); |
| 197 | |
| 198 | // Get timestamp |
| 199 | uint64_t usec{0}; |
| 200 | if (0 == sd_journal_get_realtime_usec(journal, &usec)) |
| 201 | { |
| 202 | |
| 203 | // Convert realtime microseconds to date format |
| 204 | char dateBuffer[80]; |
| 205 | std::string date; |
| 206 | std::time_t timeInSecs = usec / 1000000; |
| 207 | strftime(dateBuffer, sizeof(dateBuffer), "%b %d %H:%M:%S", |
| 208 | std::localtime(&timeInSecs)); |
| 209 | date = dateBuffer; |
| 210 | |
| 211 | // Store value to messages |
| 212 | value = date + " " + syslog + "[" + pid + "]: " + message; |
| 213 | messages.insert(messages.begin(), value); |
| 214 | } |
| 215 | } |
| 216 | |
| 217 | // limit maximum number of messages |
| 218 | if (messages.size() >= max) |
| 219 | { |
| 220 | break; |
| 221 | } |
| 222 | } |
| 223 | |
| 224 | sd_journal_close(journal); // close journal when done |
| 225 | } |
| 226 | |
| 227 | return messages; |
| 228 | } |
| 229 | |
| 230 | /** @brief create a file containing FFDC data */ |
| 231 | util::FFDCFile createFFDCFile(const std::vector<std::string>& lines) |
| 232 | { |
| 233 | // Create FFDC file of type Text |
| 234 | util::FFDCFile file{util::FFDCFormat::Text}; |
| 235 | int fd = file.getFileDescriptor(); |
| 236 | |
| 237 | // Write FFDC lines to file |
| 238 | std::string buffer; |
| 239 | for (const std::string& line : lines) |
| 240 | { |
| 241 | // Copy line to buffer. Add newline if necessary. |
| 242 | buffer = line; |
| 243 | if (line.empty() || (line.back() != '\n')) |
| 244 | { |
| 245 | buffer += '\n'; |
| 246 | } |
| 247 | |
| 248 | // write buffer to file |
| 249 | write(fd, buffer.c_str(), buffer.size()); |
| 250 | } |
| 251 | |
| 252 | // Seek to beginning of file so error logging system can read data |
| 253 | lseek(fd, 0, SEEK_SET); |
| 254 | |
| 255 | return file; |
| 256 | } |
| 257 | |
| 258 | /** @brief Create FDDC files from journal messages of relevant executables */ |
| 259 | std::vector<util::FFDCFile> createFFDCFiles() |
| 260 | { |
| 261 | std::vector<util::FFDCFile> files{}; |
| 262 | |
| 263 | // Executables of interest |
| 264 | std::vector<std::string> executables{"openpower-hw-diags"}; |
| 265 | |
| 266 | for (const std::string& executable : executables) |
| 267 | { |
| 268 | try |
| 269 | { |
| 270 | // get journal messages |
| 271 | std::vector<std::string> messages = |
| 272 | sdjGetMessages("SYSLOG_IDENTIFIER", executable, 30); |
| 273 | |
| 274 | // Create FFDC file containing the journal messages |
| 275 | if (!messages.empty()) |
| 276 | { |
| 277 | files.emplace_back(createFFDCFile(messages)); |
| 278 | } |
| 279 | } |
| 280 | catch (const std::exception& e) |
| 281 | { |
| 282 | std::stringstream ss; |
| 283 | ss << "createFFDCFiles: " << e.what(); |
| 284 | trace<level::INFO>(ss.str().c_str()); |
| 285 | } |
| 286 | } |
| 287 | |
| 288 | return files; |
| 289 | } |
| 290 | |
| 291 | /** create tuples of FFDC files */ |
| 292 | std::vector<FFDCTuple> createFFDCTuples(std::vector<util::FFDCFile>& files) |
| 293 | { |
| 294 | std::vector<FFDCTuple> ffdcTuples{}; |
| 295 | for (util::FFDCFile& file : files) |
| 296 | { |
| 297 | ffdcTuples.emplace_back( |
| 298 | file.getFormat(), file.getSubType(), file.getVersion(), |
| 299 | sdbusplus::message::unix_fd(file.getFileDescriptor())); |
| 300 | } |
| 301 | return ffdcTuples; |
| 302 | } |
| 303 | |
Ben Tyner | b1ebfcb | 2020-05-08 18:52:48 -0500 | [diff] [blame] | 304 | } // namespace attn |