From a118945b5709a5c7c1684b23f2fee743c425dc53 Mon Sep 17 00:00:00 2001 From: Samy Lanka Date: Wed, 15 Mar 2023 21:15:04 +0000 Subject: Revert "SERVER-71490: Move steady state replication constraint relaxation opCounters to logs" This reverts commit fca10770f9698b4c1a43197bdc3ff7576c6e8bf2. --- src/mongo/db/repl/SConscript | 15 ---- src/mongo/db/repl/oplog.cpp | 85 ++++----------------- src/mongo/db/repl/oplog.h | 11 --- .../db/repl/oplog_applier_impl_test_fixture.cpp | 28 +------ src/mongo/db/repl/oplog_applier_utils.cpp | 8 -- .../db/repl/oplog_constraint_violation_logger.cpp | 89 ---------------------- .../db/repl/oplog_constraint_violation_logger.h | 86 --------------------- 7 files changed, 16 insertions(+), 306 deletions(-) delete mode 100644 src/mongo/db/repl/oplog_constraint_violation_logger.cpp delete mode 100644 src/mongo/db/repl/oplog_constraint_violation_logger.h (limited to 'src/mongo/db') diff --git a/src/mongo/db/repl/SConscript b/src/mongo/db/repl/SConscript index 983ba98b1e2..ec1d257cf25 100644 --- a/src/mongo/db/repl/SConscript +++ b/src/mongo/db/repl/SConscript @@ -52,16 +52,6 @@ env.Library( ], ) -env.Library( - target='oplog_constraint_violation_logger', - source=[ - 'oplog_constraint_violation_logger.cpp', - ], - LIBDEPS_PRIVATE=[ - '$BUILD_DIR/mongo/base', - ], -) - env.Library( target='oplog', source=[ @@ -78,7 +68,6 @@ env.Library( '$BUILD_DIR/mongo/base', '$BUILD_DIR/mongo/db/catalog/catalog_helpers', '$BUILD_DIR/mongo/db/catalog/collection_crud', - '$BUILD_DIR/mongo/db/catalog/health_log_interface', '$BUILD_DIR/mongo/db/catalog/import_collection_oplog_entry', '$BUILD_DIR/mongo/db/catalog/index_build_oplog_entry', '$BUILD_DIR/mongo/db/catalog/local_oplog_info', @@ -109,7 +98,6 @@ env.Library( '$BUILD_DIR/mongo/util/namespace_string_database_name_util', 'dbcheck', 'image_collection_entry', - 'oplog_constraint_violation_logger', 'repl_coordinator_interface', 'repl_server_parameters', 'repl_settings', @@ -1623,8 +1611,6 @@ if wiredtiger: LIBDEPS=[ '$BUILD_DIR/mongo/db/catalog/database_holder', '$BUILD_DIR/mongo/db/catalog/document_validation', - '$BUILD_DIR/mongo/db/catalog/health_log', - '$BUILD_DIR/mongo/db/catalog/health_log_interface', '$BUILD_DIR/mongo/db/index_builds_coordinator_interface', '$BUILD_DIR/mongo/db/multitenancy', '$BUILD_DIR/mongo/db/service_context_d_test_fixture', @@ -1743,7 +1729,6 @@ if wiredtiger: '$BUILD_DIR/mongo/db/auth/authmocks', '$BUILD_DIR/mongo/db/auth/authorization_manager_global', '$BUILD_DIR/mongo/db/catalog/catalog_helpers', - '$BUILD_DIR/mongo/db/catalog/health_log', '$BUILD_DIR/mongo/db/change_stream_pre_images_collection_manager', '$BUILD_DIR/mongo/db/commands/mongod_fcv', '$BUILD_DIR/mongo/db/commands/txn_cmd_request', diff --git a/src/mongo/db/repl/oplog.cpp b/src/mongo/db/repl/oplog.cpp index bb50e416599..33a096072e9 100644 --- a/src/mongo/db/repl/oplog.cpp +++ b/src/mongo/db/repl/oplog.cpp @@ -51,7 +51,6 @@ #include "mongo/db/catalog/drop_collection.h" #include "mongo/db/catalog/drop_database.h" #include "mongo/db/catalog/drop_indexes.h" -#include "mongo/db/catalog/health_log_interface.h" #include "mongo/db/catalog/import_collection_oplog_entry_gen.h" #include "mongo/db/catalog/local_oplog_info.h" #include "mongo/db/catalog/multi_index_block.h" @@ -1362,36 +1361,6 @@ StatusWith OplogApplication::parseMode(const std::string MONGO_UNREACHABLE; } -// Logger for oplog constraint violations. -OplogConstraintViolationLogger* oplogConstraintViolationLogger; - -MONGO_INITIALIZER(CreateOplogConstraintViolationLogger)(InitializerContext* context) { - oplogConstraintViolationLogger = new OplogConstraintViolationLogger(); -} - -void logOplogConstraintViolation(OperationContext* opCtx, - const NamespaceString& nss, - OplogConstraintViolationEnum type, - const std::string& operation, - const BSONObj& opObj, - boost::optional status) { - // Log the violation. - oplogConstraintViolationLogger->logViolationIfReady(type, opObj, status); - - // Write a new entry to the health log. - HealthLogEntry entry; - entry.setNss(nss); - entry.setTimestamp(Date_t::now()); - // Oplog constraint violations should always be marked as warning. - entry.setSeverity(SeverityEnum::Warning); - entry.setScope(ScopeEnum::Document); - entry.setMsg(toString(type)); - entry.setOperation(operation); - entry.setData(opObj); - - HealthLogInterface::get(opCtx->getServiceContext())->log(entry); -} - // @return failure status if an update should have happened and the document DNE. // See replset initial sync code. Status applyOperation_inlock(OperationContext* opCtx, @@ -1681,17 +1650,7 @@ Status applyOperation_inlock(OperationContext* opCtx, return status; } if (mode == OplogApplication::Mode::kSecondary) { - const auto& opObj = redact(op.toBSONForLogging()); - opCounters->gotInsertOnExistingDoc(); - logOplogConstraintViolation( - opCtx, - op.getNss(), - OplogConstraintViolationEnum::kInsertOnExistingDoc, - "insert", - opObj, - boost::none /* status */); - if (oplogApplicationEnforcesSteadyStateConstraints) { return status; } @@ -1912,15 +1871,10 @@ Status applyOperation_inlock(OperationContext* opCtx, !ur.upsertedId.isEmpty() && !(collection && collection->isCapped())) { // This indicates we upconverted an update to an upsert, and it did indeed // upsert. In steady state mode this is unexpected. - const auto& opObj = redact(op.toBSONForLogging()); - + LOGV2_WARNING(2170001, + "update needed to be converted to upsert", + "op"_attr = redact(op.toBSONForLogging())); opCounters->gotUpdateOnMissingDoc(); - logOplogConstraintViolation(opCtx, - op.getNss(), - OplogConstraintViolationEnum::kUpdateOnMissingDoc, - "update", - opObj, - boost::none /* status */); // We shouldn't be doing upserts in secondary mode when enforcing steady state // constraints. @@ -2043,6 +1997,11 @@ Status applyOperation_inlock(OperationContext* opCtx, // documents at all times. if (result.nDeleted == 0 && mode == OplogApplication::Mode::kSecondary && !requestNss.isChangeStreamPreImagesCollection()) { + LOGV2_WARNING(2170002, + "Applied a delete which did not delete anything in steady state " + "replication", + "op"_attr = redact(op.toBSONForLogging())); + // In FCV 4.4, each node is responsible for deleting the excess documents in // capped collections. This implies that capped deletes may not be synchronized // between nodes at times. When upgraded to FCV 5.0, the primary will generate @@ -2055,25 +2014,11 @@ Status applyOperation_inlock(OperationContext* opCtx, // capped collections when oplog application is enforcing steady state // constraints. bool isCapped = false; - const auto& opObj = redact(op.toBSONForLogging()); if (collection) { isCapped = collection->isCapped(); opCounters->gotDeleteWasEmpty(); - logOplogConstraintViolation(opCtx, - op.getNss(), - OplogConstraintViolationEnum::kDeleteWasEmpty, - "delete", - opObj, - boost::none /* status */); } else { opCounters->gotDeleteFromMissingNamespace(); - logOplogConstraintViolation( - opCtx, - op.getNss(), - OplogConstraintViolationEnum::kDeleteOnMissingNs, - "delete", - opObj, - boost::none /* status */); } if (!isCapped) { @@ -2350,16 +2295,12 @@ Status applyCommand_inlock(OperationContext* opCtx, if (mode == OplogApplication::Mode::kSecondary && status.code() != ErrorCodes::IndexNotFound) { - const auto& opObj = redact(op->toBSONForLogging()); - + LOGV2_WARNING(2170000, + "Acceptable error during oplog application", + "db"_attr = nss.db(), + "error"_attr = status, + "oplogEntry"_attr = redact(op->toBSONForLogging())); opCounters->gotAcceptableErrorInCommand(); - logOplogConstraintViolation( - opCtx, - op->getNss(), - OplogConstraintViolationEnum::kAcceptableErrorInCommand, - "command", - opObj, - status); } else { LOGV2_DEBUG(51776, 1, diff --git a/src/mongo/db/repl/oplog.h b/src/mongo/db/repl/oplog.h index d9a3710112e..33dab887243 100644 --- a/src/mongo/db/repl/oplog.h +++ b/src/mongo/db/repl/oplog.h @@ -37,7 +37,6 @@ #include "mongo/bson/bsonobj.h" #include "mongo/bson/timestamp.h" #include "mongo/db/catalog/collection_options.h" -#include "mongo/db/repl/oplog_constraint_violation_logger.h" #include "mongo/db/repl/oplog_entry.h" #include "mongo/db/repl/oplog_entry_or_grouped_inserts.h" #include "mongo/db/repl/optime.h" @@ -202,16 +201,6 @@ inline std::ostream& operator<<(std::ostream& s, OplogApplication::Mode mode) { return (s << OplogApplication::modeToString(mode)); } -/** - * Logs an oplog constraint violation and writes an entry into the health log. - */ -void logOplogConstraintViolation(OperationContext* opCtx, - const NamespaceString& nss, - OplogConstraintViolationEnum type, - const std::string& operation, - const BSONObj& opObj, - boost::optional status); - /** * Used for applying from an oplog entry or grouped inserts. * @param opOrGroupedInserts a single oplog entry or grouped inserts to be applied. diff --git a/src/mongo/db/repl/oplog_applier_impl_test_fixture.cpp b/src/mongo/db/repl/oplog_applier_impl_test_fixture.cpp index e9ddd34d944..3a7f642bb85 100644 --- a/src/mongo/db/repl/oplog_applier_impl_test_fixture.cpp +++ b/src/mongo/db/repl/oplog_applier_impl_test_fixture.cpp @@ -31,8 +31,6 @@ #include "mongo/db/catalog/database_holder.h" #include "mongo/db/catalog/document_validation.h" -#include "mongo/db/catalog/health_log.h" -#include "mongo/db/catalog/health_log_interface.h" #include "mongo/db/concurrency/exception_util.h" #include "mongo/db/curop.h" #include "mongo/db/db_raii.h" @@ -197,13 +195,9 @@ void OplogApplierImplTest::setUp() { // This is necessary to generate ghost timestamps for index builds that are not 0, since 0 is an // invalid timestamp. VectorClockMutable::get(_opCtx.get())->tickClusterTimeTo(LogicalTime(Timestamp(1, 0))); - - HealthLogInterface::set(serviceContext, std::make_unique()); - HealthLogInterface::get(serviceContext)->startup(); } void OplogApplierImplTest::tearDown() { - HealthLogInterface::get(serviceContext)->shutdown(); _opCtx.reset(); _consistencyMarkers = {}; DropPendingCollectionReaper::set(serviceContext, {}); @@ -238,7 +232,6 @@ void OplogApplierImplTest::_testApplyOplogEntryOrGroupedInsertsCrudOperation( bool expectedApplyOpCalled) { bool applyOpCalled = false; - // auto testOpCtx = _opCtx.get(); auto checkOpCtx = [&targetNss](OperationContext* opCtx) { ASSERT_TRUE(opCtx); ASSERT_TRUE(opCtx->lockState()->isDbLockedForMode(targetNss.dbName(), MODE_IX)); @@ -250,14 +243,9 @@ void OplogApplierImplTest::_testApplyOplogEntryOrGroupedInsertsCrudOperation( _opObserver->onInsertsFn = [&](OperationContext* opCtx, const NamespaceString& nss, const std::vector& docs) { - // Other threads may be calling into the opObserver. Only assert if we are writing to - // the target ns, otherwise skip these asserts. - if (targetNss != nss) { - return Status::OK(); - } - applyOpCalled = true; checkOpCtx(opCtx); + ASSERT_EQUALS(targetNss, nss); ASSERT_EQUALS(1U, docs.size()); // For upserts we don't know the intended value of the document. if (op.getOpType() == repl::OpTypeEnum::kInsert) { @@ -270,28 +258,18 @@ void OplogApplierImplTest::_testApplyOplogEntryOrGroupedInsertsCrudOperation( const CollectionPtr& coll, StmtId stmtId, const OplogDeleteEntryArgs& args) { - // Other threads may be calling into the opObserver. Only assert if we are writing to - // the target ns, otherwise skip these asserts. - if (targetNss != coll->ns()) { - return Status::OK(); - } - applyOpCalled = true; checkOpCtx(opCtx); + ASSERT_EQUALS(targetNss, coll->ns()); ASSERT(args.deletedDoc); ASSERT_BSONOBJ_EQ(op.getObject(), *(args.deletedDoc)); return Status::OK(); }; _opObserver->onUpdateFn = [&](OperationContext* opCtx, const OplogUpdateEntryArgs& args) { - // Other threads may be calling into the opObserver. Only assert if we are writing to - // the target ns, otherwise skip these asserts. - if (targetNss != args.coll->ns()) { - return Status::OK(); - } - applyOpCalled = true; checkOpCtx(opCtx); + ASSERT_EQUALS(targetNss, args.coll->ns()); return Status::OK(); }; diff --git a/src/mongo/db/repl/oplog_applier_utils.cpp b/src/mongo/db/repl/oplog_applier_utils.cpp index 8e3ab8c1a5e..2861c7e877d 100644 --- a/src/mongo/db/repl/oplog_applier_utils.cpp +++ b/src/mongo/db/repl/oplog_applier_utils.cpp @@ -417,15 +417,7 @@ Status OplogApplierUtils::applyOplogEntryOrGroupedInsertsCommon( !oplogApplicationEnforcesSteadyStateConstraints && oplogApplicationMode == OplogApplication::Mode::kSecondary) { if (opCounters) { - const auto& opObj = redact(op->toBSONForLogging()); opCounters->gotDeleteFromMissingNamespace(); - logOplogConstraintViolation( - opCtx, - op->getNss(), - OplogConstraintViolationEnum::kDeleteOnMissingNs, - "delete", - opObj, - boost::none /* status */); } return Status::OK(); } diff --git a/src/mongo/db/repl/oplog_constraint_violation_logger.cpp b/src/mongo/db/repl/oplog_constraint_violation_logger.cpp deleted file mode 100644 index dd06f1c3dee..00000000000 --- a/src/mongo/db/repl/oplog_constraint_violation_logger.cpp +++ /dev/null @@ -1,89 +0,0 @@ -/** - * Copyright (C) 2023-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 - * . - * - * 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. - */ - -#include "mongo/db/repl/oplog_constraint_violation_logger.h" - -#define MONGO_LOGV2_DEFAULT_COMPONENT ::mongo::logv2::LogComponent::kReplication - -namespace mongo { -namespace repl { - -// Default interval set to 10 minutes. -const Seconds OplogConstraintViolationLogger::kPeriodicLogTimeout(60 * 10); - -StringData toString(OplogConstraintViolationEnum type) { - switch (type) { - case OplogConstraintViolationEnum::kInsertOnExistingDoc: - return kInsertOnExistingDocMsg; - case OplogConstraintViolationEnum::kUpdateOnMissingDoc: - return kUpdateOnMissingDocMsg; - case OplogConstraintViolationEnum::kDeleteWasEmpty: - return kDeleteWasEmptyMsg; - case OplogConstraintViolationEnum::kDeleteOnMissingNs: - return kDeleteOnMissingNs; - case OplogConstraintViolationEnum::kAcceptableErrorInCommand: - return kAcceptableErrorInCommand; - default: - return ""; - } -} - -void OplogConstraintViolationLogger::logViolationIfReady(OplogConstraintViolationEnum type, - const BSONObj& obj, - boost::optional status) { - const auto index = static_cast(type); - - stdx::lock_guard lk(_mutex); - const auto lastLog = _lastLogTimes[index]; - const auto now = Date_t::now(); - - if (now < lastLog + OplogConstraintViolationLogger::kPeriodicLogTimeout) { - // We have logged this violation already within the last 10 minutes. - return; - } - - if (!status) { - LOGV2_WARNING(7149000, - "Potential replication constraint violation during steady state replication", - "msg"_attr = toString(type), - "obj"_attr = obj); - } else { - LOGV2_WARNING(7149001, - "Potential replication constraint violation during steady state replication", - "msg"_attr = toString(type), - "obj"_attr = obj, - "status"_attr = *status); - } - - // Update the last log time to now. - _lastLogTimes[index] = now; -} - -} // namespace repl -} // namespace mongo diff --git a/src/mongo/db/repl/oplog_constraint_violation_logger.h b/src/mongo/db/repl/oplog_constraint_violation_logger.h deleted file mode 100644 index 326b98a5d4b..00000000000 --- a/src/mongo/db/repl/oplog_constraint_violation_logger.h +++ /dev/null @@ -1,86 +0,0 @@ -/** - * Copyright (C) 2023-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 - * . - * - * 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 - -#include "mongo/base/status.h" -#include "mongo/bson/bsonobj.h" -#include "mongo/logv2/log.h" -#include "mongo/platform/mutex.h" -#include "mongo/util/time_support.h" - -namespace mongo { -namespace repl { - -static constexpr StringData kInsertOnExistingDocMsg = "attempted to insert on existing doc"_sd; -static constexpr StringData kUpdateOnMissingDocMsg = - "ran update as upsert and failed to match any documents"_sd; -static constexpr StringData kDeleteWasEmptyMsg = "applied a delete that did not delete anything"_sd; -static constexpr StringData kDeleteOnMissingNs = "applied a delete on missing namespace"_sd; -static constexpr StringData kAcceptableErrorInCommand = - "received an acceptable error during oplog application"_sd; - -enum class OplogConstraintViolationEnum { - kInsertOnExistingDoc = 0, - kUpdateOnMissingDoc, - kDeleteWasEmpty, - kDeleteOnMissingNs, - kAcceptableErrorInCommand, - NUM_VIOLATION_TYPES, -}; - -// Returns a string describing the constraint violation of the given type. -StringData toString(OplogConstraintViolationEnum type); - -/** - * Logs oplog constraint violation occurrences. - * - * To avoid flooding the logs if continuous oplog constraint violations occur, we will only log - * once every 10 minutes per each oplog constraint violation type. - */ -class OplogConstraintViolationLogger { -public: - // Minimum period of time before logging another warning log message, set to 10min. - static const Seconds kPeriodicLogTimeout; - - void logViolationIfReady(OplogConstraintViolationEnum type, - const BSONObj& obj, - boost::optional status); - -private: - mutable Mutex _mutex = MONGO_MAKE_LATCH("OplogConstraintViolationLogger::mutex"); - - std::vector _lastLogTimes = std::vector( - static_cast(OplogConstraintViolationEnum::NUM_VIOLATION_TYPES)); // (M) -}; - -} // namespace repl -} // namespace mongo -- cgit v1.2.1