/* * Copyright (C) 2018 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. */ #define LOG_TAG "NBLog" //#define LOG_NDEBUG 0 #include #include #include #include #include #include #include #include #include #include #include namespace android { namespace NBLog { Writer::Writer(void *shared, size_t size) : mShared((Shared *) shared), mFifo(mShared != NULL ? new audio_utils_fifo(size, sizeof(uint8_t), mShared->mBuffer, mShared->mRear, NULL /*throttlesFront*/) : NULL), mFifoWriter(mFifo != NULL ? new audio_utils_fifo_writer(*mFifo) : NULL), mEnabled(mFifoWriter != NULL) { // caching pid and process name pid_t id = ::getpid(); char procName[16]; int status = prctl(PR_GET_NAME, procName); if (status) { // error getting process name procName[0] = '\0'; } size_t length = strlen(procName); mPidTagSize = length + sizeof(pid_t); mPidTag = new char[mPidTagSize]; memcpy(mPidTag, &id, sizeof(pid_t)); memcpy(mPidTag + sizeof(pid_t), procName, length); } Writer::Writer(const sp& iMemory, size_t size) // TODO: Using unsecurePointer() has some associated security pitfalls // (see declaration for details). // Either document why it is safe in this case or address the // issue (e.g. by copying). : Writer(iMemory != 0 ? (Shared *) iMemory->unsecurePointer() : NULL, size) { mIMemory = iMemory; } Writer::~Writer() { delete mFifoWriter; delete mFifo; delete[] mPidTag; } void Writer::log(const char *string) { if (!mEnabled) { return; } LOG_ALWAYS_FATAL_IF(string == NULL, "Attempted to log NULL string"); size_t length = strlen(string); if (length > Entry::kMaxLength) { length = Entry::kMaxLength; } log(EVENT_STRING, string, length); } void Writer::logf(const char *fmt, ...) { if (!mEnabled) { return; } va_list ap; va_start(ap, fmt); Writer::logvf(fmt, ap); // the Writer:: is needed to avoid virtual dispatch for LockedWriter va_end(ap); } void Writer::logTimestamp() { if (!mEnabled) { return; } struct timespec ts; if (!clock_gettime(CLOCK_MONOTONIC, &ts)) { log(EVENT_TIMESTAMP, &ts, sizeof(ts)); } } void Writer::logFormat(const char *fmt, log_hash_t hash, ...) { if (!mEnabled) { return; } va_list ap; va_start(ap, hash); Writer::logVFormat(fmt, hash, ap); va_end(ap); } void Writer::logEventHistTs(Event event, log_hash_t hash) { if (!mEnabled) { return; } HistTsEntry data; data.hash = hash; data.ts = systemTime(); if (data.ts > 0) { log(event, &data, sizeof(data)); } else { ALOGE("Failed to get timestamp"); } } bool Writer::isEnabled() const { return mEnabled; } bool Writer::setEnabled(bool enabled) { bool old = mEnabled; mEnabled = enabled && mShared != NULL; return old; } void Writer::log(const Entry &etr, bool trusted) { if (!mEnabled) { return; } if (!trusted) { log(etr.mEvent, etr.mData, etr.mLength); return; } const size_t need = etr.mLength + Entry::kOverhead; // mEvent, mLength, data[mLength], mLength // need = number of bytes written to FIFO // FIXME optimize this using memcpy for the data part of the Entry. // The Entry could have a method copyTo(ptr, offset, size) to optimize the copy. // checks size of a single log Entry: type, length, data pointer and ending uint8_t temp[Entry::kMaxLength + Entry::kOverhead]; // write this data to temp array for (size_t i = 0; i < need; i++) { temp[i] = etr.copyEntryDataAt(i); } // write to circular buffer mFifoWriter->write(temp, need); } void Writer::log(Event event, const void *data, size_t length) { if (!mEnabled) { return; } if (data == NULL || length > Entry::kMaxLength) { // TODO Perhaps it makes sense to display truncated data or at least a // message that the data is too long? The current behavior can create // a confusion for a programmer debugging their code. return; } // Ignore if invalid event if (event == EVENT_RESERVED || event >= EVENT_UPPER_BOUND) { return; } Entry etr(event, data, length); log(etr, true /*trusted*/); } void Writer::logvf(const char *fmt, va_list ap) { if (!mEnabled) { return; } char buffer[Entry::kMaxLength + 1 /*NUL*/]; int length = vsnprintf(buffer, sizeof(buffer), fmt, ap); if (length >= (int) sizeof(buffer)) { length = sizeof(buffer) - 1; // NUL termination is not required // buffer[length] = '\0'; } if (length >= 0) { log(EVENT_STRING, buffer, length); } } void Writer::logStart(const char *fmt) { if (!mEnabled) { return; } size_t length = strlen(fmt); if (length > Entry::kMaxLength) { length = Entry::kMaxLength; } log(EVENT_FMT_START, fmt, length); } void Writer::logTimestampFormat() { if (!mEnabled) { return; } const nsecs_t ts = systemTime(); if (ts > 0) { log(EVENT_FMT_TIMESTAMP, &ts, sizeof(ts)); } else { ALOGE("Failed to get timestamp"); } } void Writer::logVFormat(const char *fmt, log_hash_t hash, va_list argp) { if (!mEnabled) { return; } Writer::logStart(fmt); int i; double d; float f; char* s; size_t length; int64_t t; Writer::logTimestampFormat(); log(EVENT_FMT_HASH, &hash, sizeof(hash)); for (const char *p = fmt; *p != '\0'; p++) { // TODO: implement more complex formatting such as %.3f if (*p != '%') { continue; } switch(*++p) { case 's': // string s = va_arg(argp, char *); length = strlen(s); if (length > Entry::kMaxLength) { length = Entry::kMaxLength; } log(EVENT_FMT_STRING, s, length); break; case 't': // timestamp t = va_arg(argp, int64_t); log(EVENT_FMT_TIMESTAMP, &t, sizeof(t)); break; case 'd': // integer i = va_arg(argp, int); log(EVENT_FMT_INTEGER, &i, sizeof(i)); break; case 'f': // float d = va_arg(argp, double); // float arguments are promoted to double in vararg lists f = (float)d; log(EVENT_FMT_FLOAT, &f, sizeof(f)); break; case 'p': // pid log(EVENT_FMT_PID, mPidTag, mPidTagSize); break; // the "%\0" case finishes parsing case '\0': --p; break; case '%': break; default: ALOGW("NBLog Writer parsed invalid format specifier: %c", *p); break; } } Entry etr(EVENT_FMT_END, nullptr, 0); log(etr, true); } // --------------------------------------------------------------------------- LockedWriter::LockedWriter(void *shared, size_t size) : Writer(shared, size) { } bool LockedWriter::isEnabled() const { Mutex::Autolock _l(mLock); return Writer::isEnabled(); } bool LockedWriter::setEnabled(bool enabled) { Mutex::Autolock _l(mLock); return Writer::setEnabled(enabled); } void LockedWriter::log(const Entry &entry, bool trusted) { Mutex::Autolock _l(mLock); Writer::log(entry, trusted); } } // namespace NBLog } // namespace android