Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 49d7dd7a authored by Yao Chen's avatar Yao Chen
Browse files

Report the last atom tag, uid in the case of log loss. 

Test: manually tested and existing statsd_test
Change-Id: I8cea9e09c4c069ec234fc0d989d550886605449b
parent 44dbdbc3

cmds/statsd/src/guardrail/StatsdStats.cpp

+14 −4
Original line number Diff line number Diff line
@@ -60,6 +60,9 @@ const int FIELD_ID_PERIODIC_ALARMS_REGISTERED = 1; 
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_LOG_LOSS_STATS_TAG = 4;

const int FIELD_ID_LOG_LOSS_STATS_UID = 5;

const int FIELD_ID_LOG_LOSS_STATS_PID = 6;



const int FIELD_ID_CONFIG_STATS_UID = 1;

const int FIELD_ID_CONFIG_STATS_ID = 2;
@@ -183,12 +186,13 @@ void StatsdStats::noteConfigReset(const ConfigKey& key) { 
    noteConfigResetInternalLocked(key);

}



void StatsdStats::noteLogLost(int32_t wallClockTimeSec, int32_t count, int32_t lastError) {

void StatsdStats::noteLogLost(int32_t wallClockTimeSec, int32_t count, int32_t lastError,

                              int32_t lastTag, int32_t uid, int32_t pid) {

    lock_guard<std::mutex> lock(mLock);

    if (mLogLossStats.size() == kMaxLoggerErrors) {

        mLogLossStats.pop_front();

    }

    mLogLossStats.emplace_back(wallClockTimeSec, count, lastError);

    mLogLossStats.emplace_back(wallClockTimeSec, count, lastError, lastTag, uid, pid);

}



void StatsdStats::noteBroadcastSent(const ConfigKey& key) {
@@ -716,8 +720,11 @@ void StatsdStats::dumpStats(int out) const { 
    }



    for (const auto& loss : mLogLossStats) {

        dprintf(out, "Log loss: %lld (wall clock sec) - %d (count) %d (last error)\n",

                (long long)loss.mWallClockSec, loss.mCount, loss.mLastError);

        dprintf(out,

                "Log loss: %lld (wall clock sec) - %d (count), %d (last error), %d (last tag), %d "

                "(uid), %d (pid)\n",

                (long long)loss.mWallClockSec, loss.mCount, loss.mLastError, loss.mLastTag,

                loss.mUid, loss.mPid);

    }

}
@@ -891,6 +898,9 @@ void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) { 
        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.write(FIELD_TYPE_INT32 | FIELD_ID_LOG_LOSS_STATS_TAG, error.mLastTag);

        proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOG_LOSS_STATS_UID, error.mUid);

        proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOG_LOSS_STATS_PID, error.mPid);

        proto.end(token);

    }

cmds/statsd/src/guardrail/StatsdStats.h

+13 −3
Original line number Diff line number Diff line
@@ -336,7 +336,8 @@ public: 
    /**

     * Records statsd skipped an event.

     */

    void noteLogLost(int32_t wallClockTimeSec, int32_t count, int lastError);

    void noteLogLost(int32_t wallClockTimeSec, int32_t count, int32_t lastError,

                     int32_t lastAtomTag, int32_t uid, int32_t pid);



    /**

     * Records that the pull of an atom has failed
@@ -503,13 +504,22 @@ private: 
    std::map<int64_t, AtomMetricStats> mAtomMetricStats;



    struct LogLossStats {

        LogLossStats(int32_t sec, int32_t count, int32_t error)

            : mWallClockSec(sec), mCount(count), mLastError(error) {

        LogLossStats(int32_t sec, int32_t count, int32_t error, int32_t tag, int32_t uid,

                     int32_t pid)

            : mWallClockSec(sec),

              mCount(count),

              mLastError(error),

              mLastTag(tag),

              mUid(uid),

              mPid(pid) {

        }

        int32_t mWallClockSec;

        int32_t mCount;

        // error code defined in linux/errno.h

        int32_t mLastError;

        int32_t mLastTag;

        int32_t mUid;

        int32_t mPid;

    };



    // Timestamps when we detect log loss, and the number of logs lost.

cmds/statsd/src/socket/StatsSocketListener.cpp

+15 −7
Original line number Diff line number Diff line
@@ -106,13 +106,21 @@ bool StatsSocketListener::onDataAvailable(SocketClient* cli) { 
    // Note that all normal stats logs are in the format of event_list, so there won't be confusion.

    //

    // 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->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->header.tag);

    if (n == sizeof(android_log_event_long_t)) {

        android_log_event_long_t* long_event = reinterpret_cast<android_log_event_long_t*>(ptr);

        if (long_event->payload.type == EVENT_TYPE_LONG) {

            int64_t composed_long = long_event->payload.data;



            // format:

            // |last_tag|dropped_count|

            int32_t dropped_count = (int32_t)(0xffffffff & composed_long);

            int32_t last_atom_tag = (int32_t)((0xffffffff00000000 & (uint64_t)composed_long) >> 32);



            ALOGE("Found dropped events: %d error %d last atom tag %d from uid %d", dropped_count,

                  long_event->header.tag, last_atom_tag, cred->uid);

            StatsdStats::getInstance().noteLogLost((int32_t)getWallClockSec(), dropped_count,

                                                   long_event->header.tag, last_atom_tag, cred->uid,

                                                   cred->pid);

            return true;

        }

    }

cmds/statsd/src/stats_log.proto

+3 −0
Original line number Diff line number Diff line
@@ -455,6 +455,9 @@ message StatsdStatsReport { 
        optional int32 detected_time_sec = 1;

        optional int32 count = 2;

        optional int32 last_error = 3;

        optional int32 last_tag = 4;

        optional int32 uid = 5;

        optional int32 pid = 6;

    }

    repeated LogLossStats detected_log_loss = 16;

}

tools/stats_log_api_gen/main.cpp

+2 −2
Original line number Diff line number Diff line
@@ -512,7 +512,7 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms, const AtomDecl &at 
       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(ret);\n");

       fprintf(out, "      note_log_drop(ret, code);\n");

       fprintf(out, "  }\n");

       fprintf(out, "  return ret;\n");

       fprintf(out, "}\n");
@@ -620,7 +620,7 @@ static int write_stats_log_cpp(FILE *out, const Atoms &atoms, const AtomDecl &at 
       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(ret);\n");

       fprintf(out, "      note_log_drop(ret, code);\n");

       fprintf(out, "  }\n");

       fprintf(out, "  return ret;\n\n");

       fprintf(out, "}\n");