
/*    Copyright 2013 10gen Inc.
 *
 *    Licensed 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.
 */

#define MONGO_LOG_DEFAULT_COMPONENT ::mongo::logger::LogComponent::kDefault

#include "mongo/platform/basic.h"

#include "mongo/logger/log_test.h"

#include <sstream>
#include <string>
#include <vector>

#include "mongo/logger/appender.h"
#include "mongo/logger/encoder.h"
#include "mongo/logger/log_component.h"
#include "mongo/logger/log_component_settings.h"
#include "mongo/logger/message_event_utf8_encoder.h"
#include "mongo/logger/message_log_domain.h"
#include "mongo/platform/compiler.h"
#include "mongo/unittest/unittest.h"
#include "mongo/util/log.h"
#include "mongo/util/mongoutils/str.h"

using namespace mongo::logger;

namespace mongo {
namespace {

typedef LogTest<MessageEventDetailsEncoder> LogTestDetailsEncoder;
typedef LogTest<MessageEventUnadornedEncoder> LogTestUnadornedEncoder;

TEST_F(LogTestUnadornedEncoder, logContext) {
    logContext("WHA!");
    ASSERT_EQUALS(_logLines.size(), 1U);
    ASSERT_NOT_EQUALS(_logLines[0].find("WHA!"), std::string::npos);

    // TODO(schwerin): Ensure that logContext rights a proper context to the log stream,
    // including the address of the logContext() function.
    // void const* logContextFn = reinterpret_cast<void const*>(logContext);
}

class CountAppender : public Appender<MessageEventEphemeral> {
public:
    CountAppender() : _count(0) {}
    virtual ~CountAppender() {}

    virtual Status append(const MessageEventEphemeral& event) {
        ++_count;
        return Status::OK();
    }

