summaryrefslogtreecommitdiff
path: root/src/mongo/logv2
diff options
context:
space:
mode:
authorHenrik Edin <henrik.edin@mongodb.com>2020-03-02 14:52:46 -0500
committerEvergreen Agent <no-reply@evergreen.mongodb.com>2020-03-03 18:14:05 +0000
commit2803adc3ba76f87101d493cb940df4e0f53c7879 (patch)
tree73d5e0dbcf26bcff51fecc469b5e31d01c918585 /src/mongo/logv2
parenta68774045ce42d55e82236408bd9cf004c54d12a (diff)
downloadmongo-2803adc3ba76f87101d493cb940df4e0f53c7879.tar.gz
SERVER-46520 Add mechanism to emit uassert as part of a logv2 log statement
Diffstat (limited to 'src/mongo/logv2')
-rw-r--r--src/mongo/logv2/README.md15
-rw-r--r--src/mongo/logv2/attributes.cpp5
-rw-r--r--src/mongo/logv2/attributes.h1
-rw-r--r--src/mongo/logv2/bson_formatter.cpp17
-rw-r--r--src/mongo/logv2/bson_formatter.h3
-rw-r--r--src/mongo/logv2/log_detail.cpp8
-rw-r--r--src/mongo/logv2/log_domain_global.cpp23
-rw-r--r--src/mongo/logv2/log_manager.cpp5
-rw-r--r--src/mongo/logv2/log_options.h15
-rw-r--r--src/mongo/logv2/log_source.h8
-rw-r--r--src/mongo/logv2/log_test_v2.cpp43
-rw-r--r--src/mongo/logv2/plain_formatter.cpp19
-rw-r--r--src/mongo/logv2/plain_formatter.h1
-rw-r--r--src/mongo/logv2/uassert_sink.h55
14 files changed, 199 insertions, 19 deletions
diff --git a/src/mongo/logv2/README.md b/src/mongo/logv2/README.md
index 4f695d49742..a5578c83b0a 100644
--- a/src/mongo/logv2/README.md
+++ b/src/mongo/logv2/README.md
@@ -277,6 +277,21 @@ Text | JSON/BSON
---- | ---------
`(200 ns, 400 ns)` | `"samples": [{"durationNanos": 200}, {"durationNanos": 400}]`
+# Additional features
+
+## Combining uassert with log statement
+
+Code that emits a high severity log statement may also need to emit a `uassert` after the log. There is the `UserAssertAfterLog` helper that allows you to re-use the log statement to do the formatting required for the `uassert`. The reason string will be a plain text formatted log (replacement fields filled in format-string).
+
+##### Examples
+```
+LOGV2_ERROR_OPTIONS(1050, {UserAssertAfterLog(ErrorCodes::DataCorruptionDetected)}, "Data corruption detected for {recordId}, "recordId"_attr=RecordId(123456));
+```
+Would emit an `uassert` after performing the log that is equivalent to:
+```
+uasserted(ErrorCodes::DataCorruptionDetected, "Data corruption detected for RecordId(123456)");
+```
+
# Output formats
Desired log output format is set to mongod, mongos and the mongo shell using the `-logFormat` option. Available values are `text` and `json`. Currently text formatting is default.
diff --git a/src/mongo/logv2/attributes.cpp b/src/mongo/logv2/attributes.cpp
index f767f3ae94c..c53c030a988 100644
--- a/src/mongo/logv2/attributes.cpp
+++ b/src/mongo/logv2/attributes.cpp
@@ -83,6 +83,11 @@ const boost::log::attribute_name& truncation() {
return attr;
}
+const boost::log::attribute_name& userassert() {
+ static const boost::log::attribute_name attr("userassert");
+ return attr;
+}
+
} // namespace attributes
} // namespace logv2
} // namespace mongo
diff --git a/src/mongo/logv2/attributes.h b/src/mongo/logv2/attributes.h
index f39f24a95cd..8118faaaf0f 100644
--- a/src/mongo/logv2/attributes.h
+++ b/src/mongo/logv2/attributes.h
@@ -46,6 +46,7 @@ const boost::log::attribute_name& id();
const boost::log::attribute_name& message();
const boost::log::attribute_name& attributes();
const boost::log::attribute_name& truncation();
+const boost::log::attribute_name& userassert();
} // namespace attributes
} // namespace logv2
diff --git a/src/mongo/logv2/bson_formatter.cpp b/src/mongo/logv2/bson_formatter.cpp
index 88222e6a9d6..116f537273a 100644
--- a/src/mongo/logv2/bson_formatter.cpp
+++ b/src/mongo/logv2/bson_formatter.cpp
@@ -112,14 +112,12 @@ private:
};
} // namespace
-void BSONFormatter::operator()(boost::log::record_view const& rec,
- boost::log::formatting_ostream& strm) const {
+void BSONFormatter::operator()(boost::log::record_view const& rec, BSONObjBuilder& builder) const {
using boost::log::extract;
// Build a JSON object for the user attributes.
const auto& attrs = extract<TypeErasedAttributeStorage>(attributes::attributes(), rec).get();
- BSONObjBuilder builder;
builder.append(constants::kTimestampFieldName,
extract<Date_t>(attributes::timeStamp(), rec).get());
builder.append(constants::kSeverityFieldName,
@@ -140,10 +138,21 @@ void BSONFormatter::operator()(boost::log::record_view const& rec,
if (tags != LogTag::kNone) {
builder.append(constants::kTagsFieldName, tags.toBSONArray());
}
+}
- BSONObj obj = builder.obj();
+void BSONFormatter::operator()(boost::log::record_view const& rec,
+ boost::log::formatting_ostream& strm) const {
+ BSONObjBuilder builder;
+ operator()(rec, builder);
+ BSONObj obj = builder.done();
strm.write(obj.objdata(), obj.objsize());
}
+BSONObj BSONFormatter::operator()(boost::log::record_view const& rec) const {
+ BSONObjBuilder builder;
+ operator()(rec, builder);
+ return builder.obj();
+}
+
} // namespace logv2
} // namespace mongo
diff --git a/src/mongo/logv2/bson_formatter.h b/src/mongo/logv2/bson_formatter.h
index 0e9479d65b8..61053b1f15f 100644
--- a/src/mongo/logv2/bson_formatter.h
+++ b/src/mongo/logv2/bson_formatter.h
@@ -32,6 +32,7 @@
#include <boost/log/core/record_view.hpp>
#include <boost/log/utility/formatting_ostream_fwd.hpp>
+#include "mongo/bson/bsonobjbuilder.h"
#include "mongo/logv2/constants.h"
namespace mongo {
@@ -41,7 +42,9 @@ class BSONFormatter {
public:
BSONFormatter(const AtomicWord<int32_t>* maxAttributeSizeKB = nullptr) {}
+ void operator()(boost::log::record_view const& rec, BSONObjBuilder& builder) const;
void operator()(boost::log::record_view const& rec, boost::log::formatting_ostream& strm) const;
+ BSONObj operator()(boost::log::record_view const& rec) const;
};
} // namespace logv2
diff --git a/src/mongo/logv2/log_detail.cpp b/src/mongo/logv2/log_detail.cpp
index 4668ff2339f..71bc1fb9b5d 100644
--- a/src/mongo/logv2/log_detail.cpp
+++ b/src/mongo/logv2/log_detail.cpp
@@ -49,8 +49,12 @@ void doLogImpl(int32_t id,
TypeErasedAttributeStorage const& attrs) {
dassert(options.component() != LogComponent::kNumLogComponents);
auto& source = options.domain().internal().source();
- auto record =
- source.open_record(id, severity, options.component(), options.tags(), options.truncation());
+ auto record = source.open_record(id,
+ severity,
+ options.component(),
+ options.tags(),
+ options.truncation(),
+ options.uassertErrorCode());
if (record) {
record.attribute_values().insert(
attributes::message(),
diff --git a/src/mongo/logv2/log_domain_global.cpp b/src/mongo/logv2/log_domain_global.cpp
index 327c046da42..236f389f5ee 100644
--- a/src/mongo/logv2/log_domain_global.cpp
+++ b/src/mongo/logv2/log_domain_global.cpp
@@ -40,6 +40,7 @@
#include "mongo/logv2/shared_access_fstream.h"
#include "mongo/logv2/tagged_severity_filter.h"
#include "mongo/logv2/text_formatter.h"
+#include "mongo/logv2/uassert_sink.h"
#include <boost/core/null_deleter.hpp>
#include <boost/filesystem/operations.hpp>
@@ -54,13 +55,20 @@ void LogDomainGlobal::ConfigurationOptions::makeDisabled() {
}
struct LogDomainGlobal::Impl {
- typedef CompositeBackend<boost::log::sinks::text_ostream_backend, RamLogSink, RamLogSink>
+ typedef CompositeBackend<boost::log::sinks::text_ostream_backend,
+ RamLogSink,
+ RamLogSink,
+ UserAssertSink>
ConsoleBackend;
#ifndef _WIN32
- typedef CompositeBackend<boost::log::sinks::syslog_backend, RamLogSink, RamLogSink>
+ typedef CompositeBackend<boost::log::sinks::syslog_backend,
+ RamLogSink,
+ RamLogSink,
+ UserAssertSink>
SyslogBackend;
#endif
- typedef CompositeBackend<FileRotateSink, RamLogSink, RamLogSink> RotatableFileBackend;
+ typedef CompositeBackend<FileRotateSink, RamLogSink, RamLogSink, UserAssertSink>
+ RotatableFileBackend;
Impl(LogDomainGlobal& parent);
Status configure(LogDomainGlobal::ConfigurationOptions const& options);
@@ -87,7 +95,8 @@ LogDomainGlobal::Impl::Impl(LogDomainGlobal& parent) : _parent(parent) {
auto console = boost::make_shared<ConsoleBackend>(
boost::make_shared<boost::log::sinks::text_ostream_backend>(),
boost::make_shared<RamLogSink>(RamLog::get("global")),
- boost::make_shared<RamLogSink>(RamLog::get("startupWarnings")));
+ boost::make_shared<RamLogSink>(RamLog::get("startupWarnings")),
+ boost::make_shared<UserAssertSink>());
console->lockedBackend<0>()->add_stream(
boost::shared_ptr<std::ostream>(&Console::out(), boost::null_deleter()));
@@ -117,7 +126,8 @@ Status LogDomainGlobal::Impl::configure(LogDomainGlobal::ConfigurationOptions co
boost::log::sinks::syslog::make_facility(options.syslogFacility),
boost::log::keywords::use_impl = boost::log::sinks::syslog::native),
boost::make_shared<RamLogSink>(RamLog::get("global")),
- boost::make_shared<RamLogSink>(RamLog::get("startupWarnings")));
+ boost::make_shared<RamLogSink>(RamLog::get("startupWarnings")),
+ boost::make_shared<UserAssertSink>());
boost::log::sinks::syslog::custom_severity_mapping<LogSeverity> mapping(
attributes::severity());
@@ -158,7 +168,8 @@ Status LogDomainGlobal::Impl::configure(LogDomainGlobal::ConfigurationOptions co
auto backend = boost::make_shared<RotatableFileBackend>(
boost::make_shared<FileRotateSink>(),
boost::make_shared<RamLogSink>(RamLog::get("global")),
- boost::make_shared<RamLogSink>(RamLog::get("startupWarnings")));
+ boost::make_shared<RamLogSink>(RamLog::get("startupWarnings")),
+ boost::make_shared<UserAssertSink>());
Status ret = backend->lockedBackend<0>()->addFile(
options.filePath,
options.fileOpenMode == ConfigurationOptions::OpenMode::kAppend ? true : false);
diff --git a/src/mongo/logv2/log_manager.cpp b/src/mongo/logv2/log_manager.cpp
index b5fc193ace3..d4710dc4977 100644
--- a/src/mongo/logv2/log_manager.cpp
+++ b/src/mongo/logv2/log_manager.cpp
@@ -58,13 +58,18 @@ LogManager::LogManager() {
++depth;
// Try and log that we failed to log
if (depth == 1) {
+ std::exception_ptr ex = nullptr;
try {
throw;
+ } catch (const DBException&) {
+ ex = std::current_exception();
} catch (...) {
LOGV2(4638200,
"Exception during log, message not written to stream",
"exception"_attr = exceptionToStatus());
}
+ if (ex)
+ std::rethrow_exception(ex);
}
// Logging exceptions are fatal in debug builds. Guard ourselves from additional logging
diff --git a/src/mongo/logv2/log_options.h b/src/mongo/logv2/log_options.h
index fdd41307b43..d03a7bf274b 100644
--- a/src/mongo/logv2/log_options.h
+++ b/src/mongo/logv2/log_options.h
@@ -37,6 +37,13 @@
namespace mongo {
namespace logv2 {
+class UserAssertAfterLog {
+public:
+ explicit UserAssertAfterLog(ErrorCodes::Error code) : errorCode(code) {}
+
+ ErrorCodes::Error errorCode;
+};
+
class LogOptions {
public:
static LogOptions ensureValidComponent(LogOptions options, LogComponent component) {
@@ -54,6 +61,9 @@ public:
LogOptions(LogTruncation truncation) : _truncation(truncation) {}
+ LogOptions(UserAssertAfterLog uassertAfterLog)
+ : _userAssertErrorCode(uassertAfterLog.errorCode) {}
+
LogOptions(LogTag tags, LogTruncation truncation) : _tags(tags), _truncation(truncation) {}
LogOptions(LogComponent component, LogDomain* domain, LogTag tags)
@@ -78,11 +88,16 @@ public:
return _truncation;
}
+ ErrorCodes::Error uassertErrorCode() const {
+ return _userAssertErrorCode;
+ }
+
private:
LogDomain* _domain = &LogManager::global().getGlobalDomain();
LogTag _tags;
LogComponent _component = LogComponent::kAutomaticDetermination;
LogTruncation _truncation = constants::kDefaultTruncation;
+ ErrorCodes::Error _userAssertErrorCode = ErrorCodes::OK;
};
} // namespace logv2
diff --git a/src/mongo/logv2/log_source.h b/src/mongo/logv2/log_source.h
index 99269bcdba2..7e389bd4548 100644
--- a/src/mongo/logv2/log_source.h
+++ b/src/mongo/logv2/log_source.h
@@ -63,12 +63,14 @@ public:
_component(LogComponent::kDefault),
_tags(LogTag::kNone),
_truncation(constants::kDefaultTruncation),
+ _uassertErrorCode(ErrorCodes::OK),
_id(-1) {
add_attribute_unlocked(attributes::domain(), _domain);
add_attribute_unlocked(attributes::severity(), _severity);
add_attribute_unlocked(attributes::component(), _component);
add_attribute_unlocked(attributes::tags(), _tags);
add_attribute_unlocked(attributes::truncation(), _truncation);
+ add_attribute_unlocked(attributes::userassert(), _uassertErrorCode);
add_attribute_unlocked(attributes::id(), _id);
add_attribute_unlocked(attributes::timeStamp(), boost::log::attributes::make_function([]() {
return Date_t::now();
@@ -85,13 +87,15 @@ public:
LogSeverity severity,
LogComponent component,
LogTag tags,
- LogTruncation truncation) {
+ LogTruncation truncation,
+ ErrorCodes::Error userassertErrorCode) {
// Perform a quick check first
if (this->core()->get_logging_enabled()) {
_severity.set(severity);
_component.set(component);
_tags.set(tags);
_truncation.set(truncation);
+ _uassertErrorCode.set(userassertErrorCode);
_id.set(id);
return Base::open_record_unlocked();
} else
@@ -104,6 +108,7 @@ public:
_component.set(LogComponent::kDefault);
_tags.set(LogTag::kNone);
_truncation.set(constants::kDefaultTruncation);
+ _uassertErrorCode.set(ErrorCodes::OK);
_id.set(-1);
}
@@ -113,6 +118,7 @@ private:
boost::log::attributes::mutable_constant<LogComponent> _component;
boost::log::attributes::mutable_constant<LogTag> _tags;
boost::log::attributes::mutable_constant<LogTruncation> _truncation;
+ boost::log::attributes::mutable_constant<ErrorCodes::Error> _uassertErrorCode;
boost::log::attributes::mutable_constant<int32_t> _id;
};
diff --git a/src/mongo/logv2/log_test_v2.cpp b/src/mongo/logv2/log_test_v2.cpp
index f0ac7e3218f..0bda9fcc28d 100644
--- a/src/mongo/logv2/log_test_v2.cpp
+++ b/src/mongo/logv2/log_test_v2.cpp
@@ -44,6 +44,7 @@
#include "mongo/bson/oid.h"
#include "mongo/logv2/bson_formatter.h"
#include "mongo/logv2/component_settings_filter.h"
+#include "mongo/logv2/composite_backend.h"
#include "mongo/logv2/constants.h"
#include "mongo/logv2/json_formatter.h"
#include "mongo/logv2/log.h"
@@ -52,6 +53,7 @@
#include "mongo/logv2/plain_formatter.h"
#include "mongo/logv2/ramlog_sink.h"
#include "mongo/logv2/text_formatter.h"
+#include "mongo/logv2/uassert_sink.h"
#include "mongo/platform/decimal128.h"
#include "mongo/stdx/thread.h"
#include "mongo/unittest/temp_dir.h"
@@ -1515,6 +1517,47 @@ TEST_F(LogTestV2, FileLogging) {
ASSERT(before_rotation == after_rotation);
}
+TEST_F(LogTestV2, UserAssert) {
+ std::vector<std::string> lines;
+
+ using backend_t = CompositeBackend<LogCaptureBackend, UserAssertSink>;
+
+ auto sink = boost::make_shared<boost::log::sinks::synchronous_sink<backend_t>>(
+ boost::make_shared<backend_t>(boost::make_shared<LogCaptureBackend>(lines),
+ boost::make_shared<UserAssertSink>()));
+
+ sink->set_filter(ComponentSettingsFilter(LogManager::global().getGlobalDomain(),
+ LogManager::global().getGlobalSettings()));
+ sink->set_formatter(PlainFormatter());
+ attach(sink);
+
+ bool gotUassert = false;
+ try {
+ LOGV2_OPTIONS(4652000, {UserAssertAfterLog(ErrorCodes::BadValue)}, "uasserting log");
+ } catch (const DBException& ex) {
+ ASSERT_EQUALS(ex.code(), ErrorCodes::BadValue);
+ ASSERT_EQUALS(ex.reason(), "uasserting log");
+ ASSERT_EQUALS(lines.back(), ex.reason());
+ gotUassert = true;
+ }
+ ASSERT(gotUassert);
+
+
+ bool gotUassertWithReplacementFields = false;
+ try {
+ LOGV2_OPTIONS(4652001,
+ {UserAssertAfterLog(ErrorCodes::BadValue)},
+ "uasserting log {name}",
+ "name"_attr = 1);
+ } catch (const DBException& ex) {
+ ASSERT_EQUALS(ex.code(), ErrorCodes::BadValue);
+ ASSERT_EQUALS(ex.reason(), "uasserting log 1");
+ ASSERT_EQUALS(lines.back(), ex.reason());
+ gotUassertWithReplacementFields = true;
+ }
+ ASSERT(gotUassertWithReplacementFields);
+}
+
} // namespace
} // namespace logv2
} // namespace mongo
diff --git a/src/mongo/logv2/plain_formatter.cpp b/src/mongo/logv2/plain_formatter.cpp
index 8fd8d635fda..00edef93491 100644
--- a/src/mongo/logv2/plain_formatter.cpp
+++ b/src/mongo/logv2/plain_formatter.cpp
@@ -135,7 +135,7 @@ private:
} // namespace
void PlainFormatter::operator()(boost::log::record_view const& rec,
- boost::log::formatting_ostream& strm) const {
+ fmt::memory_buffer& buffer) const {
using namespace boost::log;
StringData message = extract<StringData>(attributes::message(), rec).get();
@@ -144,7 +144,6 @@ void PlainFormatter::operator()(boost::log::record_view const& rec,
TextValueExtractor extractor;
extractor.args.reserve(attrs.size());
attrs.apply(extractor);
- fmt::memory_buffer buffer;
fmt::vformat_to(
buffer,
to_string_view(message),
@@ -157,10 +156,18 @@ void PlainFormatter::operator()(boost::log::record_view const& rec,
else
attributeMaxSize = constants::kDefaultMaxAttributeOutputSizeKB * 1024;
}
- StringData dataToWrite(buffer.data(), std::min(attributeMaxSize, buffer.size()));
- if (dataToWrite.endsWith("\n"_sd))
- dataToWrite = StringData(dataToWrite.rawData(), dataToWrite.size() - 1);
- strm.write(dataToWrite.rawData(), dataToWrite.size());
+
+ buffer.resize(std::min(attributeMaxSize, buffer.size()));
+ if (StringData sd(buffer.data(), buffer.size()); sd.endsWith("\n"_sd))
+ buffer.resize(buffer.size() - 1);
+}
+
+void PlainFormatter::operator()(boost::log::record_view const& rec,
+ boost::log::formatting_ostream& strm) const {
+ using namespace boost::log;
+ fmt::memory_buffer buffer;
+ operator()(rec, buffer);
+ strm.write(buffer.data(), buffer.size());
}
} // namespace mongo::logv2
diff --git a/src/mongo/logv2/plain_formatter.h b/src/mongo/logv2/plain_formatter.h
index 6860c2dda10..bc74dd0a810 100644
--- a/src/mongo/logv2/plain_formatter.h
+++ b/src/mongo/logv2/plain_formatter.h
@@ -43,6 +43,7 @@ public:
PlainFormatter(const AtomicWord<int32_t>* maxAttributeSizeKB = nullptr)
: _maxAttributeSizeKB(maxAttributeSizeKB) {}
+ void operator()(boost::log::record_view const& rec, fmt::memory_buffer& buffer) const;
void operator()(boost::log::record_view const& rec, boost::log::formatting_ostream& strm) const;
private:
diff --git a/src/mongo/logv2/uassert_sink.h b/src/mongo/logv2/uassert_sink.h
new file mode 100644
index 00000000000..61aeb67625b
--- /dev/null
+++ b/src/mongo/logv2/uassert_sink.h
@@ -0,0 +1,55 @@
+/**
+ * Copyright (C) 2020-present MongoDB, Inc.
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the Server Side Public License, version 1,
+ * as published by MongoDB, Inc.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * Server Side Public License for more details.
+ *
+ * You should have received a copy of the Server Side Public License
+ * along with this program. If not, see
+ * <http://www.mongodb.com/licensing/server-side-public-license>.
+ *
+ * As a special exception, the copyright holders give permission to link the
+ * code of portions of this program with the OpenSSL library under certain
+ * conditions as described in each individual source file and distribute
+ * linked combinations including the program with the OpenSSL library. You
+ * must comply with the Server Side Public License in all respects for
+ * all of the code used other than as permitted herein. If you modify file(s)
+ * with this exception, you may extend this exception to your version of the
+ * file(s), but you are not obligated to do so. If you do not wish to do so,
+ * delete this exception statement from your version. If you delete this
+ * exception statement from all source files in the program, then also delete
+ * it in the license file.
+ */
+
+#pragma once
+
+#include <boost/log/attributes/attribute_value_set.hpp>
+#include <boost/log/attributes/value_extraction.hpp>
+#include <boost/log/core/record_view.hpp>
+#include <boost/log/sinks.hpp>
+
+#include "mongo/logv2/bson_formatter.h"
+#include "mongo/util/assert_util.h"
+
+namespace mongo::logv2 {
+class UserAssertSink
+ : public boost::log::sinks::
+ basic_formatted_sink_backend<char, boost::log::sinks::concurrent_feeding> {
+public:
+ void consume(boost::log::record_view const& rec, string_type const& formatted_string) {
+ using boost::log::extract;
+ ErrorCodes::Error code = extract<ErrorCodes::Error>(attributes::userassert(), rec).get();
+ if (code != ErrorCodes::OK) {
+ fmt::memory_buffer buffer;
+ PlainFormatter()(rec, buffer);
+ uasserted(code, StringData(buffer.data(), buffer.size()));
+ }
+ }
+};
+} // namespace mongo::logv2