doris/cloud/test/log_test.cpp

// Licensed to the Apache Software Foundation (ASF) under one
// or more contributor license agreements.  See the NOTICE file
// distributed with this work for additional information
// regarding copyright ownership.  The ASF licenses this file
// to you under the Apache License, Version 2.0 (the
// "License"); you may not use this file except in compliance
// with the License.  You may obtain a copy of the License at
//
//   http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing,
// software distributed under the License is distributed on an
// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
// KIND, either express or implied.  See the License for the
// specific language governing permissions and limitations
// under the License.

#include <bthread/bthread.h>
#include <glog/logging.h>
#include <gtest/gtest.h>

#include <cstring>
#include <fstream>
#include <random>
#include <regex>
#include <sstream>
#include <thread>

#include "common/config.h"
#include "common/logging.h"

using doris::cloud::AnnotateTag;

int main(int argc, char** argv) {
    if (!doris::cloud::init_glog("log_test")) {
        std::cerr << "failed to init glog" << std::endl;
        return -1;
    }
    ::testing::InitGoogleTest(&argc, argv);
    return RUN_ALL_TESTS();
}

TEST(LogTest, ConstructionTest) {
    // Heap allocation is disabled.
    // new AnnotateTag();

    // Arithmetics
    {
        char c = 0;
        bool b = false;
        int8_t i8 = 0;
        uint8_t u8 = 0;
        int16_t i16 = 0;
        uint16_t u16 = 0;
        int32_t i32 = 0;
        uint32_t u32 = 0;
        int64_t i64 = 0;
        uint64_t u64 = 0;

        AnnotateTag tag_char("char", c);
        AnnotateTag tag_bool("bool", b);
        AnnotateTag tag_i8("i8", i8);
        AnnotateTag tag_u8("u8", u8);
        AnnotateTag tag_i16("i16", i16);
        AnnotateTag tag_u16("u16", u16);
        AnnotateTag tag_i32("i32", i32);
        AnnotateTag tag_u32("u32", u32);
        AnnotateTag tag_i64("i64", i64);
        AnnotateTag tag_u64("u64", u64);
        LOG_INFO("hello");
    }

    // String literals.
    {
        const char* text = "hello";
        AnnotateTag tag_text("hello", text);
        LOG_INFO("hello");
    }

    // String view.
    {
        std::string test("abc");
        AnnotateTag tag_text("hello", std::string_view(test));
        LOG_INFO("hello");
    }

    // Const string.
    {
        const std::string test("abc");
        AnnotateTag tag_text("hello", test);
        LOG_INFO("hello");
    }
}

TEST(LogTest, ThreadTest) {
    // In pthread.
    {
        ASSERT_EQ(bthread_self(), 0);
        AnnotateTag tag("run_in_bthread", true);
        LOG_INFO("thread test");
    }

    // In bthread.
    {
        auto fn = +[](void*) -> void* {
            EXPECT_NE(bthread_self(), 0);
            AnnotateTag tag("run_in_bthread", true);
            LOG_INFO("thread test");
            return nullptr;
        };
        bthread_t tid;
        ASSERT_EQ(bthread_start_background(&tid, nullptr, fn, nullptr), 0);
        ASSERT_EQ(bthread_join(tid, nullptr), 0);
    }
}

// Test StdoutLogSink format output
TEST(LogTest, StdoutLogSinkFormatTest) {
    // Capture stdout
    testing::internal::CaptureStdout();

    // Create a test log sink and send a test message
    struct TestLogSink : google::LogSink {
        std::stringstream captured_output;

        void send(google::LogSeverity severity, const char* /*full_filename*/,
                  const char* base_filename, int line, const google::LogMessageTime& time,
                  const char* message, std::size_t message_len) override {
            char severity_char;
            switch (severity) {
            case google::GLOG_INFO:
                severity_char = 'I';
                break;
            case google::GLOG_WARNING:
                severity_char = 'W';
                break;
            case google::GLOG_ERROR:
                severity_char = 'E';
                break;
            case google::GLOG_FATAL:
                severity_char = 'F';
                break;
            default:
                severity_char = '?';
                break;
            }

            captured_output << std::setfill('0');
            captured_output << severity_char;
            captured_output << std::setw(4) << (time.year() + 1900) << std::setw(2)
                            << std::setfill('0') << (time.month() + 1) << std::setw(2)
                            << std::setfill('0') << time.day();
            captured_output << " " << std::setw(2) << std::setfill('0') << time.hour() << ":"
                            << std::setw(2) << std::setfill('0') << time.min() << ":"
                            << std::setw(2) << std::setfill('0') << time.sec() << "."
                            << std::setw(6) << std::setfill('0') << time.usec();
            captured_output << " " << std::setfill(' ') << std::setw(5) << getpid()
                            << std::setfill('0');
            captured_output << " " << base_filename << ":" << line << "] ";
            captured_output.write(message, message_len);
        }
    } test_sink;

    // Simulate a log message using current time
    google::LogMessageTime test_time;

    const char* test_message = "Test log message";
    test_sink.send(google::GLOG_INFO, "test_file.cpp", "test_file.cpp", 123, test_time,
                   test_message, strlen(test_message));

    std::string output = test_sink.captured_output.str();

    // Verify format pattern: I<YYYYMMDD> <HH:MM:SS>.<usec> <pid> test_file.cpp:123] Test log message
    // Check severity character
    EXPECT_EQ(output[0], 'I') << "Severity character incorrect: " << output;

    // Check date format (8 digits after 'I')
    std::regex date_pattern(R"(I\d{8}\s)");
    EXPECT_TRUE(std::regex_search(output, date_pattern)) << "Date format incorrect: " << output;

    // Check time format (HH:MM:SS.ffffff)
    std::regex time_pattern(R"(\d{2}:\d{2}:\d{2}\.\d{6})");
    EXPECT_TRUE(std::regex_search(output, time_pattern)) << "Time format incorrect: " << output;

    // Check file:line format
    EXPECT_TRUE(output.find("test_file.cpp:123]") != std::string::npos)
            << "File:line format incorrect: " << output;

    // Check message content
    EXPECT_TRUE(output.find("Test log message") != std::string::npos)
            << "Message not found: " << output;

    // Verify process ID is present (at least 1 digit followed by space and filename)
    std::regex pid_pattern(R"(\d+\s+test_file\.cpp)");
    EXPECT_TRUE(std::regex_search(output, pid_pattern)) << "Process ID not found: " << output;

    std::string captured = testing::internal::GetCapturedStdout();
}