    int getCount() {
        return _count;
    }

private:
    int _count;
};

/** Simple tests for detaching appenders. */
TEST_F(LogTestUnadornedEncoder, DetachAppender) {
    MessageLogDomain::AppenderAutoPtr countAppender(new CountAppender);
    MessageLogDomain domain;

    // Appending to the domain before attaching the appender does not affect the appender.
    domain.append(MessageEventEphemeral(0ULL, LogSeverity::Log(), "", "1"));
    ASSERT_EQUALS(0, dynamic_cast<CountAppender*>(countAppender.get())->getCount());

    // Appending to the domain after attaching the appender does affect the appender.
    MessageLogDomain::AppenderHandle handle = domain.attachAppender(countAppender);
    domain.append(MessageEventEphemeral(0ULL, LogSeverity::Log(), "", "2"));
    countAppender = domain.detachAppender(handle);
    ASSERT_EQUALS(1, dynamic_cast<CountAppender*>(countAppender.get())->getCount());

    // Appending to the domain after detaching the appender does not affect the appender.
    domain.append(MessageEventEphemeral(0ULL, LogSeverity::Log(), "", "3"));
    ASSERT_EQUALS(1, dynamic_cast<CountAppender*>(countAppender.get())->getCount());
}

class A {
public:
    std::string toString() const {
        log() << "Golly!\n";
        return "Golly!";
    }
};

// Tests that logging while in the midst of logging produces two distinct log messages, with the
// inner log message appearing before the outer.
TEST_F(LogTestUnadornedEncoder, LogstreamBuilderReentrance) {
    log() << "Logging A() -- " << A() << " -- done!" << std::endl;
    ASSERT_EQUALS(2U, _logLines.size());
    ASSERT_EQUALS(std::string("Golly!\n"), _logLines[0]);
    ASSERT_EQUALS(std::string("Logging A() -- Golly! -- done!\n"), _logLines[1]);
}

//
// Instantiating this object is a basic test of static-initializer-time logging.
//
class B {
public:
    B() {
        log() << "Exercising initializer time logging.";
    }
} b;

// Constants for log component test cases.
const LogComponent componentDefault = LogComponent::kDefault;
const LogComponent componentA = LogComponent::kCommand;
const LogComponent componentB = LogComponent::kAccessControl;
const LogComponent componentC = LogComponent::kNetwork;
const LogComponent componentD = LogComponent::kStorage;
const LogComponent componentE = LogComponent::kJournal;

// No log component declared at file scope.
// Component severity configuration:
//     LogComponent::kDefault: 2
TEST_F(LogTestUnadornedEncoder, MongoLogMacroNoFileScopeLogComponent) {
    globalLogDomain()->setMinimumLoggedSeverity(LogSeverity::Debug(2));

    LOG(2) << "This is logged";
    LOG(3) << "This is not logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_EQUALS(std::string("This is logged\n"), _logLines[0]);

    // MONGO_LOG_COMPONENT
    _logLines.clear();
    MONGO_LOG_COMPONENT(2, componentA) << "This is logged";
    MONGO_LOG_COMPONENT(3, componentA) << "This is not logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_EQUALS(std::string("This is logged\n"), _logLines[0]);

    // MONGO_LOG_COMPONENT2
    _logLines.clear();
    MONGO_LOG_COMPONENT2(2, componentA, componentB) << "This is logged";
    MONGO_LOG_COMPONENT2(3, componentA, componentB) << "This is not logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_EQUALS(std::string("This is logged\n"), _logLines[0]);

    // MONGO_LOG_COMPONENT3
    _logLines.clear();
    MONGO_LOG_COMPONENT3(2, componentA, componentB, componentC) << "This is logged";
    MONGO_LOG_COMPONENT3(3, componentA, componentB, componentC) << "This is not logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_EQUALS(std::string("This is logged\n"), _logLines[0]);
}

//
// Component log level tests.
// The global log manager holds the component log level configuration for the global log domain.
// LOG() and MONGO_LOG_COMPONENT() macros in util/log.h determine at runtime if a log message
// should be written to the log domain.
//

TEST_F(LogTestUnadornedEncoder, LogComponentSettingsMinimumLogSeverity) {
    LogComponentSettings settings;
    ASSERT_TRUE(settings.hasMinimumLogSeverity(LogComponent::kDefault));
    ASSERT_TRUE(settings.getMinimumLogSeverity(LogComponent::kDefault) == LogSeverity::Log());
    for (int i = 0; i < int(LogComponent::kNumLogComponents); ++i) {
        LogComponent component = static_cast<LogComponent::Value>(i);
        if (component == LogComponent::kDefault) {
            continue;
        }
        ASSERT_FALSE(settings.hasMinimumLogSeverity(component));
    }

    // Override and clear minimum severity level.
    for (int i = 0; i < int(LogComponent::kNumLogComponents); ++i) {
        LogComponent component = static_cast<LogComponent::Value>(i);
        LogSeverity severity = LogSeverity::Debug(2);

        // Override severity level.
        settings.setMinimumLoggedSeverity(component, severity);
        ASSERT_TRUE(settings.hasMinimumLogSeverity(component));
        ASSERT_TRUE(settings.getMinimumLogSeverity(component) == severity);

        // Clear severity level.
        // Special case: when clearing LogComponent::kDefault, the corresponding
        //               severity level is set to default values (ie. Log()).
        settings.clearMinimumLoggedSeverity(component);
        if (component == LogComponent::kDefault) {
            ASSERT_TRUE(settings.hasMinimumLogSeverity(component));
            ASSERT_TRUE(settings.getMinimumLogSeverity(LogComponent::kDefault) ==
                        LogSeverity::Log());
        } else {
            ASSERT_FALSE(settings.hasMinimumLogSeverity(component));
        }
    }
}

// Test for shouldLog() when the minimum logged severity is set only for LogComponent::kDefault.
TEST_F(LogTestUnadornedEncoder, LogComponentSettingsShouldLogDefaultLogComponentOnly) {
    LogComponentSettings settings;

    // Initial log severity for LogComponent::kDefault is Log().
    ASSERT_TRUE(shouldLog(LogSeverity::Info()));
    ASSERT_TRUE(shouldLog(LogSeverity::Log()));
    ASSERT_FALSE(shouldLog(LogSeverity::Debug(1)));
    ASSERT_FALSE(shouldLog(LogSeverity::Debug(2)));

    // If any components are provided to shouldLog(), we should get the same outcome
    // because we have not configured any non-LogComponent::kDefault components.
    ASSERT_TRUE(settings.shouldLog(componentA, LogSeverity::Log()));
    ASSERT_FALSE(settings.shouldLog(componentA, LogSeverity::Debug(1)));

    // Set minimum logged severity so that Debug(1) messages are written to log domain.
    settings.setMinimumLoggedSeverity(LogComponent::kDefault, LogSeverity::Debug(1));
    logger::globalLogDomain()->setMinimumLoggedSeverity(LogComponent::kDefault,
                                                        LogSeverity::Debug(1));

    ASSERT_TRUE(shouldLog(LogSeverity::Info()));
    ASSERT_TRUE(shouldLog(LogSeverity::Log()));
    ASSERT_TRUE(shouldLog(LogSeverity::Debug(1)));
    ASSERT_FALSE(shouldLog(LogSeverity::Debug(2)));

    // Revert back.
    logger::globalLogDomain()->setMinimumLoggedSeverity(LogComponent::kDefault, LogSeverity::Log());

    // Same results when components are supplied to shouldLog().
    ASSERT_TRUE(settings.shouldLog(componentA, LogSeverity::Debug(1)));
    ASSERT_FALSE(settings.shouldLog(componentA, LogSeverity::Debug(2)));
}

// Test for shouldLog() when we have configured a single component.
// Also checks that severity level has been reverted to match LogComponent::kDefault
// after clearing level.
// Minimum severity levels:
// LogComponent::kDefault: 1
// componentA: 2
TEST_F(LogTestUnadornedEncoder, LogComponentSettingsShouldLogSingleComponent) {
    LogComponentSettings settings;

    settings.setMinimumLoggedSeverity(LogComponent::kDefault, LogSeverity::Debug(1));
    settings.setMinimumLoggedSeverity(componentA, LogSeverity::Debug(2));

    // Components for log message: componentA only.
    ASSERT_TRUE(settings.shouldLog(componentA, LogSeverity::Debug(2)));
    ASSERT_FALSE(settings.shouldLog(componentA, LogSeverity::Debug(3)));

    // Clear severity level for componentA and check shouldLog() again.
    settings.clearMinimumLoggedSeverity(componentA);
    ASSERT_TRUE(settings.shouldLog(componentA, LogSeverity::Debug(1)));
    ASSERT_FALSE(settings.shouldLog(componentA, LogSeverity::Debug(2)));

    // Test shouldLog() with global settings.
    logger::globalLogDomain()->setMinimumLoggedSeverity(LogComponent::kDefault,
                                                        LogSeverity::Debug(1));

    // Components for log message: LogComponent::kDefault only.
    ASSERT_TRUE(shouldLog(LogSeverity::Debug(1)));
    ASSERT_FALSE(shouldLog(LogSeverity::Debug(2)));

    logger::globalLogDomain()->setMinimumLoggedSeverity(LogComponent::kDefault, LogSeverity::Log());
}

// Test for shouldLog() when we have configured multiple components.
// Minimum severity levels:
// LogComponent::kDefault: 1
// componentA: 2
// componentB: 0
TEST_F(LogTestUnadornedEncoder, LogComponentSettingsShouldLogMultipleComponentsConfigured) {
    LogComponentSettings settings;

    settings.setMinimumLoggedSeverity(LogComponent::kDefault, LogSeverity::Debug(1));
    settings.setMinimumLoggedSeverity(componentA, LogSeverity::Debug(2));
    settings.setMinimumLoggedSeverity(componentB, LogSeverity::Log());

    // Components for log message: componentA only.
    ASSERT_TRUE(settings.shouldLog(componentA, LogSeverity::Debug(2)));
    ASSERT_FALSE(settings.shouldLog(componentA, LogSeverity::Debug(3)));

    // Components for log message: componentB only.
    ASSERT_TRUE(settings.shouldLog(componentB, LogSeverity::Log()));
    ASSERT_FALSE(settings.shouldLog(componentB, LogSeverity::Debug(1)));

    // Components for log message: componentC only.
    // Since a component-specific minimum severity is not configured for componentC,
    // shouldLog() falls back on LogComponent::kDefault.
    ASSERT_TRUE(settings.shouldLog(componentC, LogSeverity::Debug(1)));
    ASSERT_FALSE(settings.shouldLog(componentC, LogSeverity::Debug(2)));

    // Test shouldLog() with global settings.
    logger::globalLogDomain()->setMinimumLoggedSeverity(LogComponent::kDefault,
                                                        LogSeverity::Debug(1));


    // Components for log message: LogComponent::kDefault only.
    ASSERT_TRUE(shouldLog(LogSeverity::Debug(1)));
    ASSERT_FALSE(shouldLog(LogSeverity::Debug(2)));

    logger::globalLogDomain()->setMinimumLoggedSeverity(LogComponent::kDefault, LogSeverity::Log());
}

// Log component hierarchy.
TEST_F(LogTestUnadornedEncoder, LogComponentHierarchy) {
    // Parent component is not meaningful for kDefault and kNumLogComponents.
    ASSERT_EQUALS(LogComponent::kNumLogComponents, LogComponent(LogComponent::kDefault).parent());
    ASSERT_EQUALS(LogComponent::kNumLogComponents,
                  LogComponent(LogComponent::kNumLogComponents).parent());

    // Default -> ComponentD -> ComponentE
    ASSERT_EQUALS(LogComponent::kDefault, LogComponent(componentD).parent());
    ASSERT_EQUALS(componentD, LogComponent(componentE).parent());
    ASSERT_NOT_EQUALS(LogComponent::kDefault, LogComponent(componentE).parent());

    // Log components should inherit parent's log severity in settings.
    LogComponentSettings settings;
    settings.setMinimumLoggedSeverity(LogComponent::kDefault, LogSeverity::Debug(1));
    settings.setMinimumLoggedSeverity(componentD, LogSeverity::Debug(2));

    // componentE should inherit componentD's log severity.
    ASSERT_TRUE(settings.shouldLog(componentE, LogSeverity::Debug(2)));
    ASSERT_FALSE(settings.shouldLog(componentE, LogSeverity::Debug(3)));

    // Clearing parent's log severity - componentE should inherit from Default.
    settings.clearMinimumLoggedSeverity(componentD);
    ASSERT_TRUE(settings.shouldLog(componentE, LogSeverity::Debug(1)));
    ASSERT_FALSE(settings.shouldLog(componentE, LogSeverity::Debug(2)));
}

// Dotted name of component includes names of ancestors.
TEST_F(LogTestUnadornedEncoder, LogComponentDottedName) {
    // Default -> ComponentD -> ComponentE
    ASSERT_EQUALS(componentDefault.getShortName(),
                  LogComponent(LogComponent::kDefault).getDottedName());
    ASSERT_EQUALS(componentD.getShortName(), componentD.getDottedName());
    ASSERT_EQUALS(componentD.getShortName() + "." + componentE.getShortName(),
                  componentE.getDottedName());
}

// Log names of all components should have the same length.
TEST_F(LogTestUnadornedEncoder, LogComponentNameForLog) {
    size_t defaultNameForLogLength = componentDefault.getNameForLog().toString().length();
    ASSERT_NOT_EQUALS(0U, defaultNameForLogLength);
    for (int i = 0; i < int(LogComponent::kNumLogComponents); ++i) {
        LogComponent component = static_cast<LogComponent::Value>(i);
        ASSERT_EQUALS(defaultNameForLogLength, component.getNameForLog().toString().length());
    }
}

/**
 * Verifies that the encoded log line contains string.
 */
void testEncodedLogLine(const MessageEventEphemeral& event, const std::string& expectedSubstring) {
    MessageEventDetailsEncoder encoder;
    std::ostringstream os;
    ASSERT_TRUE(static_cast<bool>(encoder.encode(event, os)));
    std::string s = os.str();
    if (s.find(expectedSubstring) == std::string::npos) {
        FAIL() << "encoded log line does not contain substring \"" << expectedSubstring
               << "\". log line: " << s;
    }
}

// Log severity should always be logged as a single capital letter.
TEST_F(LogTestUnadornedEncoder, MessageEventDetailsEncoderLogSeverity) {
    Date_t d(curTimeMillis64());
    StringData ctx("WHAT", StringData::LiteralTag());
    StringData msg("HUH", StringData::LiteralTag());
    // Severe is indicated by (F)atal.
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Severe(), ctx, msg), " F ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Error(), ctx, msg), " E ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Warning(), ctx, msg), " W ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Info(), ctx, msg), " I ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Log(), ctx, msg), " I ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(0), ctx, msg), " I ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(1), ctx, msg), " D ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(2), ctx, msg), " D ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(3), ctx, msg), " D ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(4), ctx, msg), " D ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(5), ctx, msg), " D ");
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(100), ctx, msg), " D ");
    // Unknown severity.
    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Severe().moreSevere(), ctx, msg),
                       " U ");
}

