OLD | NEW |
| (Empty) |
1 // Copyright 2016 The Chromium Authors. All rights reserved. | |
2 // Use of this source code is governed by a BSD-style license that can be | |
3 // found in the LICENSE file. | |
4 | |
5 #include "components/arc/metrics/oom_kills_monitor.h" | |
6 | |
7 #include <errno.h> | |
8 #include <fcntl.h> | |
9 #include <stdio.h> | |
10 | |
11 #include <vector> | |
12 | |
13 #include "base/bind.h" | |
14 #include "base/debug/leak_annotations.h" | |
15 #include "base/files/file_util.h" | |
16 #include "base/files/scoped_file.h" | |
17 #include "base/location.h" | |
18 #include "base/logging.h" | |
19 #include "base/memory/ptr_util.h" | |
20 #include "base/metrics/histogram_macros.h" | |
21 #include "base/posix/safe_strerror.h" | |
22 #include "base/sequenced_task_runner.h" | |
23 #include "base/strings/string_number_conversions.h" | |
24 #include "base/strings/string_piece.h" | |
25 #include "base/strings/string_split.h" | |
26 #include "base/time/time.h" | |
27 #include "components/arc/metrics/oom_kills_histogram.h" | |
28 #include "third_party/re2/src/re2/re2.h" | |
29 #include "third_party/re2/src/re2/stringpiece.h" | |
30 | |
31 namespace arc { | |
32 | |
33 using base::StringPiece; | |
34 | |
35 using base::SequencedWorkerPool; | |
36 using base::TimeDelta; | |
37 | |
38 namespace { | |
39 | |
40 int64_t GetTimestamp(const StringPiece& line) { | |
41 std::vector<StringPiece> fields = base::SplitStringPiece( | |
42 line, ",", base::TRIM_WHITESPACE, base::SPLIT_WANT_ALL); | |
43 | |
44 int64_t timestamp = -1; | |
45 // Timestamp is the third field in a line of /dev/kmsg. | |
46 if (fields.size() < 3 || !base::StringToInt64(fields[2], ×tamp)) | |
47 return -1; | |
48 return timestamp; | |
49 } | |
50 | |
51 bool GetTimeDelta( | |
52 const StringPiece& line, int64_t* last, TimeDelta* time_delta) { | |
53 int64_t now = GetTimestamp(line); | |
54 if (now < 0) | |
55 return false; | |
56 | |
57 // Sets to |kMaxOomMemoryKillTimeSecs| for the first kill event. | |
58 if (*last < 0) | |
59 *time_delta = TimeDelta::FromSeconds(kMaxOomMemoryKillTimeDeltaSecs); | |
60 else | |
61 *time_delta = TimeDelta::FromMicroseconds(now - *last); | |
62 | |
63 *last = now; | |
64 | |
65 return true; | |
66 } | |
67 | |
68 void LogOOMKill(const StringPiece& line) { | |
69 static int64_t last_timestamp = -1; | |
70 static int oom_kills = 0; | |
71 | |
72 // Sample log line: | |
73 // 3,1362,97646497541,-;Out of memory: Kill process 29582 (android.vending) | |
74 // score 961 or sacrifice child. | |
75 int oom_badness; | |
76 TimeDelta time_delta; | |
77 if (RE2::PartialMatch(re2::StringPiece(line.data(), line.size()), | |
78 "Out of memory: Kill process .* score (\\d+)", | |
79 &oom_badness)) { | |
80 ++oom_kills; | |
81 // Report the cumulative count of killed process in one login session. | |
82 // For example if there are 3 processes killed, it would report 1 for the | |
83 // first kill, 2 for the second kill, then 3 for the final kill. | |
84 // It doesn't report a final count at the end of a user session because | |
85 // the code runs in a dedicated thread and never ends until browser shutdown | |
86 // (or logout on Chrome OS). And on browser shutdown the thread may be | |
87 // terminated brutally so there's no chance to execute a "final" block. | |
88 // More specifically, code outside the main loop of OomKillsMonitor::Run() | |
89 // are not guaranteed to be executed. | |
90 UMA_HISTOGRAM_CUSTOM_COUNTS( | |
91 "Arc.OOMKills.Count", oom_kills, 1, 1000, 1001); | |
92 | |
93 // In practice most process has oom_badness < 1000, but | |
94 // strictly speaking the number could be [1, 2000]. What it really | |
95 // means is the baseline, proportion of memory used (normalized to | |
96 // [0, 1000]), plus an adjustment score oom_score_adj [-1000, 1000], | |
97 // truncated to 1 if negative (0 means never kill). | |
98 // Ref: https://lwn.net/Articles/396552/ | |
99 UMA_HISTOGRAM_CUSTOM_COUNTS( | |
100 "Arc.OOMKills.Score", oom_badness, 1, 2000, 2001); | |
101 | |
102 if (GetTimeDelta(line, &last_timestamp, &time_delta)) { | |
103 UMA_HISTOGRAM_OOM_KILL_TIME_INTERVAL( | |
104 "Arc.OOMKills.TimeDelta", time_delta); | |
105 } | |
106 } | |
107 } | |
108 | |
109 void LogLowMemoryKill(const StringPiece& line) { | |
110 static int64_t last_timestamp = -1; | |
111 static int low_memory_kills = 0; | |
112 | |
113 int freed_size; | |
114 TimeDelta time_delta; | |
115 // Sample log line: | |
116 // 6,2302,533604004,-;lowmemorykiller: Killing 'externalstorage' (21742), | |
117 // adj 1000,\x0a to free 27320kB on behalf of 'kswapd0' (47) because\x0a | |
118 // cache 181920kB is below limit 184320kB for oom_score_adj 1000\x0a | |
119 // Free memory is 1228kB above reserved | |
120 if (RE2::PartialMatch(re2::StringPiece(line.data(), line.size()), | |
121 "lowmemorykiller: .* to free (\\d+)kB", | |
122 &freed_size)) { | |
123 // Report the count for each lowmemorykill event. See comments in | |
124 // LogOOMKill(). | |
125 ++low_memory_kills; | |
126 UMA_HISTOGRAM_CUSTOM_COUNTS( | |
127 "Arc.LowMemoryKiller.Count", low_memory_kills, 1, 1000, 1001); | |
128 | |
129 UMA_HISTOGRAM_MEMORY_KB("Arc.LowMemoryKiller.FreedSize", freed_size); | |
130 | |
131 if (GetTimeDelta(line, &last_timestamp, &time_delta)) { | |
132 UMA_HISTOGRAM_OOM_KILL_TIME_INTERVAL( | |
133 "Arc.LowMemoryKiller.TimeDelta", time_delta); | |
134 } | |
135 } | |
136 } | |
137 | |
138 } // namespace | |
139 | |
140 OomKillsMonitor::Handle::Handle(OomKillsMonitor* outer) : outer_(outer) { | |
141 DCHECK(outer_); | |
142 } | |
143 | |
144 OomKillsMonitor::Handle::~Handle() { | |
145 outer_->is_shutting_down_.Set(); | |
146 } | |
147 | |
148 OomKillsMonitor::OomKillsMonitor() { | |
149 base::SimpleThread::Options non_joinable_options; | |
150 non_joinable_options.joinable = false; | |
151 non_joinable_worker_thread_ = base::MakeUnique<base::DelegateSimpleThread>( | |
152 this, "oom_kills_monitor", non_joinable_options); | |
153 non_joinable_worker_thread_->Start(); | |
154 } | |
155 | |
156 OomKillsMonitor::~OomKillsMonitor() { | |
157 // The instance has to be leaked on shutdown as it is referred to by a | |
158 // non-joinable thread but ~OomKillsMonitor() can't be explicitly deleted as | |
159 // it overrides ~SimpleThread(), it should nevertheless never be invoked. | |
160 NOTREACHED(); | |
161 } | |
162 | |
163 // static | |
164 OomKillsMonitor::Handle OomKillsMonitor::StartMonitoring() { | |
165 #if DCHECK_IS_ON() | |
166 static volatile bool monitoring_active = false; | |
167 DCHECK(!monitoring_active); | |
168 monitoring_active = true; | |
169 #endif | |
170 | |
171 // Instantiate the OomKillsMonitor and its underlying thread. The | |
172 // OomKillsMonitor itself has to be leaked on shutdown per having a | |
173 // non-joinable thread associated to its state. The OomKillsMonitor::Handle | |
174 // will notify the OomKillsMonitor when it is destroyed so that the underlying | |
175 // thread can at a minimum not do extra work during shutdown. | |
176 OomKillsMonitor* instance = new OomKillsMonitor; | |
177 ANNOTATE_LEAKING_OBJECT_PTR(instance); | |
178 return Handle(instance); | |
179 } | |
180 | |
181 void OomKillsMonitor::Run() { | |
182 base::ScopedFILE kmsg_handle( | |
183 base::OpenFile(base::FilePath("/dev/kmsg"), "r")); | |
184 if (!kmsg_handle) { | |
185 LOG(WARNING) << "Open /dev/kmsg failed: " << base::safe_strerror(errno); | |
186 return; | |
187 } | |
188 // Skip kernel messages prior to the instantiation of this object to avoid | |
189 // double reporting. | |
190 fseek(kmsg_handle.get(), 0, SEEK_END); | |
191 | |
192 static const int kMaxBufSize = 512; | |
193 char buf[kMaxBufSize]; | |
194 | |
195 while (fgets(buf, kMaxBufSize, kmsg_handle.get())) { | |
196 if (is_shutting_down_.IsSet()) { | |
197 DVLOG(1) << "Chrome is shutting down, exit now."; | |
198 break; | |
199 } | |
200 const StringPiece buf_string(buf); | |
201 LogOOMKill(buf_string); | |
202 LogLowMemoryKill(buf_string); | |
203 } | |
204 } | |
205 | |
206 } // namespace arc | |
OLD | NEW |