/src/gbmcweb/tlbmc/pacemaker/pacemaker.cc
Line | Count | Source |
1 | | #include "tlbmc/pacemaker/pacemaker.h" |
2 | | |
3 | | #include <cstdint> |
4 | | #include <cstdio> |
5 | | #include <cstdlib> |
6 | | #include <memory> |
7 | | #include <string> |
8 | | #include <utility> |
9 | | |
10 | | #include "absl/functional/any_invocable.h" |
11 | | #include "absl/log/log.h" |
12 | | #include "absl/status/status.h" |
13 | | #include "absl/status/statusor.h" |
14 | | #include "absl/strings/ascii.h" |
15 | | #include "absl/strings/match.h" |
16 | | #include "absl/strings/numbers.h" |
17 | | #include "absl/strings/str_cat.h" |
18 | | #include "absl/strings/str_format.h" |
19 | | #include "absl/synchronization/mutex.h" |
20 | | #include "absl/time/clock.h" |
21 | | #include "absl/time/time.h" |
22 | | #include "g3/macros.h" |
23 | | #include "time/clock.h" |
24 | | #include "nlohmann/json.hpp" |
25 | | |
26 | | namespace milotic_tlbmc { |
27 | | |
28 | | namespace { |
29 | | |
30 | | constexpr const int kMaxConsecutiveRestartAttempts = 10; |
31 | | constexpr const char* kProcessName = "bmcweb"; |
32 | | constexpr const int kExpectedListeningPort = 443; |
33 | | constexpr const int kMemoryUsageThreshold = 300 * 1024 * 1024; // 300MB |
34 | | constexpr const char* kIsActiveCommand = "systemctl is-active %s"; |
35 | | constexpr const char* kActiveStatus = "active"; |
36 | | constexpr const char* kRestartCommand = "systemctl restart %s"; |
37 | | constexpr const char* kIsListeningCommand = "ss -tulpn | grep %d"; |
38 | | constexpr const char* kGetMemoryUsageCommand = |
39 | | "cat /proc/%d/status | grep VmRSS | awk '{print $2}'"; |
40 | | constexpr const char* kGetPidCommand = |
41 | | "systemctl status %s | grep 'Main PID:' | awk '{print $3}'"; |
42 | | constexpr const char* kGetCpuUsageCommand = |
43 | | "top -n1 | grep %s -i | awk '{print int($8)}'"; |
44 | | constexpr const char* kGetActiveEnterTimestampMonotonic = |
45 | | "systemctl show --property=ActiveEnterTimestampMonotonic %s | awk -F'=' " |
46 | | "'{print $2}'"; |
47 | | constexpr const int kMaxRecentDataPoints = 12; |
48 | | |
49 | | } // namespace |
50 | | |
51 | 4.99k | nlohmann::json Pacemaker::ErrorInfo::ToJson() const { |
52 | 4.99k | auto error_type_to_string = [](ErrorType type) -> std::string { |
53 | 4.99k | switch (type) { |
54 | 1.92k | case ErrorType::kUnknown: |
55 | 1.92k | return "Unknown"; |
56 | 2.62k | case ErrorType::kServiceInactive: |
57 | 2.62k | return "ServiceInactive"; |
58 | 298 | case ErrorType::kPortNotListening: |
59 | 298 | return "PortNotListening"; |
60 | 115 | case ErrorType::kMemoryUsageAboveThreshold: |
61 | 115 | return "MemoryUsageAboveThreshold"; |
62 | 30 | default: |
63 | 30 | return "Unknown"; |
64 | 4.99k | } |
65 | 4.99k | }; |
66 | | |
67 | 4.99k | nlohmann::json json; |
68 | 4.99k | json["type"] = error_type_to_string(type); |
69 | 4.99k | json["timestamp"] = absl::FormatTime(timestamp); |
70 | 4.99k | return json; |
71 | 4.99k | } |
72 | | |
73 | 4.08k | nlohmann::json Pacemaker::MonitoredData::ToJson() const { |
74 | 4.08k | nlohmann::json json; |
75 | | // Get the last kMaxRecentDataPoints memory usage data points. |
76 | 4.08k | auto it = memory_usage_bytes.rbegin(); |
77 | 6.07k | for (int i = 0; i < kMaxRecentDataPoints && it != memory_usage_bytes.rend(); |
78 | 4.08k | ++i, ++it) { |
79 | 1.99k | json["MemoryUsageRecentToOldest"].push_back(*it); |
80 | 1.99k | } |
81 | | // Get the last kMaxRecentDataPoints error data points. |
82 | 4.08k | auto it_error = restart_log.rbegin(); |
83 | 8.01k | for (int i = 0; i < kMaxRecentDataPoints && it_error != restart_log.rend(); |
84 | 4.08k | ++i, ++it_error) { |
85 | 3.93k | json["ErrorsRecentToOldest"].push_back(it_error->ToJson()); |
86 | 3.93k | } |
87 | 4.08k | json["CpuUsage"] = cpu_usage; |
88 | 4.08k | json["MemoryUsage"] = |
89 | 4.08k | memory_usage_bytes.empty() ? -1 : memory_usage_bytes.back(); |
90 | 4.08k | json["LastActiveTimestamp"] = last_active_timestamp; |
91 | 4.08k | json["LastResetTime"] = absl::FormatTime(last_reset_time); |
92 | 4.08k | json["RestartTriggered"] = restart_triggered; |
93 | 4.08k | json["Pid"] = pid; |
94 | 4.08k | json["ConsecutiveRestartAttempts"] = consecutive_restart_attempts; |
95 | 4.08k | return json; |
96 | 4.08k | } |
97 | | |
98 | | absl::StatusOr<std::string> ShellCommandExecutor::Execute( |
99 | 0 | const std::string& command) { |
100 | 0 | FILE* pipe = popen(command.c_str(), "r"); |
101 | 0 | if (pipe == nullptr) { |
102 | 0 | return absl::InternalError( |
103 | 0 | absl::StrCat("Error: Failed to execute command: ", command)); |
104 | 0 | } |
105 | 0 | std::string result; |
106 | 0 | char* line = nullptr; |
107 | 0 | size_t len = 0; |
108 | 0 | ssize_t read; |
109 | |
|
110 | 0 | while ((read = getline(&line, &len, pipe)) != -1) { |
111 | 0 | result.append(line, static_cast<std::string::size_type>(read)); |
112 | 0 | } |
113 | |
|
114 | 0 | free(line); |
115 | 0 | pclose(pipe); |
116 | 0 | return result; |
117 | 0 | } |
118 | | |
119 | | absl::StatusOr<bool> Pacemaker::IsServiceActive( |
120 | 4.08k | const std::string& service_name) const { |
121 | 12.2k | LOG(INFO) << "Checking if service " << service_name << " is active."; |
122 | 6.84k | ECCLESIA_ASSIGN_OR_RETURN( |
123 | 6.84k | std::string output, shell_command_executor_->Execute( |
124 | 6.84k | absl::StrFormat(kIsActiveCommand, service_name))); |
125 | 6.84k | absl::StripAsciiWhitespace(&output); |
126 | | // Compare string |
127 | 6.84k | if (!absl::EqualsIgnoreCase(output, "active")) { |
128 | 7.39k | LOG(ERROR) << "Service " << service_name << " is not active." |
129 | 7.39k | << " status is " << output << " instead of " << kActiveStatus; |
130 | 2.46k | return false; |
131 | 2.46k | } |
132 | 295 | return true; |
133 | 6.84k | } |
134 | | |
135 | 2.33k | absl::StatusOr<bool> Pacemaker::IsPortListening(int port) const { |
136 | 7.00k | LOG(INFO) << "Checking if port " << port << " is listening."; |
137 | 2.33k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
138 | 2.14k | shell_command_executor_->Execute( |
139 | 2.14k | absl::StrFormat(kIsListeningCommand, port))); |
140 | 2.14k | return !output.empty(); |
141 | 2.33k | } |
142 | | |
143 | 2.17k | absl::StatusOr<int> Pacemaker::GetMemoryUsage(int pid) const { |
144 | 6.52k | LOG(INFO) << "Getting memory usage for pid " << pid; |
145 | 4.21k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
146 | 4.21k | shell_command_executor_->Execute( |
147 | 4.21k | absl::StrFormat(kGetMemoryUsageCommand, pid))); |
148 | 4.21k | int memory_usage; |
149 | 4.21k | if (!absl::SimpleAtoi(output, &memory_usage)) { |
150 | 1.95k | return absl::InternalError( |
151 | 1.95k | absl::StrCat("Error: Failed to parse memory usage: ", output)); |
152 | 1.95k | } |
153 | 87 | return memory_usage; |
154 | 4.21k | } |
155 | | |
156 | | absl::StatusOr<int> Pacemaker::GetCpuUsage( |
157 | 2.25k | const std::string& process_name) const { |
158 | 6.77k | LOG(INFO) << "Getting CPU usage for process " << process_name; |
159 | 4.04k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
160 | 4.04k | shell_command_executor_->Execute(absl::StrFormat( |
161 | 4.04k | kGetCpuUsageCommand, process_name))); |
162 | 4.04k | int cpu_usage = -1; |
163 | 4.04k | if (output.empty()) { |
164 | 1.61k | return cpu_usage; |
165 | 1.61k | } |
166 | 164 | if (!absl::SimpleAtoi(output, &cpu_usage)) { |
167 | 140 | return absl::InternalError( |
168 | 140 | absl::StrCat("Error: Failed to parse CPU usage: ", output)); |
169 | 140 | } |
170 | 24 | return cpu_usage; |
171 | 164 | } |
172 | | |
173 | | absl::StatusOr<int64_t> Pacemaker::GetLastActiveTimestamp( |
174 | 3.03k | const std::string& process_name) const { |
175 | 9.11k | LOG(INFO) << "Getting last active timestamp for process " << process_name; |
176 | 5.53k | ECCLESIA_ASSIGN_OR_RETURN( |
177 | 5.53k | std::string output, |
178 | 5.53k | shell_command_executor_->Execute( |
179 | 5.53k | absl::StrFormat(kGetActiveEnterTimestampMonotonic, process_name))); |
180 | 5.53k | int64_t last_active_timestamp; |
181 | 5.53k | if (!absl::SimpleAtoi(output, &last_active_timestamp)) { |
182 | 2.17k | return absl::InternalError( |
183 | 2.17k | absl::StrCat("Error: Failed to parse last reset time: ", output)); |
184 | 2.17k | } |
185 | 321 | return last_active_timestamp; |
186 | 5.53k | } |
187 | | |
188 | 2.98k | absl::Status Pacemaker::RestartService(const std::string& service_name) { |
189 | 8.96k | LOG(ERROR) << "Restarting service " << service_name; |
190 | 2.98k | { |
191 | 2.98k | absl::MutexLock lock(&mutex_); |
192 | 2.98k | if (monitored_data_.restart_triggered) { |
193 | 947 | if (monitored_data_.consecutive_restart_attempts >= |
194 | 947 | kMaxConsecutiveRestartAttempts) { |
195 | 0 | LOG(ERROR) << "Restart attempts exceeded the limit of " |
196 | 0 | << kMaxConsecutiveRestartAttempts; |
197 | 0 | return absl::InternalError( |
198 | 0 | absl::StrCat("Error: Restart attempts exceeded the limit of ", |
199 | 0 | kMaxConsecutiveRestartAttempts)); |
200 | 0 | } |
201 | 947 | ++monitored_data_.consecutive_restart_attempts; |
202 | 947 | } |
203 | 2.98k | monitored_data_.restart_triggered = true; |
204 | 2.98k | monitored_data_.last_reset_time = absl::Now(); |
205 | 2.98k | } |
206 | 2.47k | ECCLESIA_ASSIGN_OR_RETURN( |
207 | 2.47k | std::string output, shell_command_executor_->Execute( |
208 | 2.47k | absl::StrFormat(kRestartCommand, service_name))); |
209 | 2.47k | return absl::OkStatus(); |
210 | 2.98k | } |
211 | | |
212 | | // Get PID of the process. |
213 | 2.31k | absl::StatusOr<int> Pacemaker::GetPid(const std::string& process_name) const { |
214 | 6.94k | LOG(INFO) << "Getting PID for process " << process_name; |
215 | 4.09k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
216 | 4.09k | shell_command_executor_->Execute( |
217 | 4.09k | absl::StrFormat(kGetPidCommand, process_name))); |
218 | 4.09k | int pid = -1; |
219 | 4.09k | if (output.empty()) { |
220 | 1.11k | return absl::InternalError( |
221 | 1.11k | absl::StrCat("Error: Main PID not found for service: ", process_name)); |
222 | 1.11k | } |
223 | | // Trim leading and trailing whitespace, including newlines. |
224 | 665 | output = std::string(absl::StripAsciiWhitespace(output)); |
225 | | |
226 | 665 | if (absl::SimpleAtoi(output, &pid)) { |
227 | 380 | return pid; |
228 | 380 | } |
229 | 285 | return absl::InternalError( |
230 | 285 | absl::StrCat("Error: Invalid PID found in systemctl output: ", output, |
231 | 285 | " for service: ", process_name)); |
232 | 665 | } |
233 | | |
234 | 2.98k | void Pacemaker::RecordError(ErrorType type) { |
235 | 2.98k | absl::MutexLock lock(&mutex_); |
236 | | // If the error type is unknown, we can't determine the timestamp. |
237 | | // So we just record the error and continue. |
238 | 2.98k | if (type == ErrorType::kUnknown) { |
239 | 1.92k | monitored_data_.restart_log.push_back({type, absl::InfinitePast()}); |
240 | 1.92k | return; |
241 | 1.92k | } |
242 | 1.06k | ErrorInfo error_info = {type, absl::Now()}; |
243 | 3.18k | LOG(ERROR) << "Restart required due to Error:\n" |
244 | 3.18k | << error_info.ToJson().dump(2); |
245 | 1.06k | monitored_data_.restart_log.push_back(error_info); |
246 | 1.06k | } |
247 | | |
248 | 2.04k | absl::Status Pacemaker::PerformChecks() { |
249 | 2.04k | bool unknown_restart_detected = false; |
250 | 2.04k | ECCLESIA_ASSIGN_OR_RETURN(bool is_active, IsServiceActive(kProcessName)); |
251 | | |
252 | 1.14k | int pid = -1; |
253 | 1.14k | int cpu_usage = -1; |
254 | 1.14k | int memory_usage = -1; |
255 | 1.14k | bool is_listening = false; |
256 | | |
257 | 1.14k | if (is_active) { |
258 | 294 | ECCLESIA_ASSIGN_OR_RETURN(is_listening, |
259 | 273 | IsPortListening(kExpectedListeningPort)); |
260 | 273 | ECCLESIA_ASSIGN_OR_RETURN(pid, GetPid(kProcessName)); |
261 | 218 | ECCLESIA_ASSIGN_OR_RETURN(cpu_usage, GetCpuUsage(kProcessName)); |
262 | 194 | if (pid > 0) { |
263 | 133 | ECCLESIA_ASSIGN_OR_RETURN(memory_usage, GetMemoryUsage(pid)); |
264 | 81 | } |
265 | 194 | } |
266 | | |
267 | 996 | absl::StatusOr<int64_t> last_active_timestamp = |
268 | 996 | GetLastActiveTimestamp(kProcessName); |
269 | 996 | if (!last_active_timestamp.ok()) { |
270 | 2.04k | LOG(ERROR) << "Failed to get last active timestamp: " |
271 | 2.04k | << last_active_timestamp.status(); |
272 | 682 | } |
273 | | |
274 | | // Update monitored data. |
275 | 996 | { |
276 | 996 | absl::MutexLock lock(&mutex_); |
277 | 996 | monitored_data_.memory_usage_bytes.push_back(memory_usage); |
278 | 996 | monitored_data_.cpu_usage = cpu_usage; |
279 | 996 | monitored_data_.pid = pid; |
280 | | |
281 | | // Check if the process was restarted outside of pacemaker. |
282 | 996 | if (last_active_timestamp.ok()) { |
283 | | // We check if the `last_active_timestamp` we got from systemctl |
284 | | // is different from the one we got from the previous run and if the |
285 | | // process was not restarted by pacemaker. |
286 | | // If the timestamps are different, it means the process was restarted |
287 | | // outside of pacemaker and we should record it as an unknown error. |
288 | 314 | if (monitored_data_.last_active_timestamp != -1 && |
289 | 0 | *last_active_timestamp != monitored_data_.last_active_timestamp && |
290 | 0 | !monitored_data_.restart_triggered) { |
291 | 0 | LOG(INFO) << "Process " << kProcessName |
292 | 0 | << " was restarted outside of pacemaker."; |
293 | 0 | unknown_restart_detected = true; |
294 | 0 | } |
295 | 314 | monitored_data_.last_active_timestamp = *last_active_timestamp; |
296 | 314 | } |
297 | 996 | } |
298 | | |
299 | 996 | if (unknown_restart_detected) { |
300 | 0 | RecordError(ErrorType::kUnknown); |
301 | 0 | } |
302 | | |
303 | 996 | if (!is_active) { |
304 | 854 | RecordError(ErrorType::kServiceInactive); |
305 | 854 | ECCLESIA_RETURN_IF_ERROR(RestartService(kProcessName)); |
306 | 788 | return absl::OkStatus(); |
307 | 854 | } |
308 | | |
309 | 142 | if (!is_listening) { |
310 | 204 | LOG(ERROR) << "Process " << kProcessName << " is not listening on port " |
311 | 204 | << kExpectedListeningPort; |
312 | 68 | RecordError(ErrorType::kPortNotListening); |
313 | 68 | ECCLESIA_RETURN_IF_ERROR(RestartService(kProcessName)); |
314 | 51 | return absl::OkStatus(); |
315 | 68 | } |
316 | | |
317 | 74 | if (memory_usage > kMemoryUsageThreshold) { |
318 | 75 | LOG(ERROR) << "Process " << kProcessName << " memory usage is " |
319 | 75 | << memory_usage << " bytes which is more than the threshold of " |
320 | 75 | << kMemoryUsageThreshold; |
321 | 25 | RecordError(ErrorType::kMemoryUsageAboveThreshold); |
322 | 25 | ECCLESIA_RETURN_IF_ERROR(RestartService(kProcessName)); |
323 | 3 | return absl::OkStatus(); |
324 | 25 | } |
325 | | |
326 | | // If we reach here, it means all checks passed. |
327 | | // Reset the restart triggered and consecutive restart attempts counters. |
328 | 49 | absl::MutexLock lock(&mutex_); |
329 | 49 | monitored_data_.restart_triggered = false; |
330 | 49 | monitored_data_.consecutive_restart_attempts = 0; |
331 | 49 | return absl::OkStatus(); |
332 | 74 | } |
333 | | |
334 | 4.08k | nlohmann::json Pacemaker::GetMonitoringData() const { |
335 | 4.08k | nlohmann::json json; |
336 | 4.08k | { |
337 | 4.08k | absl::MutexLock lock(&mutex_); |
338 | 4.08k | json = monitored_data_.ToJson(); |
339 | 4.08k | } |
340 | 4.08k | json["PacemakerSchedulerStats"] = scheduler_.ToJson(); |
341 | 4.08k | return json; |
342 | 4.08k | } |
343 | | |
344 | | Pacemaker::Pacemaker( |
345 | | absl::Duration interval, |
346 | | std::unique_ptr<ShellCommandExecutor> shell_command_executor, |
347 | | ecclesia::Clock* clock) |
348 | 2.04k | : shell_command_executor_(std::move(shell_command_executor)), |
349 | 2.04k | scheduler_(clock) { |
350 | 2.04k | scheduler_.ScheduleAsync( |
351 | 2.04k | [this](absl::AnyInvocable<void()> OnDone) { |
352 | 0 | if (absl::Status status = PerformChecks(); !status.ok()) { |
353 | 0 | LOG(ERROR) << "Failed to perform checks: " << status; |
354 | 0 | } else { |
355 | | // Dump the monitoring data to the syslog periodically. |
356 | 0 | LOG(WARNING) << "tlBMC Health stats:\n" |
357 | 0 | << GetMonitoringData().dump(2); |
358 | 0 | } |
359 | 0 | OnDone(); |
360 | 0 | }, |
361 | 2.04k | interval); |
362 | 2.04k | } |
363 | | |
364 | | } // namespace milotic_tlbmc |