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

Commit 365fdb7a authored by Tom Cherry's avatar Tom Cherry Committed by Gerrit Code Review
Browse files

Merge changes Id47b288d,I969565eb,Iba2e654e 

* changes:
  logd: drop can_read_security_logs
  logd: create FlushToState class
  logd: fix bug in FlushTo when requesting exact sequence number
parents 7a5b3970 eb49b04e

logd/ChattyLogBufferTest.cpp

+11 −8
Original line number Diff line number Diff line
@@ -61,7 +61,8 @@ TEST_P(ChattyLogBufferTest, deduplication_simple) { 


    std::vector<LogMessage> read_log_messages;

    std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));

    log_buffer_->FlushTo(test_writer.get(), 1, nullptr, nullptr);

    std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, kLogMaskAll);

    EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));



    std::vector<LogMessage> expected_log_messages = {

            make_message(0, "test_tag", "duplicate"),
@@ -72,12 +73,12 @@ TEST_P(ChattyLogBufferTest, deduplication_simple) { 
            make_message(5, "test_tag", "not_same"),

            // 3 duplicate logs together print the first, a 1 count chatty message, then the last.

            make_message(6, "test_tag", "duplicate"),

            make_message(7, "chatty", "uid=0\\([^\\)]+\\) [^ ]+ expire 1 line", true),

            make_message(7, "chatty", "uid=0\\([^\\)]+\\) [^ ]+ identical 1 line", true),

            make_message(8, "test_tag", "duplicate"),

            make_message(9, "test_tag", "not_same"),

            // 6 duplicate logs together print the first, a 4 count chatty message, then the last.

            make_message(10, "test_tag", "duplicate"),

            make_message(14, "chatty", "uid=0\\([^\\)]+\\) [^ ]+ expire 4 lines", true),

            make_message(14, "chatty", "uid=0\\([^\\)]+\\) [^ ]+ identical 4 lines", true),

            make_message(15, "test_tag", "duplicate"),

            make_message(16, "test_tag", "not_same"),

            // duplicate logs > 1 minute apart are not deduplicated.
@@ -117,15 +118,16 @@ TEST_P(ChattyLogBufferTest, deduplication_overflow) { 


    std::vector<LogMessage> read_log_messages;

    std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));

    log_buffer_->FlushTo(test_writer.get(), 1, nullptr, nullptr);

    std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, kLogMaskAll);

    EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));



    std::vector<LogMessage> expected_log_messages = {

            make_message(0, "test_tag", "normal"),

            make_message(1, "test_tag", "duplicate"),

            make_message(expired_per_chatty_message + 1, "chatty",

                         "uid=0\\([^\\)]+\\) [^ ]+ expire 65535 lines", true),

                         "uid=0\\([^\\)]+\\) [^ ]+ identical 65535 lines", true),

            make_message(expired_per_chatty_message + 2, "chatty",

                         "uid=0\\([^\\)]+\\) [^ ]+ expire 1 line", true),

                         "uid=0\\([^\\)]+\\) [^ ]+ identical 1 line", true),

            make_message(expired_per_chatty_message + 3, "test_tag", "duplicate"),

            make_message(expired_per_chatty_message + 4, "test_tag", "normal"),

    };
@@ -172,7 +174,8 @@ TEST_P(ChattyLogBufferTest, deduplication_liblog) { 


    std::vector<LogMessage> read_log_messages;

    std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));

    log_buffer_->FlushTo(test_writer.get(), 1, nullptr, nullptr);

    std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, kLogMaskAll);

    EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));



    std::vector<LogMessage> expected_log_messages = {

            make_message(0, 1234, 1),

logd/LogBuffer.h

+28 −10
Original line number Diff line number Diff line
@@ -25,6 +25,27 @@ 


#include "LogWriter.h"



// A mask to represent which log buffers a reader is watching, values are (1 << LOG_ID_MAIN), etc.

using LogMask = uint32_t;

constexpr uint32_t kLogMaskAll = 0xFFFFFFFF;



// State that a LogBuffer may want to persist across calls to FlushTo().

class FlushToState {

  public:

    FlushToState(uint64_t start, LogMask log_mask) : start_(start), log_mask_(log_mask) {}

    virtual ~FlushToState() {}



    uint64_t start() const { return start_; }

    void set_start(uint64_t start) { start_ = start; }



    LogMask log_mask() const { return log_mask_; }



  private:

    uint64_t start_;

    LogMask log_mask_;

};



// Enum for the return values of the `filter` function passed to FlushTo().

enum class FilterResult {

    kSkip,

    kStop,
@@ -39,12 +60,9 @@ class LogBuffer { 


    virtual int Log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid,

                    const char* msg, uint16_t len) = 0;

    // lastTid is an optional context to help detect if the last previous

    // valid message was from the same source so we can differentiate chatty

    // filter types (identical or expired)

    static const uint64_t FLUSH_ERROR = 0;

    virtual uint64_t FlushTo(LogWriter* writer, uint64_t start,

                             pid_t* last_tid,  // nullable



    virtual std::unique_ptr<FlushToState> CreateFlushToState(uint64_t start, LogMask log_mask) = 0;

    virtual bool FlushTo(LogWriter* writer, FlushToState& state,

                         const std::function<FilterResult(log_id_t log_id, pid_t pid,

                                                          uint64_t sequence, log_time realtime,

                                                          uint16_t dropped_count)>& filter) = 0;

logd/LogBufferTest.cpp

+38 −2
Original line number Diff line number Diff line
@@ -208,8 +208,9 @@ TEST_P(LogBufferTest, smoke) { 


    std::vector<LogMessage> read_log_messages;

    std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));

    uint64_t flush_result = log_buffer_->FlushTo(test_writer.get(), 1, nullptr, nullptr);

    EXPECT_EQ(1ULL, flush_result);

    std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, kLogMaskAll);

    EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));

    EXPECT_EQ(2ULL, flush_to_state->start());

    CompareLogMessages(log_messages, read_log_messages);

}
@@ -335,4 +336,39 @@ TEST_P(LogBufferTest, random_messages) { 
    CompareLogMessages(log_messages, read_log_messages);

}



