815 lines
30 KiB
C++
815 lines
30 KiB
C++
|
/*
|
||
|
|
* Copyright (C) 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 "SerializedLogBuffer.h"
|
||
|
|
|
||
|
|
#include <sys/prctl.h>
|
||
|
|
#ifdef MTK_LOGD_ENHANCE
|
||
|
|
#include <sys/prctl.h>
|
||
|
|
#include <sys/klog.h>
|
||
|
|
#include <utils/threads.h>
|
||
|
|
#include <cutils/properties.h>
|
||
|
|
#include <android-base/properties.h>
|
||
|
|
#include <android-base/logging.h>
|
||
|
|
#include <android-base/stringprintf.h>
|
||
|
|
#ifdef MSSI_HAVE_AEE_FEATURE
|
||
|
|
#include "aee.h"
|
||
|
|
#endif
|
||
|
|
#endif
|
||
|
|
|
||
|
|
#include <limits>
|
||
|
|
|
||
|
|
#include <android-base/logging.h>
|
||
|
|
#include <android-base/scopeguard.h>
|
||
|
|
|
||
|
|
#include "LogSize.h"
|
||
|
|
#include "LogStatistics.h"
|
||
|
|
#include "SerializedFlushToState.h"
|
||
|
|
|
||
|
|
#ifdef MTK_LOGD_ENHANCE
|
||
|
|
#if defined(MSSI_HAVE_AEE_FEATURE) && defined(ANDROID_LOG_MUCH_COUNT)
|
||
|
|
#include <cutils/sockets.h>
|
||
|
|
|
||
|
|
char aee_string[70];
|
||
|
|
char *log_much_buf;
|
||
|
|
int log_much_used_size;
|
||
|
|
int log_much_alloc_size;
|
||
|
|
bool log_much_detected = false;
|
||
|
|
#define EACH_LOG_SIZE 300 /* each log size * detect count = alloc size*/
|
||
|
|
|
||
|
|
//#define LOGMUCH_TEST_DEBUG 0
|
||
|
|
|
||
|
|
#if LOGMUCH_TEST_DEBUG
|
||
|
|
static void aee_write_file() {
|
||
|
|
static int count = 0;
|
||
|
|
char file_name[50];
|
||
|
|
if (count > 99) {
|
||
|
|
count = 0;
|
||
|
|
}
|
||
|
|
snprintf(file_name, sizeof(file_name), "/data/tombstones/logmuch_%d", count++);
|
||
|
|
int logmuch_fd = TEMP_FAILURE_RETRY(open(file_name, O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR | S_IRGRP));
|
||
|
|
if (logmuch_fd < 0) {
|
||
|
|
LOG(INFO) << android::base::StringPrintf("logmuch aee_write_file error:%d", logmuch_fd);
|
||
|
|
return;
|
||
|
|
}
|
||
|
|
|
||
|
|
write(logmuch_fd, aee_string, 70);
|
||
|
|
write(logmuch_fd, log_much_buf, log_much_used_size);
|
||
|
|
close(logmuch_fd);
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
|
||
|
|
static void *logmuchaee_thread_start(void * /*obj*/) {
|
||
|
|
prctl(PR_SET_NAME, "logd.logmuch");
|
||
|
|
#if LOGMUCH_TEST_DEBUG
|
||
|
|
aee_write_file();
|
||
|
|
#endif
|
||
|
|
LOG(DEBUG) << "logmuchaee_thread_start success";
|
||
|
|
aee_system_warning(aee_string, NULL, DB_OPT_DUMMY_DUMP|DB_OPT_PRINTK_TOO_MUCH, log_much_buf);
|
||
|
|
if (log_much_buf != NULL) {
|
||
|
|
free(log_much_buf);
|
||
|
|
log_much_buf = NULL;
|
||
|
|
}
|
||
|
|
log_much_used_size = 0;
|
||
|
|
log_much_detected = false;
|
||
|
|
return NULL;
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
|
||
|
|
#if defined(MSSI_HAVE_AEE_FEATURE) && defined(LOGD_MEM_CONTROL)
|
||
|
|
static void *logd_memory_leak_thread_start(void * /*obj*/) {
|
||
|
|
prctl(PR_SET_NAME, "logd.memoryleak");
|
||
|
|
aee_system_warning("Logd memory leak", NULL, DB_OPT_DEFAULT, "Logd memory leak");
|
||
|
|
return NULL;
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
|
||
|
|
#if defined(MSSI_HAVE_AEE_FEATURE) && defined(MTK_LOGD_DEBUG_PERFORMANCE)
|
||
|
|
static void *logd_performance_issue_thread_start(void * /*obj*/) {
|
||
|
|
prctl(PR_SET_NAME, "logd.performance");
|
||
|
|
aee_system_warning("Logd cpu usage high", NULL, DB_OPT_DEFAULT, "Logd cpu usage high");
|
||
|
|
return NULL;
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
#endif
|
||
|
|
|
||
|
|
static SerializedLogEntry* LogToLogBuffer(std::list<SerializedLogChunk>& log_buffer,
|
||
|
|
size_t max_size, uint64_t sequence, log_time realtime,
|
||
|
|
uid_t uid, pid_t pid, pid_t tid, const char* msg,
|
||
|
|
uint16_t len) {
|
||
|
|
if (log_buffer.empty()) {
|
||
|
|
log_buffer.push_back(SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
|
||
|
|
}
|
||
|
|
|
||
|
|
auto total_len = sizeof(SerializedLogEntry) + len;
|
||
|
|
if (!log_buffer.back().CanLog(total_len)) {
|
||
|
|
log_buffer.back().FinishWriting();
|
||
|
|
log_buffer.push_back(SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
|
||
|
|
}
|
||
|
|
|
||
|
|
return log_buffer.back().Log(sequence, realtime, uid, pid, tid, msg, len);
|
||
|
|
}
|
||
|
|
|
||
|
|
// Clear all logs from a particular UID by iterating through all existing logs for a log_id, and
|
||
|
|
// write all logs that don't match the UID into a new log buffer, then swapping the log buffers.
|
||
|
|
// There is an optimization that chunks are copied as-is until a log message from the UID is found,
|
||
|
|
// to ensure that back-to-back clears of the same UID do not require reflowing the entire buffer.
|
||
|
|
void ClearLogsByUid(std::list<SerializedLogChunk>& log_buffer, uid_t uid, size_t max_size,
|
||
|
|
log_id_t log_id, LogStatistics* stats) REQUIRES(logd_lock) {
|
||
|
|
bool contains_uid_logs = false;
|
||
|
|
std::list<SerializedLogChunk> new_logs;
|
||
|
|
auto it = log_buffer.begin();
|
||
|
|
while (it != log_buffer.end()) {
|
||
|
|
auto chunk = it++;
|
||
|
|
chunk->NotifyReadersOfPrune(log_id);
|
||
|
|
chunk->IncReaderRefCount();
|
||
|
|
|
||
|
|
if (!contains_uid_logs) {
|
||
|
|
for (const auto& entry : *chunk) {
|
||
|
|
if (entry.uid() == uid) {
|
||
|
|
contains_uid_logs = true;
|
||
|
|
break;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
if (!contains_uid_logs) {
|
||
|
|
chunk->DecReaderRefCount();
|
||
|
|
new_logs.splice(new_logs.end(), log_buffer, chunk);
|
||
|
|
continue;
|
||
|
|
}
|
||
|
|
// We found a UID log, so push a writable chunk to prepare for the next loop.
|
||
|
|
new_logs.push_back(
|
||
|
|
SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
|
||
|
|
}
|
||
|
|
|
||
|
|
for (const auto& entry : *chunk) {
|
||
|
|
if (entry.uid() == uid) {
|
||
|
|
if (stats != nullptr) {
|
||
|
|
stats->Subtract(entry.ToLogStatisticsElement(log_id));
|
||
|
|
}
|
||
|
|
} else {
|
||
|
|
LogToLogBuffer(new_logs, max_size, entry.sequence(), entry.realtime(), entry.uid(),
|
||
|
|
entry.pid(), entry.tid(), entry.msg(), entry.msg_len());
|
||
|
|
}
|
||
|
|
}
|
||
|
|
chunk->DecReaderRefCount();
|
||
|
|
log_buffer.erase(chunk);
|
||
|
|
}
|
||
|
|
std::swap(new_logs, log_buffer);
|
||
|
|
}
|
||
|
|
|
||
|
|
SerializedLogBuffer::SerializedLogBuffer(LogReaderList* reader_list, LogTags* tags,
|
||
|
|
LogStatistics* stats)
|
||
|
|
: reader_list_(reader_list), tags_(tags), stats_(stats) {
|
||
|
|
Init();
|
||
|
|
}
|
||
|
|
|
||
|
|
void SerializedLogBuffer::Init() {
|
||
|
|
#if defined(MTK_LOGD_ENHANCE) && defined(ANDROID_LOG_MUCH_COUNT) && defined(MSSI_HAVE_AEE_FEATURE)
|
||
|
|
int rc;
|
||
|
|
unsigned long default_size;
|
||
|
|
unsigned long klog_size = 0;
|
||
|
|
|
||
|
|
log_id_for_each(i) {
|
||
|
|
default_size = GetBufferSizeFromProperties(i);
|
||
|
|
if (i == LOG_ID_MAIN || i == LOG_ID_RADIO) {
|
||
|
|
default_size = 5 * default_size;
|
||
|
|
} else if (i == LOG_ID_KERNEL) {
|
||
|
|
rc = klogctl(KLOG_SIZE_BUFFER, nullptr, 0);
|
||
|
|
if (rc > 0)
|
||
|
|
klog_size = rc + 64 * 1024UL; // kernel log buffer len + 64KB
|
||
|
|
if (klog_size > default_size)
|
||
|
|
default_size = klog_size;
|
||
|
|
}
|
||
|
|
|
||
|
|
if (!SetSize(i, default_size)) {
|
||
|
|
SetSize(i, kLogBufferMinSize);
|
||
|
|
}
|
||
|
|
}
|
||
|
|
#else
|
||
|
|
log_id_for_each(i) {
|
||
|
|
if (!SetSize(i, GetBufferSizeFromProperties(i))) {
|
||
|
|
SetSize(i, kLogBufferMinSize);
|
||
|
|
}
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
|
||
|
|
// Release any sleeping reader threads to dump their current content.
|
||
|
|
auto lock = std::lock_guard{logd_lock};
|
||
|
|
for (const auto& reader_thread : reader_list_->reader_threads()) {
|
||
|
|
reader_thread->TriggerReader();
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
bool SerializedLogBuffer::ShouldLog(log_id_t log_id, const char* msg, uint16_t len) {
|
||
|
|
if (log_id == LOG_ID_SECURITY) {
|
||
|
|
return true;
|
||
|
|
}
|
||
|
|
|
||
|
|
int prio = ANDROID_LOG_INFO;
|
||
|
|
const char* tag = nullptr;
|
||
|
|
size_t tag_len = 0;
|
||
|
|
if (IsBinary(log_id)) {
|
||
|
|
int32_t tag_int = MsgToTag(msg, len);
|
||
|
|
tag = tags_->tagToName(tag_int);
|
||
|
|
if (tag) {
|
||
|
|
tag_len = strlen(tag);
|
||
|
|
}
|
||
|
|
} else {
|
||
|
|
prio = *msg;
|
||
|
|
tag = msg + 1;
|
||
|
|
tag_len = strnlen(tag, len - 1);
|
||
|
|
}
|
||
|
|
return __android_log_is_loggable_len(prio, tag, tag_len, ANDROID_LOG_VERBOSE);
|
||
|
|
}
|
||
|
|
|
||
|
|
int SerializedLogBuffer::Log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid,
|
||
|
|
const char* msg, uint16_t len) {
|
||
|
|
if (log_id >= LOG_ID_MAX || len == 0) {
|
||
|
|
return -EINVAL;
|
||
|
|
}
|
||
|
|
|
||
|
|
#if defined(MTK_LOGD_ENHANCE) && defined(ANDROID_LOG_MUCH_COUNT)
|
||
|
|
if (len > LOGGER_ENTRY_MAX_PAYLOAD + 18) {
|
||
|
|
len = LOGGER_ENTRY_MAX_PAYLOAD + 18;
|
||
|
|
}
|
||
|
|
#else
|
||
|
|
if (len > LOGGER_ENTRY_MAX_PAYLOAD) {
|
||
|
|
len = LOGGER_ENTRY_MAX_PAYLOAD;
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
|
||
|
|
if (!ShouldLog(log_id, msg, len)) {
|
||
|
|
stats_->AddTotal(log_id, len);
|
||
|
|
return -EACCES;
|
||
|
|
}
|
||
|
|
|
||
|
|
auto sequence = sequence_.fetch_add(1, std::memory_order_relaxed);
|
||
|
|
|
||
|
|
auto lock = std::lock_guard{logd_lock};
|
||
|
|
#if defined(MTK_LOGD_ENHANCE) && defined(MSSI_HAVE_AEE_FEATURE) && defined(ANDROID_LOG_MUCH_COUNT)
|
||
|
|
logMuchDetect(log_id, realtime);
|
||
|
|
#endif
|
||
|
|
|
||
|
|
auto entry = LogToLogBuffer(logs_[log_id], max_size_[log_id], sequence, realtime, uid, pid, tid,
|
||
|
|
msg, len);
|
||
|
|
stats_->Add(entry->ToLogStatisticsElement(log_id));
|
||
|
|
|
||
|
|
MaybePrune(log_id);
|
||
|
|
|
||
|
|
reader_list_->NotifyNewLog(1 << log_id);
|
||
|
|
return len;
|
||
|
|
}
|
||
|
|
|
||
|
|
void SerializedLogBuffer::MaybePrune(log_id_t log_id) {
|
||
|
|
size_t total_size = GetSizeUsed(log_id);
|
||
|
|
size_t after_size = total_size;
|
||
|
|
if (total_size > max_size_[log_id]) {
|
||
|
|
Prune(log_id, total_size - max_size_[log_id]);
|
||
|
|
after_size = GetSizeUsed(log_id);
|
||
|
|
LOG(VERBOSE) << "Pruned Logs from log_id: " << log_id << ", previous size: " << total_size
|
||
|
|
<< " after size: " << after_size;
|
||
|
|
}
|
||
|
|
|
||
|
|
stats_->set_overhead(log_id, after_size);
|
||
|
|
}
|
||
|
|
|
||
|
|
void SerializedLogBuffer::RemoveChunkFromStats(log_id_t log_id, SerializedLogChunk& chunk) {
|
||
|
|
chunk.IncReaderRefCount();
|
||
|
|
for (const auto& entry : chunk) {
|
||
|
|
stats_->Subtract(entry.ToLogStatisticsElement(log_id));
|
||
|
|
}
|
||
|
|
chunk.DecReaderRefCount();
|
||
|
|
}
|
||
|
|
|
||
|
|
void SerializedLogBuffer::Prune(log_id_t log_id, size_t bytes_to_free) {
|
||
|
|
auto& log_buffer = logs_[log_id];
|
||
|
|
auto it = log_buffer.begin();
|
||
|
|
|
||
|
|
#ifdef MTK_LOGD_ENHANCE
|
||
|
|
size_t total_size = GetSizeUsed(log_id);
|
||
|
|
|
||
|
|
if (total_size > (100 * max_size_[log_id])) {
|
||
|
|
#if defined(MSSI_HAVE_AEE_FEATURE) && defined(LOGD_MEM_CONTROL)
|
||
|
|
pthread_attr_t attr_m;
|
||
|
|
static bool memory_issue;
|
||
|
|
|
||
|
|
if (memory_issue == true) {
|
||
|
|
return true;
|
||
|
|
}
|
||
|
|
|
||
|
|
if (!pthread_attr_init(&attr_m)) {
|
||
|
|
struct sched_param param_m;
|
||
|
|
|
||
|
|
memory_issue = true;
|
||
|
|
memset(¶m_m, 0, sizeof(param_m));
|
||
|
|
pthread_attr_setschedparam(&attr_m, ¶m_m);
|
||
|
|
pthread_attr_setschedpolicy(&attr_m, SCHED_BATCH);
|
||
|
|
if (!pthread_attr_setdetachstate(&attr_m, PTHREAD_CREATE_DETACHED)) {
|
||
|
|
pthread_t thread;
|
||
|
|
pthread_create(&thread, &attr_m, logd_memory_leak_thread_start, NULL);
|
||
|
|
}
|
||
|
|
pthread_attr_destroy(&attr_m);
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
}
|
||
|
|
#endif
|
||
|
|
|
||
|
|
while (it != log_buffer.end()) {
|
||
|
|
for (const auto& reader_thread : reader_list_->reader_threads()) {
|
||
|
|
if (!reader_thread->IsWatching(log_id)) {
|
||
|
|
continue;
|
||
|
|
}
|
||
|
|
|
||
|
|
if (reader_thread->deadline().time_since_epoch().count() != 0) {
|
||
|
|
// Always wake up wrapped readers when pruning. 'Wrapped' readers are an
|
||
|
|
// optimization that allows the reader to wait until logs starting at a specified
|
||
|
|
// time stamp are about to be pruned. This is error-prone however, since if that
|
||
|
|
// timestamp is about to be pruned, the reader is not likely to read the messages
|
||
|
|
// fast enough to not back-up logd. Instead, we can achieve an nearly-as-efficient
|
||
|
|
// but not error-prune batching effect by waking the reader whenever any chunk is
|
||
|
|
// about to be pruned.
|
||
|
|
reader_thread->TriggerReader();
|
||
|
|
}
|
||
|
|
|
||
|
|
// Some readers may be still reading from this log chunk, log a warning that they are
|
||
|
|
// about to lose logs.
|
||
|
|
// TODO: We should forcefully disconnect the reader instead, such that the reader itself
|
||
|
|
// has an indication that they've lost logs.
|
||
|
|
if (reader_thread->start() <= it->highest_sequence_number()) {
|
||
|
|
LOG(WARNING) << "Skipping entries from slow reader, " << reader_thread->name()
|
||
|
|
<< ", from LogBuffer::Prune()";
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
// Increment ahead of time since we're going to erase this iterator from the list.
|
||
|
|
auto it_to_prune = it++;
|
||
|
|
|
||
|
|
// Readers may have a reference to the chunk to track their last read log_position.
|
||
|
|
// Notify them to delete the reference.
|
||
|
|
it_to_prune->NotifyReadersOfPrune(log_id);
|
||
|
|
|
||
|
|
size_t buffer_size = it_to_prune->PruneSize();
|
||
|
|
RemoveChunkFromStats(log_id, *it_to_prune);
|
||
|
|
log_buffer.erase(it_to_prune);
|
||
|
|
if (buffer_size >= bytes_to_free) {
|
||
|
|
return;
|
||
|
|
}
|
||
|
|
bytes_to_free -= buffer_size;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
void SerializedLogBuffer::UidClear(log_id_t log_id, uid_t uid) {
|
||
|
|
// Wake all readers; see comment in Prune().
|
||
|
|
for (const auto& reader_thread : reader_list_->reader_threads()) {
|
||
|
|
if (!reader_thread->IsWatching(log_id)) {
|
||
|
|
continue;
|
||
|
|
}
|
||
|
|
|
||
|
|
if (reader_thread->deadline().time_since_epoch().count() != 0) {
|
||
|
|
reader_thread->TriggerReader();
|
||
|
|
}
|
||
|
|
}
|
||
|
|
ClearLogsByUid(logs_[log_id], uid, max_size_[log_id], log_id, stats_);
|
||
|
|
}
|
||
|
|
|
||
|
|
std::unique_ptr<FlushToState> SerializedLogBuffer::CreateFlushToState(uint64_t start,
|
||
|
|
LogMask log_mask) {
|
||
|
|
return std::make_unique<SerializedFlushToState>(start, log_mask, logs_);
|
||
|
|
}
|
||
|
|
|
||
|
|
bool SerializedLogBuffer::FlushTo(
|
||
|
|
LogWriter* writer, FlushToState& abstract_state,
|
||
|
|
const std::function<FilterResult(log_id_t log_id, pid_t pid, uint64_t sequence,
|
||
|
|
log_time realtime)>& filter) {
|
||
|
|
auto& state = reinterpret_cast<SerializedFlushToState&>(abstract_state);
|
||
|
|
|
||
|
|
while (state.HasUnreadLogs()) {
|
||
|
|
LogWithId top = state.PopNextUnreadLog();
|
||
|
|
auto* entry = top.entry;
|
||
|
|
auto log_id = top.log_id;
|
||
|
|
|
||
|
|
if (entry->sequence() < state.start()) {
|
||
|
|
continue;
|
||
|
|
}
|
||
|
|
state.set_start(entry->sequence());
|
||
|
|
|
||
|
|
if (!writer->privileged() && entry->uid() != writer->uid()) {
|
||
|
|
continue;
|
||
|
|
}
|
||
|
|
|
||
|
|
if (filter) {
|
||
|
|
auto ret = filter(log_id, entry->pid(), entry->sequence(), entry->realtime());
|
||
|
|
if (ret == FilterResult::kSkip) {
|
||
|
|
continue;
|
||
|
|
}
|
||
|
|
if (ret == FilterResult::kStop) {
|
||
|
|
break;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
// We copy the log entry such that we can flush it without the lock. We never block pruning
|
||
|
|
// waiting for this Flush() to complete.
|
||
|
|
#if defined(MTK_LOGD_ENHANCE) && defined(ANDROID_LOG_MUCH_COUNT)
|
||
|
|
constexpr size_t kMaxEntrySize = sizeof(*entry) + LOGGER_ENTRY_MAX_PAYLOAD + 18 + 1;
|
||
|
|
unsigned char entry_copy[kMaxEntrySize] __attribute__((uninitialized));
|
||
|
|
CHECK_LT(entry->msg_len(), LOGGER_ENTRY_MAX_PAYLOAD + 18 + 1);
|
||
|
|
#else
|
||
|
|
constexpr size_t kMaxEntrySize = sizeof(*entry) + LOGGER_ENTRY_MAX_PAYLOAD + 1;
|
||
|
|
unsigned char entry_copy[kMaxEntrySize] __attribute__((uninitialized));
|
||
|
|
CHECK_LT(entry->msg_len(), LOGGER_ENTRY_MAX_PAYLOAD + 1);
|
||
|
|
#endif
|
||
|
|
memcpy(entry_copy, entry, sizeof(*entry) + entry->msg_len());
|
||
|
|
logd_lock.unlock();
|
||
|
|
|
||
|
|
if (!reinterpret_cast<SerializedLogEntry*>(entry_copy)->Flush(writer, log_id)) {
|
||
|
|
logd_lock.lock();
|
||
|
|
return false;
|
||
|
|
}
|
||
|
|
|
||
|
|
logd_lock.lock();
|
||
|
|
}
|
||
|
|
|
||
|
|
state.set_start(state.start() + 1);
|
||
|
|
return true;
|
||
|
|
}
|
||
|
|
|
||
|
|
bool SerializedLogBuffer::Clear(log_id_t id, uid_t uid) {
|
||
|
|
auto lock = std::lock_guard{logd_lock};
|
||
|
|
if (uid == 0) {
|
||
|
|
Prune(id, ULONG_MAX);
|
||
|
|
} else {
|
||
|
|
UidClear(id, uid);
|
||
|
|
}
|
||
|
|
|
||
|
|
// Clearing SerializedLogBuffer never waits for readers and therefore is always successful.
|
||
|
|
return true;
|
||
|
|
}
|
||
|
|
|
||
|
|
size_t SerializedLogBuffer::GetSizeUsed(log_id_t id) {
|
||
|
|
size_t total_size = 0;
|
||
|
|
for (const auto& chunk : logs_[id]) {
|
||
|
|
total_size += chunk.PruneSize();
|
||
|
|
}
|
||
|
|
return total_size;
|
||
|
|
}
|
||
|
|
|
||
|
|
size_t SerializedLogBuffer::GetSize(log_id_t id) {
|
||
|
|
auto lock = std::lock_guard{logd_lock};
|
||
|
|
return max_size_[id];
|
||
|
|
}
|
||
|
|
|
||
|
|
// New SerializedLogChunk objects will be allocated according to the new size, but older one are
|
||
|
|
// unchanged. MaybePrune() is called on the log buffer to reduce it to an appropriate size if the
|
||
|
|
// new size is lower.
|
||
|
|
bool SerializedLogBuffer::SetSize(log_id_t id, size_t size) {
|
||
|
|
// Reasonable limits ...
|
||
|
|
if (!IsValidBufferSize(size)) {
|
||
|
|
return false;
|
||
|
|
}
|
||
|
|
|
||
|
|
auto lock = std::lock_guard{logd_lock};
|
||
|
|
max_size_[id] = size;
|
||
|
|
|
||
|
|
MaybePrune(id);
|
||
|
|
|
||
|
|
return true;
|
||
|
|
}
|
||
|
|
|
||
|
|
#if defined(MTK_LOGD_ENHANCE) && defined(MSSI_HAVE_AEE_FEATURE) && defined(ANDROID_LOG_MUCH_COUNT)
|
||
|
|
void SerializedLogBuffer::logMuchDetect(log_id_t log_id, log_time realtime) {
|
||
|
|
const char *log_type;
|
||
|
|
const char *log_tag = NULL;
|
||
|
|
const char *log_msg;
|
||
|
|
static int pause_detect = 1;
|
||
|
|
static int original_detect_value;
|
||
|
|
static int delay_time = 3*60;
|
||
|
|
static int line_count = 0;
|
||
|
|
static time_t old_time;
|
||
|
|
static struct timespec pause_time = {0, 0};
|
||
|
|
|
||
|
|
char *buff = NULL;
|
||
|
|
char *msg_buf = NULL;
|
||
|
|
int log_line_count = 0;
|
||
|
|
int file_count = 0;
|
||
|
|
int log_prio = ANDROID_LOG_INFO;
|
||
|
|
int buf_len;
|
||
|
|
int prop_value;
|
||
|
|
|
||
|
|
time_t logs_time, now_time;
|
||
|
|
struct timespec pause_time_now;
|
||
|
|
#if !defined(_WIN32)
|
||
|
|
struct tm tmBuf;
|
||
|
|
#endif
|
||
|
|
struct tm* ptm = NULL;
|
||
|
|
|
||
|
|
if (log_detect_value == 0) {
|
||
|
|
pause_detect = 0;
|
||
|
|
delay_time = 0;
|
||
|
|
original_detect_value = 0;
|
||
|
|
}
|
||
|
|
if (pause_detect == 1) {
|
||
|
|
if (pause_time.tv_sec == 0) {
|
||
|
|
clock_gettime(CLOCK_MONOTONIC, &pause_time);
|
||
|
|
}
|
||
|
|
clock_gettime(CLOCK_MONOTONIC, &pause_time_now);
|
||
|
|
if (pause_time_now.tv_sec - pause_time.tv_sec > delay_time) {
|
||
|
|
pause_detect = 0;
|
||
|
|
delay_time = 0;
|
||
|
|
log_detect_value = original_detect_value;
|
||
|
|
original_detect_value = 0;
|
||
|
|
LOG(DEBUG) << android::base::StringPrintf("detect delay end:level=%d,old level=%d",
|
||
|
|
log_detect_value, original_detect_value);
|
||
|
|
}
|
||
|
|
}
|
||
|
|
if (log_detect_value > 0 && log_much_detected == false) {
|
||
|
|
if (log_id == LOG_ID_KERNEL) {
|
||
|
|
goto log_much_exit;
|
||
|
|
}
|
||
|
|
|
||
|
|
now_time = realtime.tv_sec;
|
||
|
|
|
||
|
|
if (old_time == 0) {
|
||
|
|
log_much_delay_detect = 181;
|
||
|
|
}
|
||
|
|
|
||
|
|
if (log_much_delay_detect == 1) {
|
||
|
|
line_count = 1;
|
||
|
|
old_time = now_time + 1;
|
||
|
|
log_much_delay_detect = 0;
|
||
|
|
pause_detect = 0;
|
||
|
|
delay_time = 0;
|
||
|
|
original_detect_value = log_detect_value;
|
||
|
|
}
|
||
|
|
|
||
|
|
if (log_much_delay_detect > 0) {
|
||
|
|
pause_detect = 1;
|
||
|
|
clock_gettime(CLOCK_MONOTONIC, &pause_time);
|
||
|
|
delay_time = log_much_delay_detect;
|
||
|
|
log_much_delay_detect = 0;
|
||
|
|
if (now_time >= old_time) {
|
||
|
|
old_time = now_time;
|
||
|
|
line_count = 1;
|
||
|
|
}
|
||
|
|
if (original_detect_value == 0) {
|
||
|
|
original_detect_value = log_detect_value;
|
||
|
|
} else {
|
||
|
|
log_detect_value = original_detect_value;
|
||
|
|
}
|
||
|
|
log_detect_value = 2 * log_detect_value;
|
||
|
|
detect_time = (log_detect_value > 1000) ? 1 : 6;
|
||
|
|
LOG(DEBUG) << android::base::StringPrintf(
|
||
|
|
"detect delay:time=%d level=%d old level=%d",
|
||
|
|
delay_time, log_detect_value, original_detect_value);
|
||
|
|
}
|
||
|
|
|
||
|
|
if (old_time > now_time) {
|
||
|
|
line_count = 0;
|
||
|
|
goto log_much_exit;
|
||
|
|
}
|
||
|
|
if (now_time > (old_time + detect_time - 1)) {
|
||
|
|
if (line_count > (log_detect_value * detect_time)) {
|
||
|
|
std::string property = android::base::GetProperty("vendor.logmuch.value", "-1");
|
||
|
|
prop_value = strtol(property.c_str(), nullptr, 10);
|
||
|
|
|
||
|
|
if (prop_value > log_detect_value) {
|
||
|
|
log_detect_value = prop_value;
|
||
|
|
line_count = 1;
|
||
|
|
old_time = now_time + detect_time;
|
||
|
|
if (log_detect_value > 1000) {
|
||
|
|
detect_time = 1;
|
||
|
|
} else {
|
||
|
|
detect_time = 6;
|
||
|
|
}
|
||
|
|
goto log_much_exit;
|
||
|
|
}
|
||
|
|
|
||
|
|
buff = new char[BUFF_MAX_SIZE];
|
||
|
|
msg_buf = new char[BUFF_MAX_SIZE];
|
||
|
|
if (buff == NULL || msg_buf == NULL)
|
||
|
|
goto log_much_exit;
|
||
|
|
|
||
|
|
if (log_much_buf == NULL) {
|
||
|
|
if (line_count >= LOG_LINE_MAX_COUNT) {
|
||
|
|
log_line_count = LOG_LINE_MAX_COUNT;
|
||
|
|
} else {
|
||
|
|
log_line_count = line_count;
|
||
|
|
}
|
||
|
|
log_much_alloc_size = log_line_count * EACH_LOG_SIZE;
|
||
|
|
log_much_buf = (char*) malloc(log_much_alloc_size);
|
||
|
|
if (log_much_buf == NULL)
|
||
|
|
goto log_much_exit;
|
||
|
|
}
|
||
|
|
if (log_much_alloc_size > 0) {
|
||
|
|
memset(log_much_buf, 0, log_much_alloc_size);
|
||
|
|
}
|
||
|
|
log_much_used_size = 0;
|
||
|
|
memset(buff, 0, BUFF_MAX_SIZE);
|
||
|
|
memset(msg_buf, 0, BUFF_MAX_SIZE);
|
||
|
|
|
||
|
|
#if !defined(_WIN32)
|
||
|
|
ptm = localtime_r(&now_time, &tmBuf);
|
||
|
|
#else
|
||
|
|
ptm = localtime(&now_time);
|
||
|
|
#endif
|
||
|
|
if (ptm) {
|
||
|
|
strftime(buff, BUFF_MAX_SIZE, "%m-%d %H:%M:%S", ptm);
|
||
|
|
}
|
||
|
|
|
||
|
|
bool is_full = false;
|
||
|
|
for (int id = LOG_ID_MAIN; id < LOG_ID_KERNEL; ++id) {
|
||
|
|
bool find_it = false;
|
||
|
|
auto& log_buffer = logs_[id];
|
||
|
|
auto it = log_buffer.begin();
|
||
|
|
|
||
|
|
while ((!is_full) && (it != log_buffer.end())) {
|
||
|
|
int read_offset = 0;
|
||
|
|
int first_hit_offset = 0;
|
||
|
|
|
||
|
|
it->IncReaderRefCount();
|
||
|
|
if (!find_it) { // first find
|
||
|
|
while (read_offset < it->write_offset()) {
|
||
|
|
const auto* first_entry = it->log_entry(read_offset);
|
||
|
|
first_hit_offset = read_offset;
|
||
|
|
logs_time = first_entry->realtime().tv_sec;
|
||
|
|
if (old_time <= logs_time) {
|
||
|
|
find_it = true;
|
||
|
|
break;
|
||
|
|
}
|
||
|
|
read_offset += first_entry->total_len();
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
if (find_it) {
|
||
|
|
bool is_empty_msg = false;
|
||
|
|
const char *pMsg = nullptr;
|
||
|
|
uint16_t msg_len = 0;
|
||
|
|
|
||
|
|
read_offset = first_hit_offset;
|
||
|
|
while (read_offset < it->write_offset()) {
|
||
|
|
const auto* entry = it->log_entry(read_offset);
|
||
|
|
logs_time = entry->realtime().tv_sec;
|
||
|
|
read_offset += entry->total_len();
|
||
|
|
if (old_time > logs_time){
|
||
|
|
continue;
|
||
|
|
}
|
||
|
|
|
||
|
|
#if !defined(_WIN32)
|
||
|
|
ptm = localtime_r(&logs_time, &tmBuf);
|
||
|
|
#else
|
||
|
|
ptm = localtime(&logs_time);
|
||
|
|
#endif
|
||
|
|
switch (id) {
|
||
|
|
case LOG_ID_EVENTS:
|
||
|
|
log_type = android_log_id_to_name(static_cast<log_id_t>(id));
|
||
|
|
log_tag = android::tagToName(MsgToTag(entry->msg(), entry->msg_len()));
|
||
|
|
log_msg = NULL;
|
||
|
|
break;
|
||
|
|
case LOG_ID_MAIN:
|
||
|
|
case LOG_ID_SYSTEM:
|
||
|
|
case LOG_ID_CRASH:
|
||
|
|
case LOG_ID_RADIO:
|
||
|
|
log_type = android_log_id_to_name(static_cast<log_id_t>(id));
|
||
|
|
msg_len = entry->msg_len();
|
||
|
|
pMsg = entry->msg();
|
||
|
|
if ((pMsg == nullptr) ||
|
||
|
|
(msg_len == 0) || (msg_len >= BUFF_MAX_SIZE)) {
|
||
|
|
is_empty_msg = true;
|
||
|
|
break; // goto next_log;
|
||
|
|
}
|
||
|
|
// store the pMsg
|
||
|
|
memcpy(msg_buf, pMsg, msg_len);
|
||
|
|
msg_buf[msg_len] = '\0';
|
||
|
|
log_prio = msg_buf[0];
|
||
|
|
log_tag = msg_buf + 1;
|
||
|
|
if (strlen(log_tag) + 2 >= msg_len)
|
||
|
|
log_msg = NULL;
|
||
|
|
else
|
||
|
|
log_msg = msg_buf + strlen(log_tag) + 2;
|
||
|
|
msg_buf[BUFF_MAX_SIZE - 1] = '\0';
|
||
|
|
break;
|
||
|
|
default:
|
||
|
|
break;
|
||
|
|
}
|
||
|
|
if (is_empty_msg) {
|
||
|
|
is_empty_msg = false;
|
||
|
|
file_count++;
|
||
|
|
continue; // next log
|
||
|
|
}
|
||
|
|
/* strftime(timeBuf, sizeof(timeBuf), "%Y-%m-%d %H:%M:%S", ptm); */
|
||
|
|
buff[0]='\n';
|
||
|
|
if (ptm) {
|
||
|
|
strftime(buff + 1, BUFF_MAX_SIZE - 1, "%m-%d %H:%M:%S", ptm);
|
||
|
|
}
|
||
|
|
buf_len = strlen(buff);
|
||
|
|
buf_len += snprintf(buff + buf_len, BUFF_MAX_SIZE - buf_len, ".%06d ",
|
||
|
|
entry->realtime().tv_nsec / 1000);
|
||
|
|
/* event log tag */
|
||
|
|
buf_len += snprintf(buff + buf_len, BUFF_MAX_SIZE - buf_len, "%d, %d,[%s],[%d],[Tag]%s[TAG]:",
|
||
|
|
entry->pid(), entry->tid(), log_type, log_prio, log_tag);
|
||
|
|
|
||
|
|
if (id == LOG_ID_EVENTS || log_msg == NULL) {
|
||
|
|
/* event log message*/
|
||
|
|
} else if (BUFF_MAX_SIZE - 1 - buf_len > (int)strlen(log_msg)) {
|
||
|
|
snprintf(buff + buf_len, BUFF_MAX_SIZE - buf_len, "%s", log_msg);
|
||
|
|
buf_len += strlen(log_msg);
|
||
|
|
} else {
|
||
|
|
strncpy(buff + buf_len, log_msg, BUFF_MAX_SIZE - 1 - buf_len);
|
||
|
|
buff[BUFF_MAX_SIZE - 2] = '\n';
|
||
|
|
buff[BUFF_MAX_SIZE - 1] = '\0';
|
||
|
|
buf_len = BUFF_MAX_SIZE - 1;
|
||
|
|
}
|
||
|
|
file_count++;
|
||
|
|
|
||
|
|
if (buf_len < log_much_alloc_size - log_much_used_size) {
|
||
|
|
memcpy(log_much_buf + log_much_used_size, buff, buf_len);
|
||
|
|
log_much_used_size += buf_len;
|
||
|
|
} else {
|
||
|
|
buf_len = log_much_alloc_size - log_much_used_size;
|
||
|
|
memcpy(log_much_buf + log_much_used_size, buff, buf_len);
|
||
|
|
log_much_used_size += buf_len;
|
||
|
|
log_much_buf[log_much_alloc_size - 1] = 0;
|
||
|
|
is_full = true;
|
||
|
|
break;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
}
|
||
|
|
it->DecReaderRefCount();
|
||
|
|
|
||
|
|
if (!is_full) {
|
||
|
|
it++;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
if (is_full) {
|
||
|
|
break;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
// logmuch aee warning
|
||
|
|
pthread_attr_t attr;
|
||
|
|
if ((file_count > log_detect_value * detect_time) && !pthread_attr_init(&attr)) {
|
||
|
|
struct sched_param param;
|
||
|
|
int ret;
|
||
|
|
memset(aee_string, 0, 70);
|
||
|
|
|
||
|
|
ret = snprintf(aee_string, sizeof(aee_string), "Android log much: %d, %d.detect time %d.level %d.",
|
||
|
|
line_count, file_count, detect_time, log_detect_value);
|
||
|
|
if (ret > 0) {
|
||
|
|
LOG(INFO) << aee_string;
|
||
|
|
memset(¶m, 0, sizeof(param));
|
||
|
|
pthread_attr_setschedparam(&attr, ¶m);
|
||
|
|
pthread_attr_setschedpolicy(&attr, SCHED_BATCH);
|
||
|
|
if (!pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) {
|
||
|
|
pthread_t thread;
|
||
|
|
log_much_detected = true;
|
||
|
|
pthread_create(&thread, &attr, logmuchaee_thread_start, NULL);
|
||
|
|
} else {
|
||
|
|
LOG(ERROR) << "logmuch logmuchaee_thread_start create failed";
|
||
|
|
}
|
||
|
|
pthread_attr_destroy(&attr);
|
||
|
|
} else {
|
||
|
|
LOG(ERROR) << "logmuch aee_string ret:" << ret;
|
||
|
|
}
|
||
|
|
old_time = now_time + DETECT_DELAY_TIME;
|
||
|
|
} else {
|
||
|
|
old_time = now_time + detect_time;
|
||
|
|
}
|
||
|
|
|
||
|
|
line_count = 0;
|
||
|
|
delete[] buff;
|
||
|
|
buff = NULL;
|
||
|
|
delete[] msg_buf;
|
||
|
|
msg_buf = NULL;
|
||
|
|
} else {
|
||
|
|
line_count = 1;
|
||
|
|
old_time = now_time + detect_time;
|
||
|
|
}
|
||
|
|
} else {
|
||
|
|
line_count++;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
log_much_exit:
|
||
|
|
if (buff != NULL) {
|
||
|
|
delete[] buff;
|
||
|
|
buff = NULL;
|
||
|
|
}
|
||
|
|
if (msg_buf != NULL) {
|
||
|
|
delete[] msg_buf;
|
||
|
|
msg_buf = NULL;
|
||
|
|
}
|
||
|
|
}
|
||
|
|
#endif
|