// Non-default log component short name should always be logged.
TEST_F(LogTestUnadornedEncoder, MessageEventDetailsEncoderLogComponent) {
    Date_t d(curTimeMillis64());
    StringData ctx("WHAT", StringData::LiteralTag());
    StringData msg("HUH", StringData::LiteralTag());
    for (int i = 0; i < int(LogComponent::kNumLogComponents); ++i) {
        LogComponent component = static_cast<LogComponent::Value>(i);
        testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Info(), component, ctx, msg),
                           str::stream() << " I " << component.getNameForLog() << " [");
    }
}

// Tests pass through of log component:
//     log macros -> LogStreamBuilder -> MessageEventEphemeral -> MessageEventDetailsEncoder
TEST_F(LogTestDetailsEncoder, ) {
    globalLogDomain()->setMinimumLoggedSeverity(LogSeverity::Log());

    // Default log component short name should not appear in detailed log line.
    MONGO_LOG_COMPONENT(0, componentDefault) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(componentDefault.getNameForLog().toString()),
                      std::string::npos);

    // Non-default log component short name should appear in detailed log line.
    _logLines.clear();
    MONGO_LOG_COMPONENT(0, componentA) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(componentA.getNameForLog().toString()), std::string::npos);

    // MONGO_LOG_COMPONENT2 - only the first component is sent to LogStreamBuilder.
    _logLines.clear();
    MONGO_LOG_COMPONENT2(0, componentA, componentB) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(componentA.getNameForLog().toString()), std::string::npos);
    ASSERT_EQUALS(_logLines[0].find(componentB.getNameForLog().toString()), std::string::npos);

    // MONGO_LOG_COMPONENT3 - only the first component is sent to LogStreamBuilder.
    _logLines.clear();
    MONGO_LOG_COMPONENT3(0, componentA, componentB, componentC) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(componentA.getNameForLog().toString()), std::string::npos);
    ASSERT_EQUALS(_logLines[0].find(componentB.getNameForLog().toString()), std::string::npos);
    ASSERT_EQUALS(_logLines[0].find(componentC.getNameForLog().toString()), std::string::npos);
}

