Pass the last error code when statslog.write fails

The error code will give us some clue on what caused the loss (e.g., EBUSY, or ENOENT)

Test: manual
Bug: 80538532

Change-Id: I446c6e2255bdae063dfb8803ad0b702ead87c645

5 files changed, 36 insertions, 22 deletions

diff --git a/cmds/statsd/src/guardrail/StatsdStats.cpp b/cmds/statsd/src/guardrail/StatsdStats.cpp
index d2919c51a65e..86c6e5c47af7 100644
--- a/cmds/statsd/src/guardrail/StatsdStats.cpp
+++ b/cmds/statsd/src/guardrail/StatsdStats.cpp
@@ -47,11 +47,9 @@ const int FIELD_ID_CONFIG_STATS = 3;
 const int FIELD_ID_ATOM_STATS = 7;
 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_PERIODIC_ALARM_STATS = 12;
-// const int FIELD_ID_LOG_LOSS_STATS = 14;
 const int FIELD_ID_SYSTEM_SERVER_RESTART = 15;
+const int FIELD_ID_LOGGER_ERROR_STATS = 16;
 
 const int FIELD_ID_ATOM_STATS_TAG = 1;
 const int FIELD_ID_ATOM_STATS_COUNT = 2;
@@ -59,8 +57,9 @@ const int FIELD_ID_ATOM_STATS_COUNT = 2;
 const int FIELD_ID_ANOMALY_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_LOG_LOSS_STATS_TIME = 1;
+const int FIELD_ID_LOG_LOSS_STATS_COUNT = 2;
+const int FIELD_ID_LOG_LOSS_STATS_ERROR = 3;
 
 const int FIELD_ID_CONFIG_STATS_UID = 1;
 const int FIELD_ID_CONFIG_STATS_ID = 2;
@@ -181,12 +180,12 @@ void StatsdStats::noteConfigReset(const ConfigKey& key) {
     noteConfigResetInternalLocked(key);
 }
 
-void StatsdStats::noteLogLost(int32_t wallClockTimeSec, int32_t count) {
+void StatsdStats::noteLogLost(int32_t wallClockTimeSec, int32_t count, int32_t lastError) {
     lock_guard<std::mutex> lock(mLock);
     if (mLogLossStats.size() == kMaxLoggerErrors) {
         mLogLossStats.pop_front();
     }
-    mLogLossStats.push_back(std::make_pair(wallClockTimeSec, count));
+    mLogLossStats.emplace_back(wallClockTimeSec, count, lastError);
 }
 
 void StatsdStats::noteBroadcastSent(const ConfigKey& key) {
@@ -557,8 +556,8 @@ void StatsdStats::dumpStats(int out) const {
     }
 
     for (const auto& loss : mLogLossStats) {
-        dprintf(out, "Log loss: %lld (wall clock sec) - %d (count)\n", (long long)loss.first,
-                loss.second);
+        dprintf(out, "Log loss: %lld (wall clock sec) - %d (count) %d (last error)\n",
+                (long long)loss.mWallClockSec, loss.mCount, loss.mLastError);
     }
 }
 
@@ -713,13 +712,11 @@ void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) {
     proto.end(uidMapToken);
 
     for (const auto& error : mLogLossStats) {
-        // The logger error stats are not used anymore since we move away from logd.
-        // Temporarily use this field to log the log loss timestamp and count
-        // TODO(b/80538532) Add a dedicated field in stats_log for this.
         uint64_t token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_LOGGER_ERROR_STATS |
                                       FIELD_COUNT_REPEATED);
-        proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOGGER_STATS_TIME, error.first);
-        proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOGGER_STATS_ERROR_CODE, error.second);
+        proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOG_LOSS_STATS_TIME, error.mWallClockSec);
+        proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOG_LOSS_STATS_COUNT, error.mCount);
+        proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOG_LOSS_STATS_ERROR, error.mLastError);
         proto.end(token);
     }
 
diff --git a/cmds/statsd/src/guardrail/StatsdStats.h b/cmds/statsd/src/guardrail/StatsdStats.h
index 777d8652d2b6..247027ad47a5 100644
--- a/cmds/statsd/src/guardrail/StatsdStats.h
+++ b/cmds/statsd/src/guardrail/StatsdStats.h
@@ -298,7 +298,7 @@ public:
     /**
      * Records statsd skipped an event.
      */