TEST_P(LogBufferTest, read_last_sequence) {

    std::vector<LogMessage> log_messages = {

            {{.pid = 1, .tid = 2, .sec = 10000, .nsec = 20001, .lid = LOG_ID_MAIN, .uid = 0},

             "first"},

            {{.pid = 10, .tid = 2, .sec = 10000, .nsec = 20002, .lid = LOG_ID_MAIN, .uid = 0},

             "second"},

            {{.pid = 100, .tid = 2, .sec = 10000, .nsec = 20003, .lid = LOG_ID_MAIN, .uid = 0},

             "third"},

    };

    FixupMessages(&log_messages);

    LogMessages(log_messages);



    std::vector<LogMessage> read_log_messages;

    bool released = false;



    {

        auto lock = std::unique_lock{reader_list_.reader_threads_lock()};

        std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, &released));

        std::unique_ptr<LogReaderThread> log_reader(

                new LogReaderThread(log_buffer_.get(), &reader_list_, std::move(test_writer), true,

                                    0, ~0, 0, {}, 3, {}));

        reader_list_.reader_threads().emplace_back(std::move(log_reader));

    }



    while (!released) {

        usleep(5000);

    }

    {

        auto lock = std::unique_lock{reader_list_.reader_threads_lock()};

        EXPECT_EQ(0U, reader_list_.reader_threads().size());

    }

    std::vector<LogMessage> expected_log_messages = {log_messages.back()};

    CompareLogMessages(expected_log_messages, read_log_messages);

}



INSTANTIATE_TEST_CASE_P(LogBufferTests, LogBufferTest, testing::Values("chatty", "simple"));

logd/LogBufferTest.h

+1 −1
Original line number Diff line number Diff line
@@ -45,7 +45,7 @@ void FixupMessages(std::vector<LogMessage>* messages); 
class TestWriter : public LogWriter {

  public:

    TestWriter(std::vector<LogMessage>* msgs, bool* released)

        : LogWriter(0, true, true), msgs_(msgs), released_(released) {}

        : LogWriter(0, true), msgs_(msgs), released_(released) {}

    bool Write(const logger_entry& entry, const char* message) override {

        msgs_->emplace_back(LogMessage{entry, std::string(message, entry.len), false});

        return true;

logd/LogReader.cpp

+11 −16
Original line number Diff line number Diff line
@@ -45,11 +45,8 @@ static std::string SocketClientToName(SocketClient* client) { 


class SocketLogWriter : public LogWriter {

  public:

    SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged,

                    bool can_read_security_logs)

        : LogWriter(client->getUid(), privileged, can_read_security_logs),

          reader_(reader),

          client_(client) {}

    SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged)

        : LogWriter(client->getUid(), privileged), reader_(reader), client_(client) {}



    bool Write(const logger_entry& entry, const char* msg) override {

        struct iovec iovec[2];
@@ -162,25 +159,23 @@ bool LogReader::onDataAvailable(SocketClient* cli) { 


    bool privileged = clientHasLogCredentials(cli);

    bool can_read_security = CanReadSecurityLogs(cli);

    if (!can_read_security) {

        logMask &= ~(1 << LOG_ID_SECURITY);

    }



    std::unique_ptr<LogWriter> socket_log_writer(

            new SocketLogWriter(this, cli, privileged, can_read_security));

    std::unique_ptr<LogWriter> socket_log_writer(new SocketLogWriter(this, cli, privileged));



    uint64_t sequence = 1;

    // Convert realtime to sequence number

    if (start != log_time::EPOCH) {

        bool start_time_set = false;

        uint64_t last = sequence;

        auto log_find_start = [pid, logMask, start, &sequence, &start_time_set, &last](

                                      log_id_t element_log_id, pid_t element_pid,

                                      uint64_t element_sequence, log_time element_realtime,

                                      uint16_t) -> FilterResult {

        auto log_find_start = [pid, start, &sequence, &start_time_set, &last](

                                      log_id_t, pid_t element_pid, uint64_t element_sequence,

                                      log_time element_realtime, uint16_t) -> FilterResult {

            if (pid && pid != element_pid) {

                return FilterResult::kSkip;

            }

            if ((logMask & (1 << element_log_id)) == 0) {

                return FilterResult::kSkip;

            }

            if (start == element_realtime) {

                sequence = element_sequence;

                start_time_set = true;
@@ -195,8 +190,8 @@ bool LogReader::onDataAvailable(SocketClient* cli) { 
            }

            return FilterResult::kSkip;

        };



        log_buffer_->FlushTo(socket_log_writer.get(), sequence, nullptr, log_find_start);

        auto flush_to_state = log_buffer_->CreateFlushToState(sequence, logMask);

        log_buffer_->FlushTo(socket_log_writer.get(), *flush_to_state, log_find_start);



        if (!start_time_set) {

            if (nonBlock) {