Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Retry logs write when it fails. Report skipped event in statsd." into pi-dev

Browse Source
This commit is contained in:
TreeHugger Robot
2018-04-05 18:04:18 +00:00
committed by Android (Google) Code Review
parent bd2e790946 b8382a10a0
commit 164a73e0cf
6 changed files with 159 additions and 16 deletions
Download Patch File Download Diff File Expand all files Collapse all files

3
cmds/statsd/src/StatsLogProcessor.cpp
View File

@@ -158,7 +158,10 @@ void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
void StatsLogProcessor::OnLogEvent(LogEvent* event) {
std::lock_guard<std::mutex> lock(mMetricsMutex);
const int64_t currentTimestampNs = event->GetElapsedTimestampNs();
if (currentTimestampNs < mLastLogTimestamp) {
StatsdStats::getInstance().noteLogEventSkipped(
event->GetTagId(), event->GetElapsedTimestampNs());
return;
}

34
cmds/statsd/src/guardrail/StatsdStats.cpp
View File

@@ -49,17 +49,21 @@ const int FIELD_ID_UIDMAP_STATS = 8;
const int FIELD_ID_ANOMALY_ALARM_STATS = 9;
// const int FIELD_ID_PULLED_ATOM_STATS = 10; // The proto is written in stats_log_util.cpp
const int FIELD_ID_LOGGER_ERROR_STATS = 11;
const int FIELD_ID_SUBSCRIBER_ALARM_STATS = 12;
const int FIELD_ID_PERIODIC_ALARM_STATS = 12;
const int FIELD_ID_SKIPPED_LOG_EVENT_STATS = 13;
const int FIELD_ID_ATOM_STATS_TAG = 1;
const int FIELD_ID_ATOM_STATS_COUNT = 2;
const int FIELD_ID_ANOMALY_ALARMS_REGISTERED = 1;
const int FIELD_ID_SUBSCRIBER_ALARMS_REGISTERED = 1;
const int FIELD_ID_PERIODIC_ALARMS_REGISTERED = 1;
const int FIELD_ID_LOGGER_STATS_TIME = 1;
const int FIELD_ID_LOGGER_STATS_ERROR_CODE = 2;
const int FIELD_ID_SKIPPED_LOG_EVENT_STATS_TAG = 1;
const int FIELD_ID_SKIPPED_LOG_EVENT_STATS_TIMESTAMP = 2;
const int FIELD_ID_CONFIG_STATS_UID = 1;
const int FIELD_ID_CONFIG_STATS_ID = 2;
const int FIELD_ID_CONFIG_STATS_CREATION = 3;
@@ -346,6 +350,15 @@ void StatsdStats::noteAtomLogged(int atomId, int32_t timeSec) {
mPushedAtomStats[atomId]++;
}
void StatsdStats::noteLogEventSkipped(int tag, int64_t timestamp) {
lock_guard<std::mutex> lock(mLock);
// grows strictly one at a time. so it won't > kMaxSkippedLogEvents
if (mSkippedLogEvents.size() == kMaxSkippedLogEvents) {
mSkippedLogEvents.pop_front();
}
mSkippedLogEvents.push_back(std::make_pair(tag, timestamp));
}
void StatsdStats::noteLoggerError(int error) {
lock_guard<std::mutex> lock(mLock);
// grows strictly one at a time. so it won't > kMaxLoggerErrors
@@ -368,6 +381,7 @@ void StatsdStats::resetInternalLocked() {
mAnomalyAlarmRegisteredStats = 0;
mPeriodicAlarmRegisteredStats = 0;
mLoggerErrors.clear();
mSkippedLogEvents.clear();
for (auto& config : mConfigStats) {
config.second->broadcast_sent_time_sec.clear();
config.second->data_drop_time_sec.clear();
@@ -491,6 +505,9 @@ void StatsdStats::dumpStats(FILE* out) const {
strftime(buffer, sizeof(buffer), "%Y-%m-%d %I:%M%p\n", error_tm);
fprintf(out, "Logger error %d at %s\n", error.second, buffer);
}
for (const auto& skipped : mSkippedLogEvents) {
fprintf(out, "Log event (%d) skipped at %lld\n", skipped.first, (long long)skipped.second);
}
}
void addConfigStatsToProto(const ConfigStats& configStats, ProtoOutputStream* proto) {
@@ -617,8 +634,8 @@ void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) {
}
if (mPeriodicAlarmRegisteredStats > 0) {
uint64_t token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_SUBSCRIBER_ALARM_STATS);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_SUBSCRIBER_ALARMS_REGISTERED,
uint64_t token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_PERIODIC_ALARM_STATS);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_PERIODIC_ALARMS_REGISTERED,
mPeriodicAlarmRegisteredStats);
proto.end(token);
}
@@ -640,6 +657,15 @@ void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) {
proto.end(token);
}
for (const auto& skipped : mSkippedLogEvents) {
uint64_t token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_SKIPPED_LOG_EVENT_STATS |
FIELD_COUNT_REPEATED);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_SKIPPED_LOG_EVENT_STATS_TAG, skipped.first);
proto.write(FIELD_TYPE_INT64 | FIELD_ID_SKIPPED_LOG_EVENT_STATS_TIMESTAMP,
(long long)skipped.second);
proto.end(token);
}
output->clear();
size_t bufferSize = proto.size();
output->resize(bufferSize);

