/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* kActivatingStatus = "activating"; |
37 | | constexpr const char* kRestartCommand = "systemctl restart %s"; |
38 | | constexpr const char* kIsListeningCommand = "ss -tulpn | grep %d"; |
39 | | constexpr const char* kGetMemoryUsageCommand = |
40 | | "cat /proc/%d/status | grep VmRSS | awk '{print $2}'"; |
41 | | constexpr const char* kGetPidCommand = |
42 | | "systemctl status %s | grep 'Main PID:' | awk '{print $3}'"; |
43 | | constexpr const char* kGetCpuUsageCommand = |
44 | | "top -n1 | grep %s -i | awk '{print int($8)}'"; |
45 | | constexpr const char* kGetActiveEnterTimestampMonotonic = |
46 | | "systemctl show --property=ActiveEnterTimestampMonotonic %s | awk -F'=' " |
47 | | "'{print $2}'"; |
48 | | constexpr const int kMaxRecentDataPoints = 12; |
49 | | |
50 | | } // namespace |
51 | | |
52 | 5.19k | nlohmann::json Pacemaker::ErrorInfo::ToJson() const { |
53 | 5.19k | auto error_type_to_string = [](ErrorType type) -> std::string { |
54 | 5.19k | switch (type) { |
55 | 1.98k | case ErrorType::kUnknown: |
56 | 1.98k | return "Unknown"; |
57 | 2.79k | case ErrorType::kServiceInactive: |
58 | 2.79k | return "ServiceInactive"; |
59 | 283 | case ErrorType::kPortNotListening: |
60 | 283 | return "PortNotListening"; |
61 | 111 | case ErrorType::kMemoryUsageAboveThreshold: |
62 | 111 | return "MemoryUsageAboveThreshold"; |
63 | 26 | default: |
64 | 26 | return "Unknown"; |
65 | 5.19k | } |
66 | 5.19k | }; |
67 | | |
68 | 5.19k | nlohmann::json json; |
69 | 5.19k | json["type"] = error_type_to_string(type); |
70 | 5.19k | json["timestamp"] = absl::FormatTime(timestamp); |
71 | 5.19k | return json; |
72 | 5.19k | } |
73 | | |
74 | 4.18k | nlohmann::json Pacemaker::MonitoredData::ToJson() const { |
75 | 4.18k | nlohmann::json json; |
76 | | // Get the last kMaxRecentDataPoints memory usage data points. |
77 | 4.18k | auto it = memory_usage_bytes.rbegin(); |
78 | 6.29k | for (int i = 0; i < kMaxRecentDataPoints && it != memory_usage_bytes.rend(); |
79 | 4.18k | ++i, ++it) { |
80 | 2.11k | json["MemoryUsageRecentToOldest"].push_back(*it); |
81 | 2.11k | } |
82 | | // Get the last kMaxRecentDataPoints error data points. |
83 | 4.18k | auto it_error = restart_log.rbegin(); |
84 | 8.27k | for (int i = 0; i < kMaxRecentDataPoints && it_error != restart_log.rend(); |
85 | 4.18k | ++i, ++it_error) { |
86 | 4.09k | json["ErrorsRecentToOldest"].push_back(it_error->ToJson()); |
87 | 4.09k | } |
88 | 4.18k | json["CpuUsage"] = cpu_usage; |
89 | 4.18k | json["MemoryUsage"] = |
90 | 4.18k | memory_usage_bytes.empty() ? -1 : memory_usage_bytes.back(); |
91 | 4.18k | json["LastActiveTimestamp"] = last_active_timestamp; |
92 | 4.18k | json["LastResetTime"] = absl::FormatTime(last_reset_time); |
93 | 4.18k | json["RestartTriggered"] = restart_triggered; |
94 | 4.18k | json["Pid"] = pid; |
95 | 4.18k | json["ConsecutiveRestartAttempts"] = consecutive_restart_attempts; |
96 | 4.18k | return json; |
97 | 4.18k | } |
98 | | |
99 | | absl::StatusOr<std::string> ShellCommandExecutor::Execute( |
100 | 0 | const std::string& command) { |
101 | 0 | FILE* pipe = popen(command.c_str(), "r"); |
102 | 0 | if (pipe == nullptr) { |
103 | 0 | return absl::InternalError( |
104 | 0 | absl::StrCat("Error: Failed to execute command: ", command)); |
105 | 0 | } |
106 | 0 | std::string result; |
107 | 0 | char* line = nullptr; |
108 | 0 | size_t len = 0; |
109 | 0 | ssize_t read; |
110 | |
|
111 | 0 | while ((read = getline(&line, &len, pipe)) != -1) { |
112 | 0 | result.append(line, static_cast<std::string::size_type>(read)); |
113 | 0 | } |
114 | |
|
115 | 0 | free(line); |
116 | 0 | pclose(pipe); |
117 | 0 | return result; |
118 | 0 | } |
119 | | |
120 | | absl::StatusOr<std::string> Pacemaker::GetServiceStatus( |
121 | 4.18k | const std::string& service_name) const { |
122 | 12.5k | LOG(INFO) << "Checking status of service " << service_name; |
123 | 4.18k | ECCLESIA_ASSIGN_OR_RETURN( |
124 | 2.89k | std::string output, shell_command_executor_->Execute( |
125 | 2.89k | absl::StrFormat(kIsActiveCommand, service_name))); |
126 | 2.89k | absl::StripAsciiWhitespace(&output); |
127 | 2.89k | return output; |
128 | 4.18k | } |
129 | | |
130 | | absl::StatusOr<bool> Pacemaker::IsServiceActive( |
131 | 2.09k | const std::string& service_name) const { |
132 | 2.09k | ECCLESIA_ASSIGN_OR_RETURN(std::string status, GetServiceStatus(service_name)); |
133 | | // Compare string |
134 | 1.70k | if (!absl::EqualsIgnoreCase(status, kActiveStatus)) { |
135 | 5.10k | LOG(ERROR) << "Service " << service_name << " is not active." |
136 | 5.10k | << " status is " << status << " instead of " << kActiveStatus; |
137 | 1.70k | return false; |
138 | 1.70k | } |
139 | 2 | return true; |
140 | 1.70k | } |
141 | | |
142 | | absl::StatusOr<bool> Pacemaker::IsServiceActivating( |
143 | 0 | const std::string& service_name) const { |
144 | 0 | ECCLESIA_ASSIGN_OR_RETURN(std::string status, GetServiceStatus(service_name)); |
145 | 0 | return absl::EqualsIgnoreCase(status, kActivatingStatus); |
146 | 0 | } |
147 | | |
148 | 2.37k | absl::StatusOr<bool> Pacemaker::IsPortListening(int port) const { |
149 | 7.13k | LOG(INFO) << "Checking if port " << port << " is listening."; |
150 | 2.37k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
151 | 2.21k | shell_command_executor_->Execute( |
152 | 2.21k | absl::StrFormat(kIsListeningCommand, port))); |
153 | 2.21k | return !output.empty(); |
154 | 2.37k | } |
155 | | |
156 | 2.23k | absl::StatusOr<int> Pacemaker::GetMemoryUsage(int pid) const { |
157 | 6.69k | LOG(INFO) << "Getting memory usage for pid " << pid; |
158 | 4.34k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
159 | 4.34k | shell_command_executor_->Execute( |
160 | 4.34k | absl::StrFormat(kGetMemoryUsageCommand, pid))); |
161 | 4.34k | int memory_usage; |
162 | 4.34k | if (!absl::SimpleAtoi(output, &memory_usage)) { |
163 | 2.01k | return absl::InternalError( |
164 | 2.01k | absl::StrCat("Error: Failed to parse memory usage: ", output)); |
165 | 2.01k | } |
166 | 96 | return memory_usage; |
167 | 4.34k | } |
168 | | |
169 | | absl::StatusOr<int> Pacemaker::GetCpuUsage( |
170 | 2.31k | const std::string& process_name) const { |
171 | 6.93k | LOG(INFO) << "Getting CPU usage for process " << process_name; |
172 | 4.17k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
173 | 4.17k | shell_command_executor_->Execute(absl::StrFormat( |
174 | 4.17k | kGetCpuUsageCommand, process_name))); |
175 | 4.17k | int cpu_usage = -1; |
176 | 4.17k | if (output.empty()) { |
177 | 1.70k | return cpu_usage; |
178 | 1.70k | } |
179 | 157 | if (!absl::SimpleAtoi(output, &cpu_usage)) { |
180 | 132 | return absl::InternalError( |
181 | 132 | absl::StrCat("Error: Failed to parse CPU usage: ", output)); |
182 | 132 | } |
183 | 25 | return cpu_usage; |
184 | 157 | } |
185 | | |
186 | | absl::StatusOr<int64_t> Pacemaker::GetLastActiveTimestamp( |
187 | 3.14k | const std::string& process_name) const { |
188 | 9.44k | LOG(INFO) << "Getting last active timestamp for process " << process_name; |
189 | 5.78k | ECCLESIA_ASSIGN_OR_RETURN( |
190 | 5.78k | std::string output, |
191 | 5.78k | shell_command_executor_->Execute( |
192 | 5.78k | absl::StrFormat(kGetActiveEnterTimestampMonotonic, process_name))); |
193 | 5.78k | int64_t last_active_timestamp; |
194 | 5.78k | if (!absl::SimpleAtoi(output, &last_active_timestamp)) { |
195 | 2.31k | return absl::InternalError( |
196 | 2.31k | absl::StrCat("Error: Failed to parse last reset time: ", output)); |
197 | 2.31k | } |
198 | 321 | return last_active_timestamp; |
199 | 5.78k | } |
200 | | |
201 | 3.09k | absl::Status Pacemaker::RestartService(const std::string& service_name) { |
202 | 9.27k | LOG(ERROR) << "Restarting service " << service_name; |
203 | 3.09k | { |
204 | 3.09k | absl::MutexLock lock(&mutex_); |
205 | 3.09k | if (monitored_data_.restart_triggered) { |
206 | 999 | if (monitored_data_.consecutive_restart_attempts >= |
207 | 999 | kMaxConsecutiveRestartAttempts) { |
208 | 0 | LOG(ERROR) << "Restart attempts exceeded the limit of " |
209 | 0 | << kMaxConsecutiveRestartAttempts; |
210 | 0 | return absl::InternalError( |
211 | 0 | absl::StrCat("Error: Restart attempts exceeded the limit of ", |
212 | 0 | kMaxConsecutiveRestartAttempts)); |
213 | 0 | } |
214 | 999 | ++monitored_data_.consecutive_restart_attempts; |
215 | 999 | } |
216 | 3.09k | monitored_data_.restart_triggered = true; |
217 | 3.09k | monitored_data_.last_reset_time = absl::Now(); |
218 | 3.09k | } |
219 | 2.61k | ECCLESIA_ASSIGN_OR_RETURN( |
220 | 2.61k | std::string output, shell_command_executor_->Execute( |
221 | 2.61k | absl::StrFormat(kRestartCommand, service_name))); |
222 | 2.61k | return absl::OkStatus(); |
223 | 3.09k | } |
224 | | |
225 | | // Get PID of the process. |
226 | 2.35k | absl::StatusOr<int> Pacemaker::GetPid(const std::string& process_name) const { |
227 | 7.06k | LOG(INFO) << "Getting PID for process " << process_name; |
228 | 4.21k | ECCLESIA_ASSIGN_OR_RETURN(std::string output, |
229 | 4.21k | shell_command_executor_->Execute( |
230 | 4.21k | absl::StrFormat(kGetPidCommand, process_name))); |
231 | 4.21k | int pid = -1; |
232 | 4.21k | if (output.empty()) { |
233 | 1.21k | return absl::InternalError( |
234 | 1.21k | absl::StrCat("Error: Main PID not found for service: ", process_name)); |
235 | 1.21k | } |
236 | | // Trim leading and trailing whitespace, including newlines. |
237 | 644 | output = std::string(absl::StripAsciiWhitespace(output)); |
238 | | |
239 | 644 | if (absl::SimpleAtoi(output, &pid)) { |
240 | 373 | return pid; |
241 | 373 | } |
242 | 271 | return absl::InternalError( |
243 | 271 | absl::StrCat("Error: Invalid PID found in systemctl output: ", output, |
244 | 271 | " for service: ", process_name)); |
245 | 644 | } |
246 | | |
247 | 3.09k | void Pacemaker::RecordError(ErrorType type) { |
248 | 3.09k | absl::MutexLock lock(&mutex_); |
249 | | // If the error type is unknown, we can't determine the timestamp. |
250 | | // So we just record the error and continue. |
251 | 3.09k | if (type == ErrorType::kUnknown) { |
252 | 1.98k | monitored_data_.restart_log.push_back({type, absl::InfinitePast()}); |
253 | 1.98k | return; |
254 | 1.98k | } |
255 | 1.10k | ErrorInfo error_info = {type, absl::Now()}; |
256 | 3.32k | LOG(ERROR) << "Restart required due to Error:\n" |
257 | 3.32k | << error_info.ToJson().dump(2); |
258 | 1.10k | monitored_data_.restart_log.push_back(error_info); |
259 | 1.10k | } |
260 | | |
261 | 2.09k | absl::Status Pacemaker::PerformChecks() { |
262 | 2.09k | bool unknown_restart_detected = false; |
263 | 2.09k | ECCLESIA_ASSIGN_OR_RETURN(std::string service_status, |
264 | 1.19k | GetServiceStatus(kProcessName)); |
265 | | |
266 | 1.19k | if (absl::EqualsIgnoreCase(service_status, kActivatingStatus)) { |
267 | 3 | LOG(INFO) << "Service " << kProcessName |
268 | 3 | << " is activating. Skipping checks and restart."; |
269 | 1 | return absl::OkStatus(); |
270 | 1 | } |
271 | | |
272 | 1.19k | bool is_active = absl::EqualsIgnoreCase(service_status, kActiveStatus); |
273 | 1.19k | if (!is_active) { |
274 | 2.72k | LOG(ERROR) << "Service " << kProcessName << " is not active." |
275 | 2.72k | << " status is " << service_status << " instead of " |
276 | 2.72k | << kActiveStatus; |
277 | 909 | } |
278 | | |
279 | 1.19k | int pid = -1; |
280 | 1.19k | int cpu_usage = -1; |
281 | 1.19k | int memory_usage = -1; |
282 | 1.19k | bool is_listening = false; |
283 | | |
284 | 1.19k | if (is_active) { |
285 | 285 | ECCLESIA_ASSIGN_OR_RETURN(is_listening, |
286 | 261 | IsPortListening(kExpectedListeningPort)); |
287 | 261 | ECCLESIA_ASSIGN_OR_RETURN(pid, GetPid(kProcessName)); |
288 | 217 | ECCLESIA_ASSIGN_OR_RETURN(cpu_usage, GetCpuUsage(kProcessName)); |
289 | 196 | if (pid > 0) { |
290 | 139 | ECCLESIA_ASSIGN_OR_RETURN(memory_usage, GetMemoryUsage(pid)); |
291 | 89 | } |
292 | 196 | } |
293 | | |
294 | 1.05k | absl::StatusOr<int64_t> last_active_timestamp = |
295 | 1.05k | GetLastActiveTimestamp(kProcessName); |
296 | 1.05k | if (!last_active_timestamp.ok()) { |
297 | 2.23k | LOG(ERROR) << "Failed to get last active timestamp: " |
298 | 2.23k | << last_active_timestamp.status(); |
299 | 744 | } |
300 | | |
301 | | // Update monitored data. |
302 | 1.05k | { |
303 | 1.05k | absl::MutexLock lock(&mutex_); |
304 | 1.05k | monitored_data_.memory_usage_bytes.push_back(memory_usage); |
305 | 1.05k | monitored_data_.cpu_usage = cpu_usage; |
306 | 1.05k | monitored_data_.pid = pid; |
307 | | |
308 | | // Check if the process was restarted outside of pacemaker. |
309 | 1.05k | if (last_active_timestamp.ok()) { |
310 | | // We check if the `last_active_timestamp` we got from systemctl |
311 | | // is different from the one we got from the previous run and if the |
312 | | // process was not restarted by pacemaker. |
313 | | // If the timestamps are different, it means the process was restarted |
314 | | // outside of pacemaker and we should record it as an unknown error. |
315 | 311 | if (monitored_data_.last_active_timestamp != -1 && |
316 | 0 | *last_active_timestamp != monitored_data_.last_active_timestamp && |
317 | 0 | !monitored_data_.restart_triggered) { |
318 | 0 | LOG(INFO) << "Process " << kProcessName |
319 | 0 | << " was restarted outside of pacemaker."; |
320 | 0 | unknown_restart_detected = true; |
321 | 0 | } |
322 | 311 | monitored_data_.last_active_timestamp = *last_active_timestamp; |
323 | 311 | } |
324 | 1.05k | } |
325 | | |
326 | 1.05k | if (unknown_restart_detected) { |
327 | 0 | RecordError(ErrorType::kUnknown); |
328 | 0 | } |
329 | | |
330 | 1.05k | if (!is_active) { |
331 | 909 | RecordError(ErrorType::kServiceInactive); |
332 | 909 | ECCLESIA_RETURN_IF_ERROR(RestartService(kProcessName)); |
333 | 843 | return absl::OkStatus(); |
334 | 909 | } |
335 | | |
336 | 146 | if (!is_listening) { |
337 | 195 | LOG(ERROR) << "Process " << kProcessName << " is not listening on port " |
338 | 195 | << kExpectedListeningPort; |
339 | 65 | RecordError(ErrorType::kPortNotListening); |
340 | 65 | ECCLESIA_RETURN_IF_ERROR(RestartService(kProcessName)); |
341 | 46 | return absl::OkStatus(); |
342 | 65 | } |
343 | | |
344 | 81 | if (memory_usage > kMemoryUsageThreshold) { |
345 | 75 | LOG(ERROR) << "Process " << kProcessName << " memory usage is " |
346 | 75 | << memory_usage << " bytes which is more than the threshold of " |
347 | 75 | << kMemoryUsageThreshold; |
348 | 25 | RecordError(ErrorType::kMemoryUsageAboveThreshold); |
349 | 25 | ECCLESIA_RETURN_IF_ERROR(RestartService(kProcessName)); |
350 | 1 | return absl::OkStatus(); |
351 | 25 | } |
352 | | |
353 | | // If we reach here, it means all checks passed. |
354 | | // Reset the restart triggered and consecutive restart attempts counters. |
355 | 56 | absl::MutexLock lock(&mutex_); |
356 | 56 | monitored_data_.restart_triggered = false; |
357 | 56 | monitored_data_.consecutive_restart_attempts = 0; |
358 | 56 | return absl::OkStatus(); |
359 | 81 | } |
360 | | |
361 | 4.18k | nlohmann::json Pacemaker::GetMonitoringData() const { |
362 | 4.18k | nlohmann::json json; |
363 | 4.18k | { |
364 | 4.18k | absl::MutexLock lock(&mutex_); |
365 | 4.18k | json = monitored_data_.ToJson(); |
366 | 4.18k | } |
367 | 4.18k | json["PacemakerSchedulerStats"] = scheduler_.ToJson(); |
368 | 4.18k | return json; |
369 | 4.18k | } |
370 | | |
371 | | Pacemaker::Pacemaker( |
372 | | absl::Duration interval, |
373 | | std::unique_ptr<ShellCommandExecutor> shell_command_executor, |
374 | | ecclesia::Clock* clock) |
375 | 2.09k | : shell_command_executor_(std::move(shell_command_executor)), |
376 | 2.09k | scheduler_(clock) { |
377 | 2.09k | scheduler_.ScheduleAsync( |
378 | 2.09k | [this](absl::AnyInvocable<void()> OnDone) { |
379 | 0 | if (absl::Status status = PerformChecks(); !status.ok()) { |
380 | 0 | LOG(ERROR) << "Failed to perform checks: " << status; |
381 | 0 | } else { |
382 | | // Dump the monitoring data to the syslog periodically. |
383 | 0 | LOG(WARNING) << "tlBMC Health stats:\n" |
384 | 0 | << GetMonitoringData().dump(2); |
385 | 0 | } |
386 | 0 | OnDone(); |
387 | 0 | }, |
388 | 2.09k | interval); |
389 | 2.09k | } |
390 | | |
391 | | } // namespace milotic_tlbmc |