1 /*
2  * Copyright (C) 2016 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 <dirent.h>
20 #include <fcntl.h>
21 #include <linux/time.h>
22 #include <stdint.h>
23 #include <stdio.h>
24 #include <stdlib.h>
25 #include <string.h>
26 #include <sys/stat.h>
27 #include <time.h>
28 #include <unistd.h>
29 
30 #include <iomanip>
31 #include <sstream>
32 #include <string>
33 #include <unordered_map>
34 
35 #include <android-base/file.h>
36 #include <android-base/logging.h>
37 #include <android-base/stringprintf.h>
38 #include <android-base/strings.h>
39 #include <log/log_event_list.h>
40 
41 #include <storaged.h>
42 #include <storaged_utils.h>
43 
parse_disk_stats(const char * disk_stats_path,struct disk_stats * stats)44 bool parse_disk_stats(const char* disk_stats_path, struct disk_stats* stats) {
45     // Get time
46     struct timespec ts;
47     // Use monotonic to exclude suspend time so that we measure IO bytes/sec
48     // when system is running.
49     int ret = clock_gettime(CLOCK_MONOTONIC, &ts);
50     if (ret < 0) {
51         PLOG_TO(SYSTEM, ERROR) << "clock_gettime() failed";
52         return false;
53     }
54 
55     std::string buffer;
56     if (!android::base::ReadFileToString(disk_stats_path, &buffer)) {
57         PLOG_TO(SYSTEM, ERROR) << disk_stats_path << ": ReadFileToString failed.";
58         return false;
59     }
60 
61     // Regular diskstats entries
62     std::stringstream ss(buffer);
63     for (uint i = 0; i < DISK_STATS_SIZE; ++i) {
64         ss >> *((uint64_t*)stats + i);
65     }
66     // Other entries
67     stats->start_time = 0;
68     stats->end_time = (uint64_t)ts.tv_sec * SEC_TO_MSEC +
69         ts.tv_nsec / (MSEC_TO_USEC * USEC_TO_NSEC);
70     stats->counter = 1;
71     stats->io_avg = (double)stats->io_in_flight;
72     return true;
73 }
74 
get_disk_perf(struct disk_stats * stats)75 struct disk_perf get_disk_perf(struct disk_stats* stats) {
76     struct disk_perf perf;
77     memset(&perf, 0, sizeof(struct disk_perf));  // initialize
78 
79     if (stats->io_ticks) {
80         if (stats->read_ticks) {
81             unsigned long long divisor = stats->read_ticks * stats->io_ticks;
82             perf.read_perf = ((unsigned long long)SECTOR_SIZE *
83                                         stats->read_sectors *
84                                         stats->io_in_queue +
85                                         (divisor >> 1)) /
86                                             divisor;
87             perf.read_ios = ((unsigned long long)SEC_TO_MSEC *
88                                         stats->read_ios *
89                                         stats->io_in_queue +
90                                         (divisor >> 1)) /
91                                             divisor;
92         }
93         if (stats->write_ticks) {
94             unsigned long long divisor = stats->write_ticks * stats->io_ticks;
95                         perf.write_perf = ((unsigned long long)SECTOR_SIZE *
96                                                     stats->write_sectors *
97                                                     stats->io_in_queue +
98                                                     (divisor >> 1)) /
99                                                         divisor;
100                         perf.write_ios = ((unsigned long long)SEC_TO_MSEC *
101                                                     stats->write_ios *
102                                                     stats->io_in_queue +
103                                                     (divisor >> 1)) /
104                                                         divisor;
105         }
106         perf.queue = (stats->io_in_queue + (stats->io_ticks >> 1)) /
107                                 stats->io_ticks;
108     }
109     return perf;
110 }
111 
get_inc_disk_stats(struct disk_stats * prev,struct disk_stats * curr)112 struct disk_stats get_inc_disk_stats(struct disk_stats* prev, struct disk_stats* curr) {
113     struct disk_stats inc;
114     for (uint i = 0; i < DISK_STATS_SIZE; ++i) {
115         if (i == DISK_STATS_IO_IN_FLIGHT_IDX) {
116             continue;
117         }
118 
119         *((uint64_t*)&inc + i) =
120                 *((uint64_t*)curr + i) - *((uint64_t*)prev + i);
121     }
122     // io_in_flight is exception
123     inc.io_in_flight = curr->io_in_flight;
124 
125     inc.start_time = prev->end_time;
126     inc.end_time = curr->end_time;
127     inc.io_avg = curr->io_avg;
128     inc.counter = 1;
129 
130     return inc;
131 }
132 
133 // Add src to dst
add_disk_stats(struct disk_stats * src,struct disk_stats * dst)134 void add_disk_stats(struct disk_stats* src, struct disk_stats* dst) {
135     if (dst->end_time != 0 && dst->end_time != src->start_time) {
136         LOG_TO(SYSTEM, WARNING) << "Two dis-continuous periods of diskstats"
137             << " are added. dst end with " << dst->end_time
138             << ", src start with " << src->start_time;
139     }
140 
141     for (uint i = 0; i < DISK_STATS_SIZE; ++i) {
142         if (i == DISK_STATS_IO_IN_FLIGHT_IDX) {
143             continue;
144         }
145 
146         *((uint64_t*)dst + i) += *((uint64_t*)src + i);
147     }
148 
149     dst->io_in_flight = src->io_in_flight;
150     if (dst->counter + src->counter) {
151         dst->io_avg = ((dst->io_avg * dst->counter) + (src->io_avg * src->counter)) /
152                         (dst->counter + src->counter);
153     }
154     dst->counter += src->counter;
155     dst->end_time = src->end_time;
156     if (dst->start_time == 0) {
157         dst->start_time = src->start_time;
158     }
159 }
160 
cmp_uid_info(struct uid_info l,struct uid_info r)161 static bool cmp_uid_info(struct uid_info l, struct uid_info r) {
162     // Compare background I/O first.
163     for (int i = UID_STATS - 1; i >= 0; i--) {
164         uint64_t l_bytes = l.io[i].read_bytes + l.io[i].write_bytes;
165         uint64_t r_bytes = r.io[i].read_bytes + r.io[i].write_bytes;
166         uint64_t l_chars = l.io[i].rchar + l.io[i].wchar;
167         uint64_t r_chars = r.io[i].rchar + r.io[i].wchar;
168 
169         if (l_bytes != r_bytes) {
170             return l_bytes > r_bytes;
171         }
172         if (l_chars != r_chars) {
173             return l_chars > r_chars;
174         }
175     }
176 
177     return l.name < r.name;
178 }
179 
sort_running_uids_info(std::vector<struct uid_info> & uids)180 void sort_running_uids_info(std::vector<struct uid_info> &uids) {
181     std::sort(uids.begin(), uids.end(), cmp_uid_info);
182 }
183 
184 // Logging functions
log_console_running_uids_info(std::vector<struct uid_info> uids)185 void log_console_running_uids_info(std::vector<struct uid_info> uids) {
186     printf("name/uid fg_rchar fg_wchar fg_rbytes fg_wbytes "
187            "bg_rchar bg_wchar bg_rbytes bg_wbytes fg_fsync bg_fsync\n");
188 
189     for (const auto& uid : uids) {
190         printf("%s %ju %ju %ju %ju %ju %ju %ju %ju %ju %ju\n", uid.name.c_str(),
191             uid.io[0].rchar, uid.io[0].wchar, uid.io[0].read_bytes, uid.io[0].write_bytes,
192             uid.io[1].rchar, uid.io[1].wchar, uid.io[1].read_bytes, uid.io[1].write_bytes,
193             uid.io[0].fsync, uid.io[1].fsync);
194     }
195     fflush(stdout);
196 }
197 
198 #if DEBUG
log_debug_disk_perf(struct disk_perf * perf,const char * type)199 void log_debug_disk_perf(struct disk_perf* perf, const char* type) {
200     // skip if the input structure are all zeros
201     if (perf == NULL) return;
202     struct disk_perf zero_cmp;
203     memset(&zero_cmp, 0, sizeof(zero_cmp));
204     if (memcmp(&zero_cmp, perf, sizeof(struct disk_perf)) == 0) return;
205 
206     LOG_TO(SYSTEM, INFO) << "perf(ios) " << type
207               << " rd:" << perf->read_perf << "KB/s(" << perf->read_ios << "/s)"
208               << " wr:" << perf->write_perf << "KB/s(" << perf->write_ios << "/s)"
209               << " q:" << perf->queue;
210 }
211 #else
log_debug_disk_perf(struct disk_perf *,const char *)212 void log_debug_disk_perf(struct disk_perf* /* perf */, const char* /* type */) {}
213 #endif
214 
log_event_disk_stats(struct disk_stats * stats,const char * type)215 void log_event_disk_stats(struct disk_stats* stats, const char* type) {
216     // skip if the input structure are all zeros
217     if (stats == NULL) return;
218     struct disk_stats zero_cmp;
219     memset(&zero_cmp, 0, sizeof(zero_cmp));
220     // skip event logging diskstats when it is zero increment (all first 11 entries are zero)
221     if (memcmp(&zero_cmp, stats, sizeof(uint64_t) * DISK_STATS_SIZE) == 0) return;
222 
223     android_log_event_list(EVENTLOGTAG_DISKSTATS)
224         << type << stats->start_time << stats->end_time
225         << stats->read_ios << stats->read_merges
226         << stats->read_sectors << stats->read_ticks
227         << stats->write_ios << stats->write_merges
228         << stats->write_sectors << stats->write_ticks
229         << (uint64_t)stats->io_avg << stats->io_ticks << stats->io_in_queue
230         << LOG_ID_EVENTS;
231 }
232 
233