-    void noteLogLost(int32_t wallClockTimeSec, int32_t count);
+    void noteLogLost(int32_t wallClockTimeSec, int32_t count, int lastError);
 
     /**
      * Reset the historical stats. Including all stats in icebox, and the tracked stats about
@@ -358,8 +358,18 @@ private:
     // Maps PullAtomId to its stats. The size is capped by the puller atom counts.
     std::map<int, PulledAtomStats> mPulledAtomStats;
 
+    struct LogLossStats {
+        LogLossStats(int32_t sec, int32_t count, int32_t error)
+            : mWallClockSec(sec), mCount(count), mLastError(error) {
+        }
+        int32_t mWallClockSec;
+        int32_t mCount;
+        // error code defined in linux/errno.h
+        int32_t mLastError;
+    };
+
     // Timestamps when we detect log loss, and the number of logs lost.
-    std::list<std::pair<int32_t, int32_t>> mLogLossStats;
+    std::list<LogLossStats> mLogLossStats;
 
     std::list<int32_t> mSystemServerRestartSec;
 
diff --git a/cmds/statsd/src/socket/StatsSocketListener.cpp b/cmds/statsd/src/socket/StatsSocketListener.cpp
index 9b0691b6092d..6bb8cda07281 100755
--- a/cmds/statsd/src/socket/StatsSocketListener.cpp
+++ b/cmds/statsd/src/socket/StatsSocketListener.cpp
@@ -40,7 +40,6 @@ namespace os {
 namespace statsd {
 
 static const int kLogMsgHeaderSize = 28;
-static const int kLibLogTag = 1006;
 
 StatsSocketListener::StatsSocketListener(const sp<LogListener>& listener)
     : SocketListener(getLogSocket(), false /*start listen*/), mListener(listener) {
@@ -109,10 +108,11 @@ bool StatsSocketListener::onDataAvailable(SocketClient* cli) {
     // TODO(b/80538532): In addition to log it in StatsdStats, we should properly reset the config.
     if (n == sizeof(android_log_event_int_t)) {
         android_log_event_int_t* int_event = reinterpret_cast<android_log_event_int_t*>(ptr);
-        if (int_event->header.tag == kLibLogTag && int_event->payload.type == EVENT_TYPE_INT) {
-            ALOGE("Found dropped events: %d", int_event->payload.data);
+        if (int_event->payload.type == EVENT_TYPE_INT) {
+            ALOGE("Found dropped events: %d error %d", int_event->payload.data,
+                  int_event->header.tag);
             StatsdStats::getInstance().noteLogLost((int32_t)getWallClockSec(),
-                                                   int_event->payload.data);
+                                                   int_event->payload.data, int_event->header.tag);
             return true;
         }
     }
diff --git a/cmds/statsd/src/stats_log.proto b/cmds/statsd/src/stats_log.proto
index 8bfa36059e9a..7c00e35ad704 100644
--- a/cmds/statsd/src/stats_log.proto
+++ b/cmds/statsd/src/stats_log.proto
@@ -397,4 +397,11 @@ message StatsdStatsReport {
     repeated int64 log_loss_stats = 14;
 
     repeated int32 system_restart_sec = 15;
+
+    message LogLossStats {
+        optional int32 detected_time_sec = 1;
+        optional int32 count = 2;
+        optional int32 last_error = 3;
+    }
+    repeated LogLossStats detected_log_loss = 16;
 }
diff --git a/tools/stats_log_api_gen/main.cpp b/tools/stats_log_api_gen/main.cpp
index 1ef34b9c22eb..8585ae9f3f61 100644
--- a/tools/stats_log_api_gen/main.cpp
+++ b/tools/stats_log_api_gen/main.cpp
@@ -435,7 +435,7 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms,
        fprintf(out, "      std::this_thread::sleep_for(std::chrono::milliseconds(10));\n");
        fprintf(out, "  }\n");
        fprintf(out, "  if (ret < 0) {\n");
-       fprintf(out, "      note_log_drop();\n");
+       fprintf(out, "      note_log_drop(ret);\n");
        fprintf(out, "  }\n");
        fprintf(out, "  return ret;\n");
        fprintf(out, "}\n");
@@ -528,7 +528,7 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms,
        fprintf(out, "      std::this_thread::sleep_for(std::chrono::milliseconds(10));\n");
        fprintf(out, "  }\n");
        fprintf(out, "  if (ret < 0) {\n");
-       fprintf(out, "      note_log_drop();\n");
+       fprintf(out, "      note_log_drop(ret);\n");
        fprintf(out, "  }\n");
        fprintf(out, "  return ret;\n\n");
        fprintf(out, "}\n");