GraphicsStatsService.cpp revision 41c08f49b467e5e8aa291ec4a704a301bd27a6dc 
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#include "GraphicsStatsService.h"
18
19#include "JankTracker.h"
20
21#include <frameworks/base/core/proto/android/service/graphicsstats.pb.h>
22#include <google/protobuf/io/zero_copy_stream_impl_lite.h>
23#include <log/log.h>
24
25#include <errno.h>
26#include <fcntl.h>
27#include <inttypes.h>
28#include <sys/stat.h>
29#include <sys/types.h>
30#include <unistd.h>
31#include <sys/mman.h>
32
33namespace android {
34namespace uirenderer {
35
36using namespace google::protobuf;
37
38constexpr int32_t sCurrentFileVersion = 1;
39constexpr int32_t sHeaderSize = 4;
40static_assert(sizeof(sCurrentFileVersion) == sHeaderSize, "Header size is wrong");
41
42constexpr int sHistogramSize =
43        std::tuple_size<decltype(ProfileData::frameCounts)>::value +
44        std::tuple_size<decltype(ProfileData::slowFrameCounts)>::value;
45
46static void mergeProfileDataIntoProto(service::GraphicsStatsProto* proto,
47        const std::string& package, int versionCode, int64_t startTime, int64_t endTime,
48        const ProfileData* data);
49static void dumpAsTextToFd(service::GraphicsStatsProto* proto, int outFd);
50
51class FileDescriptor {
52public:
53    FileDescriptor(int fd) : mFd(fd) {}
54    ~FileDescriptor() {
55        if (mFd != -1) {
56            close(mFd);
57            mFd = -1;
58        }
59    }
60    bool valid() { return mFd != -1; }
61    operator int() { return mFd; }
62private:
63    int mFd;
64};
65
66class FileOutputStreamLite : public io::ZeroCopyOutputStream {
67public:
68    FileOutputStreamLite(int fd) : mCopyAdapter(fd), mImpl(&mCopyAdapter) {}
69    virtual ~FileOutputStreamLite() {}
70
71    int GetErrno() { return mCopyAdapter.mErrno; }
72
73    virtual bool Next(void** data, int* size) override {
74        return mImpl.Next(data, size);
75    }
76
77    virtual void BackUp(int count) override {
78        mImpl.BackUp(count);
79    }
80
81    virtual int64 ByteCount() const override {
82        return mImpl.ByteCount();
83    }
84
85    bool Flush() {
86        return mImpl.Flush();
87    }
88
89private:
90    struct FDAdapter : public io::CopyingOutputStream {
91        int mFd;
92        int mErrno = 0;
93
94        FDAdapter(int fd) : mFd(fd) {}
95        virtual ~FDAdapter() {}
96
97        virtual bool Write(const void* buffer, int size) override {
98            int ret;
99            while (size) {
100                ret = TEMP_FAILURE_RETRY( write(mFd, buffer, size) );
101                if (ret <= 0) {
102                    mErrno = errno;
103                    return false;
104                }
105                size -= ret;
106            }
107            return true;
108        }
109    };
110
111    FileOutputStreamLite::FDAdapter mCopyAdapter;
112    io::CopyingOutputStreamAdaptor mImpl;
113};
114
115bool GraphicsStatsService::parseFromFile(const std::string& path, service::GraphicsStatsProto* output) {
116
117    FileDescriptor fd{open(path.c_str(), O_RDONLY)};
118    if (!fd.valid()) {
119        int err = errno;
120        // The file not existing is normal for addToDump(), so only log if
121        // we get an unexpected error
122        if (err != ENOENT) {
123            ALOGW("Failed to open '%s', errno=%d (%s)", path.c_str(), err, strerror(err));
124        }
125        return false;
126    }
127    struct stat sb;
128    if (fstat(fd, &sb) || sb.st_size < sHeaderSize) {
129        int err = errno;
130        // The file not existing is normal for addToDump(), so only log if
131        // we get an unexpected error
132        if (err != ENOENT) {
133            ALOGW("Failed to fstat '%s', errno=%d (%s) (st_size %d)", path.c_str(), err,
134                    strerror(err), (int) sb.st_size);
135        }
136        return false;
137    }
138    void* addr = mmap(nullptr, sb.st_size, PROT_READ, MAP_SHARED, fd, 0);
139    if (!addr) {
140        int err = errno;
141        // The file not existing is normal for addToDump(), so only log if
142        // we get an unexpected error
143        if (err != ENOENT) {
144            ALOGW("Failed to mmap '%s', errno=%d (%s)", path.c_str(), err, strerror(err));
145        }
146        return false;
147    }
148    uint32_t file_version = *reinterpret_cast<uint32_t*>(addr);
149    if (file_version != sCurrentFileVersion) {
150        ALOGW("file_version mismatch! expected %d got %d", sCurrentFileVersion, file_version);
151        return false;
152    }
153
154    void* data = reinterpret_cast<uint8_t*>(addr) + sHeaderSize;
155    int dataSize = sb.st_size - sHeaderSize;
156    io::ArrayInputStream input{data, dataSize};
157    bool success = output->ParseFromZeroCopyStream(&input);
158    if (!success) {
159        ALOGW("Parse failed on '%s' error='%s'",
160                path.c_str(), output->InitializationErrorString().c_str());
161    }
162    return success;
163}
164
165void mergeProfileDataIntoProto(service::GraphicsStatsProto* proto, const std::string& package,
166        int versionCode, int64_t startTime, int64_t endTime, const ProfileData* data) {
167    if (proto->stats_start() == 0 || proto->stats_start() > startTime) {
168        proto->set_stats_start(startTime);
169    }
170    if (proto->stats_end() == 0 || proto->stats_end() < endTime) {
171        proto->set_stats_end(endTime);
172    }
173    proto->set_package_name(package);
174    proto->set_version_code(versionCode);
175    auto summary = proto->mutable_summary();
176    summary->set_total_frames(summary->total_frames() + data->totalFrameCount);
177    summary->set_janky_frames(summary->janky_frames() + data->jankFrameCount);
178    summary->set_missed_vsync_count(
179            summary->missed_vsync_count() + data->jankTypeCounts[kMissedVsync]);
180    summary->set_high_input_latency_count(
181            summary->high_input_latency_count() + data->jankTypeCounts[kHighInputLatency]);
182    summary->set_slow_ui_thread_count(
183            summary->slow_ui_thread_count() + data->jankTypeCounts[kSlowUI]);
184    summary->set_slow_bitmap_upload_count(
185            summary->slow_bitmap_upload_count() + data->jankTypeCounts[kSlowSync]);
186    summary->set_slow_draw_count(
187            summary->slow_draw_count() + data->jankTypeCounts[kSlowRT]);
188
189    bool creatingHistogram = false;
190    if (proto->histogram_size() == 0) {
191        proto->mutable_histogram()->Reserve(sHistogramSize);
192        creatingHistogram = true;
193    } else if (proto->histogram_size() != sHistogramSize) {
194        LOG_ALWAYS_FATAL("Histogram size mismatch, proto is %d expected %d",
195                proto->histogram_size(), sHistogramSize);
196    }
197    for (size_t i = 0; i < data->frameCounts.size(); i++) {
198        service::GraphicsStatsHistogramBucketProto* bucket;
199        int32_t renderTime = JankTracker::frameTimeForFrameCountIndex(i);
200        if (creatingHistogram) {
201            bucket = proto->add_histogram();
202            bucket->set_render_millis(renderTime);
203        } else {
204            bucket = proto->mutable_histogram(i);
205            LOG_ALWAYS_FATAL_IF(bucket->render_millis() != renderTime,
206                    "Frame time mistmatch %d vs. %d", bucket->render_millis(), renderTime);
207        }
208        bucket->set_frame_count(bucket->frame_count() + data->frameCounts[i]);
209    }
210    for (size_t i = 0; i < data->slowFrameCounts.size(); i++) {
211        service::GraphicsStatsHistogramBucketProto* bucket;
212        int32_t renderTime = JankTracker::frameTimeForSlowFrameCountIndex(i);
213        if (creatingHistogram) {
214            bucket = proto->add_histogram();
215            bucket->set_render_millis(renderTime);
216        } else {
217            constexpr int offset = std::tuple_size<decltype(ProfileData::frameCounts)>::value;
218            bucket = proto->mutable_histogram(offset + i);
219            LOG_ALWAYS_FATAL_IF(bucket->render_millis() != renderTime,
220                    "Frame time mistmatch %d vs. %d", bucket->render_millis(), renderTime);
221        }
222        bucket->set_frame_count(bucket->frame_count() + data->slowFrameCounts[i]);
223    }
224}
225
226static int32_t findPercentile(service::GraphicsStatsProto* proto, int percentile) {
227    int32_t pos = percentile * proto->summary().total_frames() / 100;
228    int32_t remaining = proto->summary().total_frames() - pos;
229    for (auto it = proto->histogram().rbegin(); it != proto->histogram().rend(); ++it) {
230        remaining -= it->frame_count();
231        if (remaining <= 0) {
232            return it->render_millis();
233        }
234    }
235    return 0;
236}
237
238void dumpAsTextToFd(service::GraphicsStatsProto* proto, int fd) {
239    // This isn't a full validation, just enough that we can deref at will
240    LOG_ALWAYS_FATAL_IF(proto->package_name().empty()
241            || !proto->has_summary(), "package_name() '%s' summary %d",
242            proto->package_name().c_str(), proto->has_summary());
243    dprintf(fd, "\nPackage: %s", proto->package_name().c_str());
244    dprintf(fd, "\nVersion: %d", proto->version_code());
245    dprintf(fd, "\nStats since: %lldns", proto->stats_start());
246    dprintf(fd, "\nStats end: %lldns", proto->stats_end());
247    auto summary = proto->summary();
248    dprintf(fd, "\nTotal frames rendered: %d", summary.total_frames());
249    dprintf(fd, "\nJanky frames: %d (%.2f%%)", summary.janky_frames(),
250            (float) summary.janky_frames() / (float) summary.total_frames() * 100.0f);
251    dprintf(fd, "\n50th percentile: %dms", findPercentile(proto, 50));
252    dprintf(fd, "\n90th percentile: %dms", findPercentile(proto, 90));
253    dprintf(fd, "\n95th percentile: %dms", findPercentile(proto, 95));
254    dprintf(fd, "\n99th percentile: %dms", findPercentile(proto, 99));
255    dprintf(fd, "\nNumber Missed Vsync: %d", summary.missed_vsync_count());
256    dprintf(fd, "\nNumber High input latency: %d", summary.high_input_latency_count());
257    dprintf(fd, "\nNumber Slow UI thread: %d", summary.slow_ui_thread_count());
258    dprintf(fd, "\nNumber Slow bitmap uploads: %d", summary.slow_bitmap_upload_count());
259    dprintf(fd, "\nNumber Slow issue draw commands: %d", summary.slow_draw_count());
260    dprintf(fd, "\nHISTOGRAM:");
261    for (const auto& it : proto->histogram()) {
262        dprintf(fd, " %dms=%d", it.render_millis(), it.frame_count());
263    }
264    dprintf(fd, "\n");
265}
266
267void GraphicsStatsService::saveBuffer(const std::string& path, const std::string& package,
268        int versionCode, int64_t startTime, int64_t endTime, const ProfileData* data) {
269    service::GraphicsStatsProto statsProto;
270    if (!parseFromFile(path, &statsProto)) {
271        statsProto.Clear();
272    }
273    mergeProfileDataIntoProto(&statsProto, package, versionCode, startTime, endTime, data);
274    // Although we might not have read any data from the file, merging the existing data
275    // should always fully-initialize the proto
276    LOG_ALWAYS_FATAL_IF(!statsProto.IsInitialized(), "%s",
277            statsProto.InitializationErrorString().c_str());
278    LOG_ALWAYS_FATAL_IF(statsProto.package_name().empty()
279            || !statsProto.has_summary(), "package_name() '%s' summary %d",
280            statsProto.package_name().c_str(), statsProto.has_summary());
281    int outFd = open(path.c_str(), O_CREAT | O_RDWR | O_TRUNC, 0660);
282    if (outFd <= 0) {
283        int err = errno;
284        ALOGW("Failed to open '%s', error=%d (%s)", path.c_str(), err, strerror(err));
285        return;
286    }
287    int wrote = write(outFd, &sCurrentFileVersion, sHeaderSize);
288    if (wrote != sHeaderSize) {
289        int err = errno;
290        ALOGW("Failed to write header to '%s', returned=%d errno=%d (%s)",
291                path.c_str(), wrote, err, strerror(err));
292        close(outFd);
293        return;
294    }
295    {
296        FileOutputStreamLite output(outFd);
297        bool success = statsProto.SerializeToZeroCopyStream(&output) && output.Flush();
298        if (output.GetErrno() != 0) {
299            ALOGW("Error writing to fd=%d, path='%s' err=%d (%s)",
300                    outFd, path.c_str(), output.GetErrno(), strerror(output.GetErrno()));
301            success = false;
302        } else if (!success) {
303            ALOGW("Serialize failed on '%s' unknown error", path.c_str());
304        }
305    }
306    close(outFd);
307}
308
309class GraphicsStatsService::Dump {
310public:
311    Dump(int outFd, DumpType type) : mFd(outFd), mType(type) {}
312    int fd() { return mFd; }
313    DumpType type() { return mType; }
314    service::GraphicsStatsServiceDumpProto& proto() { return mProto; }
315private:
316    int mFd;
317    DumpType mType;
318    service::GraphicsStatsServiceDumpProto mProto;
319};
320
321GraphicsStatsService::Dump* GraphicsStatsService::createDump(int outFd, DumpType type) {
322    return new Dump(outFd, type);
323}
324
325void GraphicsStatsService::addToDump(Dump* dump, const std::string& path, const std::string& package,
326        int versionCode, int64_t startTime, int64_t endTime, const ProfileData* data) {
327    service::GraphicsStatsProto statsProto;
328    if (!path.empty() && !parseFromFile(path, &statsProto)) {
329        statsProto.Clear();
330    }
331    if (data) {
332        mergeProfileDataIntoProto(&statsProto, package, versionCode, startTime, endTime, data);
333    }
334    if (!statsProto.IsInitialized()) {
335        ALOGW("Failed to load profile data from path '%s' and data %p",
336                path.empty() ? "<empty>" : path.c_str(), data);
337        return;
338    }
339
340    if (dump->type() == DumpType::Protobuf) {
341        dump->proto().add_stats()->CopyFrom(statsProto);
342    } else {
343        dumpAsTextToFd(&statsProto, dump->fd());
344    }
345}
346
347void GraphicsStatsService::addToDump(Dump* dump, const std::string& path) {
348    service::GraphicsStatsProto statsProto;
349    if (!parseFromFile(path, &statsProto)) {
350        return;
351    }
352    if (dump->type() == DumpType::Protobuf) {
353        dump->proto().add_stats()->CopyFrom(statsProto);
354    } else {
355        dumpAsTextToFd(&statsProto, dump->fd());
356    }
357}
358
359void GraphicsStatsService::finishDump(Dump* dump) {
360    if (dump->type() == DumpType::Protobuf) {
361        FileOutputStreamLite stream(dump->fd());
362        dump->proto().SerializeToZeroCopyStream(&stream);
363    }
364    delete dump;
365}
366
367} /* namespace uirenderer */
368} /* namespace android */
369