1 /*
2  * Copyright (C) 2017 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 #define LOG_TAG "storaged"
18 
19 #include <stdint.h>
20 #include <stdlib.h>
21 
22 #include <sstream>
23 
24 #include <android-base/file.h>
25 #include <android-base/logging.h>
26 #include <log/log_event_list.h>
27 
28 #include "storaged.h"
29 #include "storaged_diskstats.h"
30 
31 namespace {
32 
33 using android::sp;
34 using android::hardware::health::V2_0::DiskStats;
35 using android::hardware::health::V2_0::IHealth;
36 using android::hardware::health::V2_0::Result;
37 using android::hardware::health::V2_0::toString;
38 
39 #ifdef DEBUG
log_debug_disk_perf(struct disk_perf * perf,const char * type)40 void log_debug_disk_perf(struct disk_perf* perf, const char* type) {
41     // skip if the input structure are all zeros
42     if (perf == NULL || perf->is_zero()) return;
43 
44     LOG(INFO) << "disk_perf " << type << " rd: " << perf->read_perf << " kbps, " << perf->read_ios
45               << " iops"
46               << " wr: " << perf->write_perf << " kbps, " << perf->write_ios << " iops"
47               << " q: " << perf->queue;
48 }
49 #else
log_debug_disk_perf(struct disk_perf * perf,const char * type)50 void log_debug_disk_perf(struct disk_perf* perf, const char* type) {}
51 #endif
52 
log_event_disk_stats(struct disk_stats * stats,const char * type)53 void log_event_disk_stats(struct disk_stats* stats, const char* type) {
54     // skip if the input structure are all zeros
55     if (stats == NULL || stats->is_zero()) return;
56 
57     android_log_event_list(EVENTLOGTAG_DISKSTATS)
58         << type << stats->start_time << stats->end_time
59         << stats->read_ios << stats->read_merges
60         << stats->read_sectors << stats->read_ticks
61         << stats->write_ios << stats->write_merges
62         << stats->write_sectors << stats->write_ticks
63         << (uint64_t)stats->io_avg << stats->io_ticks << stats->io_in_queue
64         << LOG_ID_EVENTS;
65 }
66 
67 } // namespace
68 
get_time(struct timespec * ts)69 bool get_time(struct timespec* ts) {
70     // Use monotonic to exclude suspend time so that we measure IO bytes/sec
71     // when system is running.
72     int ret = clock_gettime(CLOCK_MONOTONIC, ts);
73     if (ret < 0) {
74         PLOG(ERROR) << "clock_gettime() failed";
75         return false;
76     }
77     return true;
78 }
79 
init_disk_stats_other(const struct timespec & ts,struct disk_stats * stats)80 void init_disk_stats_other(const struct timespec& ts, struct disk_stats* stats) {
81     stats->start_time = 0;
82     stats->end_time = (uint64_t)ts.tv_sec * SEC_TO_MSEC + ts.tv_nsec / (MSEC_TO_USEC * USEC_TO_NSEC);
83     stats->counter = 1;
84     stats->io_avg = (double)stats->io_in_flight;
85 }
86 
parse_disk_stats(const char * disk_stats_path,struct disk_stats * stats)87 bool parse_disk_stats(const char* disk_stats_path, struct disk_stats* stats) {
88     // Get time
89     struct timespec ts;
90     if (!get_time(&ts)) {
91         return false;
92     }
93 
94     std::string buffer;
95     if (!android::base::ReadFileToString(disk_stats_path, &buffer)) {
96         PLOG(ERROR) << disk_stats_path << ": ReadFileToString failed.";
97         return false;
98     }
99 
100     // Regular diskstats entries
101     std::stringstream ss(buffer);
102     for (uint i = 0; i < DISK_STATS_SIZE; ++i) {
103         ss >> *((uint64_t*)stats + i);
104     }
105     // Other entries
106     init_disk_stats_other(ts, stats);
107     return true;
108 }
109 
convert_hal_disk_stats(struct disk_stats * dst,const DiskStats & src)110 void convert_hal_disk_stats(struct disk_stats* dst, const DiskStats& src) {
111     dst->read_ios = src.reads;
112     dst->read_merges = src.readMerges;
113     dst->read_sectors = src.readSectors;
114     dst->read_ticks = src.readTicks;
115     dst->write_ios = src.writes;
116     dst->write_merges = src.writeMerges;
117     dst->write_sectors = src.writeSectors;
118     dst->write_ticks = src.writeTicks;
119     dst->io_in_flight = src.ioInFlight;
120     dst->io_ticks = src.ioTicks;
121     dst->io_in_queue = src.ioInQueue;
122 }
123 
get_disk_stats_from_health_hal(const sp<IHealth> & service,struct disk_stats * stats)124 bool get_disk_stats_from_health_hal(const sp<IHealth>& service, struct disk_stats* stats) {
125     struct timespec ts;
126     if (!get_time(&ts)) {
127         return false;
128     }
129 
130     bool success = false;
131     auto ret = service->getDiskStats([&success, stats](auto result, const auto& halStats) {
132         if (result == Result::NOT_SUPPORTED) {
133             LOG(DEBUG) << "getDiskStats is not supported on health HAL.";
134             return;
135         }
136         if (result != Result::SUCCESS || halStats.size() == 0) {
137             LOG(ERROR) << "getDiskStats failed with result " << toString(result) << " and size "
138                        << halStats.size();
139             return;
140         }
141 
142         convert_hal_disk_stats(stats, halStats[0]);
143         success = true;
144     });
145 
146     if (!ret.isOk()) {
147         LOG(ERROR) << "getDiskStats failed with " << ret.description();
148         return false;
149     }
150 
151     if (!success) {
152         return false;
153     }
154 
155     init_disk_stats_other(ts, stats);
156     return true;
157 }
158 
get_disk_perf(struct disk_stats * stats)159 struct disk_perf get_disk_perf(struct disk_stats* stats)
160 {
161     struct disk_perf perf = {};
162 
163     if (stats->io_ticks) {
164         if (stats->read_ticks) {
165             unsigned long long divisor = stats->read_ticks * stats->io_ticks;
166             perf.read_perf = ((unsigned long long)SECTOR_SIZE *
167                               stats->read_sectors * stats->io_in_queue +
168                               (divisor >> 1)) / divisor;
169             perf.read_ios = ((unsigned long long)SEC_TO_MSEC *
170                              stats->read_ios * stats->io_in_queue +
171                              (divisor >> 1)) / divisor;
172         }
173         if (stats->write_ticks) {
174             unsigned long long divisor = stats->write_ticks * stats->io_ticks;
175             perf.write_perf = ((unsigned long long)SECTOR_SIZE *
176                                stats->write_sectors * stats->io_in_queue +
177                                (divisor >> 1)) / divisor;
178             perf.write_ios = ((unsigned long long)SEC_TO_MSEC *
179                               stats->write_ios * stats->io_in_queue +
180                               (divisor >> 1)) / divisor;
181         }
182         perf.queue = (stats->io_in_queue + (stats->io_ticks >> 1)) /
183                      stats->io_ticks;
184     }
185     return perf;
186 }
187 
get_inc_disk_stats(const struct disk_stats * prev,const struct disk_stats * curr,struct disk_stats * inc)188 void get_inc_disk_stats(const struct disk_stats* prev, const struct disk_stats* curr,
189                         struct disk_stats* inc)
190 {
191     *inc = *curr - *prev;
192     inc->start_time = prev->end_time;
193     inc->end_time = curr->end_time;
194     inc->io_avg = curr->io_avg;
195     inc->counter = 1;
196 }
197 
198 // Add src to dst
add_disk_stats(struct disk_stats * src,struct disk_stats * dst)199 void add_disk_stats(struct disk_stats* src, struct disk_stats* dst)
200 {
201     if (dst->end_time != 0 && dst->end_time != src->start_time) {
202         LOG(WARNING) << "Two dis-continuous periods of diskstats"
203                      << " are added. dst end with " << dst->end_time << ", src start with "
204                      << src->start_time;
205     }
206 
207     *dst += *src;
208 
209     dst->io_in_flight = src->io_in_flight;
210     if (dst->counter + src->counter) {
211         dst->io_avg =
212             ((dst->io_avg * dst->counter) + (src->io_avg * src->counter)) /
213             (dst->counter + src->counter);
214     }
215     dst->counter += src->counter;
216     dst->end_time = src->end_time;
217     if (dst->start_time == 0) {
218         dst->start_time = src->start_time;
219     }
220 }
221 
222 /* disk_stats_monitor */
update_mean()223 void disk_stats_monitor::update_mean()
224 {
225     CHECK(mValid);
226     mMean.read_perf = (uint32_t)mStats.read_perf.get_mean();
227     mMean.read_ios = (uint32_t)mStats.read_ios.get_mean();
228     mMean.write_perf = (uint32_t)mStats.write_perf.get_mean();
229     mMean.write_ios = (uint32_t)mStats.write_ios.get_mean();
230     mMean.queue = (uint32_t)mStats.queue.get_mean();
231 }
232 
update_std()233 void disk_stats_monitor::update_std()
234 {
235     CHECK(mValid);
236     mStd.read_perf = (uint32_t)mStats.read_perf.get_std();
237     mStd.read_ios = (uint32_t)mStats.read_ios.get_std();
238     mStd.write_perf = (uint32_t)mStats.write_perf.get_std();
239     mStd.write_ios = (uint32_t)mStats.write_ios.get_std();
240     mStd.queue = (uint32_t)mStats.queue.get_std();
241 }
242 
add(struct disk_perf * perf)243 void disk_stats_monitor::add(struct disk_perf* perf)
244 {
245     mStats.read_perf.add(perf->read_perf);
246     mStats.read_ios.add(perf->read_ios);
247     mStats.write_perf.add(perf->write_perf);
248     mStats.write_ios.add(perf->write_ios);
249     mStats.queue.add(perf->queue);
250 }
251 
evict(struct disk_perf * perf)252 void disk_stats_monitor::evict(struct disk_perf* perf) {
253     mStats.read_perf.evict(perf->read_perf);
254     mStats.read_ios.evict(perf->read_ios);
255     mStats.write_perf.evict(perf->write_perf);
256     mStats.write_ios.evict(perf->write_ios);
257     mStats.queue.evict(perf->queue);
258 }
259 
detect(struct disk_perf * perf)260 bool disk_stats_monitor::detect(struct disk_perf* perf)
261 {
262     return ((double)perf->queue >= (double)mMean.queue + mSigma * (double)mStd.queue) &&
263         ((double)perf->read_perf < (double)mMean.read_perf - mSigma * (double)mStd.read_perf) &&
264         ((double)perf->write_perf < (double)mMean.write_perf - mSigma * (double)mStd.write_perf);
265 }
266 
update(struct disk_stats * curr)267 void disk_stats_monitor::update(struct disk_stats* curr)
268 {
269     disk_stats inc;
270     get_inc_disk_stats(&mPrevious, curr, &inc);
271     add_disk_stats(&inc, &mAccumulate_pub);
272 
273     struct disk_perf perf = get_disk_perf(&inc);
274     log_debug_disk_perf(&perf, "regular");
275 
276     add(&perf);
277     mBuffer.push(perf);
278     if (mBuffer.size() > mWindow) {
279         evict(&mBuffer.front());
280         mBuffer.pop();
281         mValid = true;
282     }
283 
284     // Update internal data structures
285     if (LIKELY(mValid)) {
286         CHECK_EQ(mBuffer.size(), mWindow);
287         update_mean();
288         update_std();
289         if (UNLIKELY(detect(&perf))) {
290             mStall = true;
291             add_disk_stats(&inc, &mAccumulate);
292             log_debug_disk_perf(&mMean, "stalled_mean");
293             log_debug_disk_perf(&mStd, "stalled_std");
294         } else {
295             if (mStall) {
296                 struct disk_perf acc_perf = get_disk_perf(&mAccumulate);
297                 log_debug_disk_perf(&acc_perf, "stalled");
298                 log_event_disk_stats(&mAccumulate, "stalled");
299                 mStall = false;
300                 memset(&mAccumulate, 0, sizeof(mAccumulate));
301             }
302         }
303     }
304 
305     mPrevious = *curr;
306 }
307 
update()308 void disk_stats_monitor::update() {
309     disk_stats curr;
310     if (mHealth != nullptr) {
311         if (!get_disk_stats_from_health_hal(mHealth, &curr)) {
312             return;
313         }
314     } else {
315         if (!parse_disk_stats(DISK_STATS_PATH, &curr)) {
316             return;
317         }
318     }
319 
320     update(&curr);
321 }
322 
publish(void)323 void disk_stats_monitor::publish(void)
324 {
325     struct disk_perf perf = get_disk_perf(&mAccumulate_pub);
326     log_debug_disk_perf(&perf, "regular");
327     log_event_disk_stats(&mAccumulate, "regular");
328     // Reset global structures
329     memset(&mAccumulate_pub, 0, sizeof(struct disk_stats));
330 }
331