10
cmds/statsd/src/guardrail/StatsdStats.h
View File

@@ -105,6 +105,8 @@ public:
const static int kMaxLoggerErrors = 10;
const static int kMaxSkippedLogEvents = 200;
const static int kMaxTimestampCount = 20;
const static int kMaxLogSourceCount = 50;
@@ -269,6 +271,11 @@ public:
*/
void noteLoggerError(int error);
/**
* Records statsd skipped an event.
*/
void noteLogEventSkipped(int tag, int64_t timestamp);
/**
* Reset the historical stats. Including all stats in icebox, and the tracked stats about
* metrics, matchers, and atoms. The active configs will be kept and StatsdStats will continue
@@ -324,6 +331,9 @@ private:
// Logd errors. Size capped by kMaxLoggerErrors.
std::list<const std::pair<int, int>> mLoggerErrors;
// Skipped log events.
std::list<const std::pair<int, int64_t>> mSkippedLogEvents;
// Stores the number of times statsd modified the anomaly alarm registered with
// StatsCompanionService.
int mAnomalyAlarmRegisteredStats = 0;

11
cmds/statsd/src/stats_log.proto
View File

@@ -292,4 +292,15 @@ message StatsdStatsReport {
optional int32 error_code = 2;
}
repeated LoggerErrorStats logger_error_stats = 11;
message PeriodicAlarmStats {
optional int32 alarms_registered = 1;
}
optional PeriodicAlarmStats periodic_alarm_stats = 12;
message SkippedLogEventStats {
optional int32 tag = 1;
optional int64 elapsed_timestamp_nanos = 2;
}
repeated SkippedLogEventStats skipped_log_event_stats = 13;
}

1
tools/stats_log_api_gen/Android.bp
View File

@@ -101,7 +101,6 @@ cc_library_shared {
cflags: [
"-Wall",
"-Werror",
"-fexceptions",
],
export_generated_headers: ["statslog.h"],
shared_libs: [

116
tools/stats_log_api_gen/main.cpp
View File

@@ -101,7 +101,8 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms,
fprintf(out, "// This file is autogenerated\n");
fprintf(out, "\n");
fprintf(out, "#include <exception>\n");
fprintf(out, "#include <chrono>\n");
fprintf(out, "#include <thread>\n");
fprintf(out, "#include <log/log_event_list.h>\n");
fprintf(out, "#include <log/log.h>\n");
fprintf(out, "#include <statslog.h>\n");
@@ -212,7 +213,7 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms,
int argIndex;
fprintf(out, "int\n");
fprintf(out, "stats_write(int32_t code");
fprintf(out, "try_stats_write(int32_t code");
argIndex = 1;
for (vector<java_type_t>::const_iterator arg = signature->begin();
arg != signature->end(); arg++) {
@@ -247,10 +248,6 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms,
if (chainField.javaType == JAVA_TYPE_STRING) {
fprintf(out, " if (%s_length != %s.size()) {\n",
attributionDecl.fields.front().name.c_str(), chainField.name.c_str());
fprintf(out, " throw std::invalid_argument(\"attribution fields with"
" diff length: %s vs %s\");\n",
attributionDecl.fields.front().name.c_str(),
chainField.name.c_str());
fprintf(out, " return -EINVAL;\n");
fprintf(out, " }\n");
}
@@ -289,12 +286,74 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms,
fprintf(out, "\n");
}
for (set<vector<java_type_t>>::const_iterator signature = atoms.signatures.begin();
signature != atoms.signatures.end(); signature++) {
int argIndex;
fprintf(out, "int \n");
fprintf(out, "stats_write(int32_t code");
argIndex = 1;
for (vector<java_type_t>::const_iterator arg = signature->begin();
arg != signature->end(); arg++) {
if (*arg == JAVA_TYPE_ATTRIBUTION_CHAIN) {
for (auto chainField : attributionDecl.fields) {
if (chainField.javaType == JAVA_TYPE_STRING) {
fprintf(out, ", const std::vector<%s>& %s",
cpp_type_name(chainField.javaType),
chainField.name.c_str());
} else {
fprintf(out, ", const %s* %s, size_t %s_length",
cpp_type_name(chainField.javaType),
chainField.name.c_str(), chainField.name.c_str());
}
}
} else {
fprintf(out, ", %s arg%d", cpp_type_name(*arg), argIndex);
}
argIndex++;
}
fprintf(out, ")\n");
fprintf(out, "{\n");
fprintf(out, " int ret = 0;\n");
fprintf(out, " for(int retry = 0; retry < 3; ++retry) {\n");
fprintf(out, " ret = try_stats_write(code");
argIndex = 1;
for (vector<java_type_t>::const_iterator arg = signature->begin();
arg != signature->end(); arg++) {
if (*arg == JAVA_TYPE_ATTRIBUTION_CHAIN) {
for (auto chainField : attributionDecl.fields) {
if (chainField.javaType == JAVA_TYPE_STRING) {
fprintf(out, ", %s",
chainField.name.c_str());
} else {
fprintf(out, ", %s, %s_length",
chainField.name.c_str(), chainField.name.c_str());
}
}
} else {
fprintf(out, ", arg%d", argIndex);
}
argIndex++;
}
fprintf(out, ");\n");
fprintf(out, " if (ret >= 0) { return retry; }\n");
fprintf(out,
" std::this_thread::sleep_for(std::chrono::milliseconds(10 + 10 * retry));\n");
fprintf(out, " }\n");
fprintf(out, " return ret;\n");
fprintf(out, "}\n");
fprintf(out, "\n");
}
for (set<vector<java_type_t>>::const_iterator signature = atoms.non_chained_signatures.begin();
signature != atoms.non_chained_signatures.end(); signature++) {
int argIndex;
fprintf(out, "int\n");
fprintf(out, "stats_write_non_chained(int32_t code");
fprintf(out, "try_stats_write_non_chained(int32_t code");
argIndex = 1;
for (vector<java_type_t>::const_iterator arg = signature->begin();
arg != signature->end(); arg++) {
@@ -331,6 +390,45 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms,
fprintf(out, "}\n");
fprintf(out, "\n");
}
for (set<vector<java_type_t>>::const_iterator signature = atoms.non_chained_signatures.begin();
signature != atoms.non_chained_signatures.end(); signature++) {
int argIndex;
fprintf(out, "int\n");
fprintf(out, "stats_write_non_chained(int32_t code");
argIndex = 1;
for (vector<java_type_t>::const_iterator arg = signature->begin();
arg != signature->end(); arg++) {
fprintf(out, ", %s arg%d", cpp_type_name(*arg), argIndex);
argIndex++;
}
fprintf(out, ")\n");
fprintf(out, "{\n");
fprintf(out, " int ret = 0;\n");
fprintf(out, " for(int retry = 0; retry < 3; ++retry) {\n");
fprintf(out, " ret = try_stats_write_non_chained(code");
argIndex = 1;
for (vector<java_type_t>::const_iterator arg = signature->begin();
arg != signature->end(); arg++) {
fprintf(out, ", arg%d", argIndex);
argIndex++;
}
fprintf(out, ");\n");
fprintf(out, " if (ret >= 0) { return retry; }\n");
fprintf(out,
" std::this_thread::sleep_for(std::chrono::milliseconds(10 + 10 * retry));\n");
fprintf(out, " }\n");
fprintf(out, " return ret;\n");
fprintf(out, "}\n");
fprintf(out, "\n");
}
// Print footer
fprintf(out, "\n");
fprintf(out, "} // namespace util\n");
@@ -775,10 +873,6 @@ write_stats_log_jni(FILE* out, const string& java_method_name, const string& cpp
fprintf(out, " if (%s_length != %s_length) {\n",
chainField.name.c_str(),
attributionDecl.fields.front().name.c_str());
fprintf(out, " jniThrowException(env, "
"\"java/lang/IllegalArgumentException\", "
"\"invalid attribution field(%s) length.\");\n",
chainField.name.c_str());
fprintf(out, " return -EINVAL;\n");
fprintf(out, " }\n");
}