// Tests pass through of log component:
//     unconditional log functions -> LogStreamBuilder -> MessageEventEphemeral
//                                 -> MessageEventDetailsEncoder
TEST_F(LogTestDetailsEncoder, LogFunctions) {
    // severe() - no component specified.
    severe() << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F " << componentDefault.getNameForLog()),
                      std::string::npos);

    // severe() - with component.
    _logLines.clear();
    severe(componentA) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F " << componentA.getNameForLog()),
                      std::string::npos);

    // error() - no component specified.
    _logLines.clear();
    error() << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E " << componentDefault.getNameForLog()),
                      std::string::npos);

    // error() - with component.
    _logLines.clear();
    error(componentA) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E " << componentA.getNameForLog()),
                      std::string::npos);

    // warning() - no component specified.
    _logLines.clear();
    warning() << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W " << componentDefault.getNameForLog()),
                      std::string::npos);

    // warning() - with component.
    _logLines.clear();
    warning(componentA) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W " << componentA.getNameForLog()),
                      std::string::npos);

    // log() - no component specified.
    _logLines.clear();
    log() << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I " << componentDefault.getNameForLog()),
                      std::string::npos);

    // log() - with component.
    _logLines.clear();
    log(componentA) << "This is logged";
    ASSERT_EQUALS(1U, _logLines.size());
    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I " << componentA.getNameForLog()),
                      std::string::npos);
}

}  // namespace
}  // namespace mongo

int main(int argc, char** argv) {
    // Ignore the client_test main since we don't want background threads when running this
    // test as that creates races with the testing appender created above.

    ::testing::InitGoogleTest(&argc, argv);
    return RUN_ALL_TESTS();
}
