// Copyright 2020 The Android Open Source Project // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at // // http://www.apache.org/licenses/LICENSE-2.0 // // Unless required by applicable law or agreed to in writing, software // distributed under the License is distributed on an "AS IS" BASIS, // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. // See the License for the specific language governing permissions and // limitations under the License. #include "logger.h" #include "base/PathUtils.h" #include "base/Lock.h" #include #include #include #include #include #include #include "base/msvc.h" #ifndef _MSC_VER #include #endif #include using android::base::AutoLock; using android::base::Lock; using android::base::PathUtils; // The purpose of the OpenGL logger is to log // information about such things as EGL initialization // and possibly miscellanous OpenGL commands, // in order to get a better idea of what is going on // in crash reports. // The OpenGLLogger implementation's initialization method // by default uses the crash reporter's data directory. static const int kBufferLen = 2048; typedef std::pair TimestampedLogEntry; class OpenGLLogger { public: OpenGLLogger(); OpenGLLogger(const char* filename); void stop(); // Coarse log: Call this infrequently. void writeCoarse(const char* str); // Fine log: When we want to log very frequent events. // Fine logs can be toggled on/off. void writeFineTimestamped(const char* str); void setLoggerFlags(AndroidOpenglLoggerFlags flags); bool isFineLogging() const; static OpenGLLogger* get(); private: void writeFineLocked(uint64_t time, const char* str); void stopFineLogLocked(); Lock mLock; AndroidOpenglLoggerFlags mLoggerFlags = OPENGL_LOGGER_NONE; uint64_t mPrevTimeUs = 0; std::string mFileName; std::ofstream mFileHandle; std::string mFineLogFileName; std::ofstream mFineLogFileHandle; std::vector mFineLog; DISALLOW_COPY_ASSIGN_AND_MOVE(OpenGLLogger); }; static OpenGLLogger* sOpenGLLogger() { static OpenGLLogger* g = new OpenGLLogger; return g; } OpenGLLogger* OpenGLLogger::get() { return sOpenGLLogger(); } OpenGLLogger::OpenGLLogger() { // #ifdef AEMU_MIN return; // #else // const std::string& data_dir = // CrashReporter::get()->getDataExchangeDir(); // mFileName = PathUtils::join(data_dir, // "opengl_log.txt"); // mFileHandle.open(mFileName, std::ios::app); // mFineLogFileName = PathUtils::join(data_dir, // "opengl_cxt_log.txt"); // mFineLogFileHandle.open(mFineLogFileName, std::ios::app); // #endif } OpenGLLogger::OpenGLLogger(const char* filename) : mFileName(filename) { mFileHandle.open(mFileName, std::ios::app); } void OpenGLLogger::writeCoarse(const char* str) { AutoLock lock(mLock); if (mLoggerFlags & OPENGL_LOGGER_PRINT_TO_STDOUT) { printf("%s\n", str); } if (mFileHandle) { mFileHandle << str << std::endl; } } void OpenGLLogger::stop() { AutoLock lock(mLock); stopFineLogLocked(); mFileHandle.close(); } void OpenGLLogger::writeFineLocked(uint64_t time, const char* str) { if (mLoggerFlags & OPENGL_LOGGER_PRINT_TO_STDOUT) { printf("%s", str); } else { mFineLog.emplace_back(time, str); } } void OpenGLLogger::writeFineTimestamped(const char* str) { if (mLoggerFlags & OPENGL_LOGGER_DO_FINE_LOGGING) { char buf[kBufferLen] = {}; struct timeval tv; gettimeofday(&tv, NULL); uint64_t curr_micros = (tv.tv_usec) % 1000; uint64_t curr_millis = (tv.tv_usec / 1000) % 1000; uint64_t curr_secs = tv.tv_sec; uint64_t curr_us = tv.tv_sec * 1000000ULL + tv.tv_usec; snprintf(buf, sizeof(buf) - 1, "time_us=" "%" PRIu64 " s " "%" PRIu64 " ms " "%" PRIu64 " us deltaUs " "%" PRIu64 " | %s", curr_secs, curr_millis, curr_micros, curr_us - mPrevTimeUs, str); AutoLock lock(mLock); writeFineLocked(curr_micros + 1000ULL * curr_millis + 1000ULL * 1000ULL * curr_secs, buf); mPrevTimeUs = curr_us; } } void OpenGLLogger::setLoggerFlags(AndroidOpenglLoggerFlags flags) { AutoLock lock(mLock); bool needStopFineLog = (mLoggerFlags & OPENGL_LOGGER_DO_FINE_LOGGING) && (!(flags & OPENGL_LOGGER_DO_FINE_LOGGING)); if (needStopFineLog) { stopFineLogLocked(); } mLoggerFlags = flags; } bool OpenGLLogger::isFineLogging() const { // For speed, we'll just let this read of mLoggerFlags race. return (mLoggerFlags & OPENGL_LOGGER_DO_FINE_LOGGING); } void OpenGLLogger::stopFineLogLocked() { // Only print message when fine-grained // logging is turned on. if (!mFineLog.empty()) { fprintf(stderr, "Writing fine-grained GL log to %s...", mFineLogFileName.c_str()); } // Sort log entries according to their timestamps. // This is because the log entries might arrive // out of order. std::sort(mFineLog.begin(), mFineLog.end(), [](const TimestampedLogEntry& x, const TimestampedLogEntry& y) { return x.first < y.first; }); if (mFineLogFileHandle) { for (const auto& entry : mFineLog) { // The fine log does not print newlines // as it is used with the opengl debug // printout in emugl, which adds // newlines of its own. mFineLogFileHandle << entry.second; } mFineLogFileHandle.close(); if (!mFineLog.empty()) { fprintf(stderr, "done\n"); } } mFineLog.clear(); } // C interface void android_init_opengl_logger() { OpenGLLogger::get(); } void android_opengl_logger_set_flags(AndroidOpenglLoggerFlags flags) { OpenGLLogger::get()->setLoggerFlags(flags); } void android_opengl_logger_write(const char* fmt, ...) { char buf[kBufferLen] = {}; va_list ap; va_start(ap, fmt); vsnprintf(buf, sizeof(buf) - 1, fmt, ap); va_end(ap); OpenGLLogger::get()->writeCoarse(buf); } void android_opengl_cxt_logger_write(const char* fmt, ...) { auto gl_log = OpenGLLogger::get(); if (!gl_log->isFineLogging()) return; char buf[kBufferLen] = {}; va_list ap; va_start(ap, fmt); vsnprintf(buf, sizeof(buf) - 1, fmt, ap); va_end(ap); gl_log->writeFineTimestamped(buf); } void android_stop_opengl_logger() { OpenGLLogger* gl_log = OpenGLLogger::get(); gl_log->stop(); }