| 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 |