// Test log initialization with different configurations
TEST(LogTest, LogInitializationTest) {
    // Test 1: Verify init_glog can be called multiple times safely
    EXPECT_TRUE(doris::cloud::init_glog("test_logger"));
    EXPECT_TRUE(doris::cloud::init_glog("test_logger")); // Should return true on second call

    // Test 2: Verify log level configuration
    // This test verifies that different log levels can be set
    std::string original_level = doris::cloud::config::log_level;

    // Note: We can't easily test the actual behavior without modifying global state,
    // but we can verify the configuration exists and init succeeds
    doris::cloud::config::log_level = "INFO";
    EXPECT_TRUE(doris::cloud::init_glog("test_info"));

    doris::cloud::config::log_level = "WARNING";
    EXPECT_TRUE(doris::cloud::init_glog("test_warn"));

    // Restore original level
    doris::cloud::config::log_level = original_level;
}

// Test log output with different severity levels
TEST(LogTest, LogSeverityTest) {
    // Test different log severity characters
    struct SeverityTestSink : google::LogSink {
        std::map<google::LogSeverity, char> severity_chars;

        void send(google::LogSeverity severity, const char* /*full_filename*/,
                  const char* /*base_filename*/, int /*line*/,
                  const google::LogMessageTime& /*time*/, const char* /*message*/,
                  std::size_t /*message_len*/) override {
            char severity_char;
            switch (severity) {
            case google::GLOG_INFO:
                severity_char = 'I';
                break;
            case google::GLOG_WARNING:
                severity_char = 'W';
                break;
            case google::GLOG_ERROR:
                severity_char = 'E';
                break;
            case google::GLOG_FATAL:
                severity_char = 'F';
                break;
            default:
                severity_char = '?';
                break;
            }
            severity_chars[severity] = severity_char;
        }
    } severity_sink;

    google::LogMessageTime test_time;
    severity_sink.send(google::GLOG_INFO, "", "", 1, test_time, "test", 4);
    severity_sink.send(google::GLOG_WARNING, "", "", 1, test_time, "test", 4);
    severity_sink.send(google::GLOG_ERROR, "", "", 1, test_time, "test", 4);

    EXPECT_EQ(severity_sink.severity_chars[google::GLOG_INFO], 'I');
    EXPECT_EQ(severity_sink.severity_chars[google::GLOG_WARNING], 'W');
    EXPECT_EQ(severity_sink.severity_chars[google::GLOG_ERROR], 'E');
}

// Test that log format matches expected pattern
TEST(LogTest, LogFormatPatternTest) {
    struct PatternTestSink : google::LogSink {
        std::string last_output;

        void send(google::LogSeverity severity, const char* /*full_filename*/,
                  const char* base_filename, int line, const google::LogMessageTime& time,
                  const char* message, std::size_t message_len) override {
            std::stringstream ss;
            char severity_char = 'I';
            switch (severity) {
            case google::GLOG_INFO:
                severity_char = 'I';
                break;
            case google::GLOG_WARNING:
                severity_char = 'W';
                break;
            case google::GLOG_ERROR:
                severity_char = 'E';
                break;
            case google::GLOG_FATAL:
                severity_char = 'F';
                break;
            default:
                severity_char = '?';
                break;
            }

            ss << severity_char;
            ss << std::setw(4) << std::setfill('0') << (time.year() + 1900) << std::setw(2)
               << (time.month() + 1) << std::setw(2) << time.day();
            ss << " " << std::setw(2) << std::setfill('0') << time.hour() << ":" << std::setw(2)
               << time.min() << ":" << std::setw(2) << time.sec() << "." << std::setw(6)
               << time.usec();
            ss << " " << std::setfill(' ') << std::setw(5) << getpid() << std::setfill('0');
            ss << " " << base_filename << ":" << line << "] ";
            ss.write(message, message_len);

            last_output = ss.str();
        }
    } pattern_sink;

    google::LogMessageTime test_time;

    pattern_sink.send(google::GLOG_INFO, "test.cpp", "test.cpp", 100, test_time, "Test message",
                      12);

    // Verify the pattern: I<YYYYMMDD> <HH:MM:SS>.<usec> <pid> test.cpp:100] Test message
    std::regex pattern(R"(I\d{8} \d{2}:\d{2}:\d{2}\.\d{6}\s+\d+\s+test\.cpp:100\]\s+Test message)");
    EXPECT_TRUE(std::regex_search(pattern_sink.last_output, pattern))
            << "Log format pattern mismatch. Got: " << pattern_sink.last_output;
}