diff --git a/cmds/statsd/src/StatsLogProcessor.cpp b/cmds/statsd/src/StatsLogProcessor.cpp index de8dfe47a6efb..de4ab639419ad 100644 --- a/cmds/statsd/src/StatsLogProcessor.cpp +++ b/cmds/statsd/src/StatsLogProcessor.cpp @@ -158,7 +158,10 @@ void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) { void StatsLogProcessor::OnLogEvent(LogEvent* event) { std::lock_guard lock(mMetricsMutex); const int64_t currentTimestampNs = event->GetElapsedTimestampNs(); + if (currentTimestampNs < mLastLogTimestamp) { + StatsdStats::getInstance().noteLogEventSkipped( + event->GetTagId(), event->GetElapsedTimestampNs()); return; } diff --git a/cmds/statsd/src/guardrail/StatsdStats.cpp b/cmds/statsd/src/guardrail/StatsdStats.cpp index b3921128ff33e..bdc8fa93a6b1e 100644 --- a/cmds/statsd/src/guardrail/StatsdStats.cpp +++ b/cmds/statsd/src/guardrail/StatsdStats.cpp @@ -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 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 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* 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* 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); diff --git a/cmds/statsd/src/guardrail/StatsdStats.h b/cmds/statsd/src/guardrail/StatsdStats.h index 00bef7560e386..93f780c1064e2 100644 --- a/cmds/statsd/src/guardrail/StatsdStats.h +++ b/cmds/statsd/src/guardrail/StatsdStats.h @@ -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> mLoggerErrors; + // Skipped log events. + std::list> mSkippedLogEvents; + // Stores the number of times statsd modified the anomaly alarm registered with // StatsCompanionService. int mAnomalyAlarmRegisteredStats = 0; diff --git a/cmds/statsd/src/stats_log.proto b/cmds/statsd/src/stats_log.proto index 4aa3c9738a41b..8213252675f91 100644 --- a/cmds/statsd/src/stats_log.proto +++ b/cmds/statsd/src/stats_log.proto @@ -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; } diff --git a/tools/stats_log_api_gen/Android.bp b/tools/stats_log_api_gen/Android.bp index 948422c868d61..17819dbabcb75 100644 --- a/tools/stats_log_api_gen/Android.bp +++ b/tools/stats_log_api_gen/Android.bp @@ -101,7 +101,6 @@ cc_library_shared { cflags: [ "-Wall", "-Werror", - "-fexceptions", ], export_generated_headers: ["statslog.h"], shared_libs: [ diff --git a/tools/stats_log_api_gen/main.cpp b/tools/stats_log_api_gen/main.cpp index 499f2549b4742..057772ffe0130 100644 --- a/tools/stats_log_api_gen/main.cpp +++ b/tools/stats_log_api_gen/main.cpp @@ -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 \n"); + fprintf(out, "#include \n"); + fprintf(out, "#include \n"); fprintf(out, "#include \n"); fprintf(out, "#include \n"); fprintf(out, "#include \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::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>::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::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::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>::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::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>::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::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::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"); }