1
0
Fork 0

(devel) add bool option rocksdb.debug-logging to easily enable rocksdb logging (#6016)

This commit is contained in:
Matthew Von-Maszewski 2018-07-30 08:30:20 -04:00 committed by Jan
parent cda104475f
commit 9f880dd529
2 changed files with 41 additions and 25 deletions

View File

@ -1,7 +1,7 @@
//////////////////////////////////////////////////////////////////////////////// ////////////////////////////////////////////////////////////////////////////////
/// DISCLAIMER /// DISCLAIMER
/// ///
/// Copyright 2014-2017 ArangoDB GmbH, Cologne, Germany /// Copyright 2014-2018 ArangoDB GmbH, Cologne, Germany
/// Copyright 2004-2014 triAGENS GmbH, Cologne, Germany /// Copyright 2004-2014 triAGENS GmbH, Cologne, Germany
/// ///
/// Licensed under the Apache License, Version 2.0 (the "License"); /// Licensed under the Apache License, Version 2.0 (the "License");
@ -142,7 +142,8 @@ RocksDBEngine::RocksDBEngine(application_features::ApplicationServer* server)
_pruneWaitTimeInitial(180.0), _pruneWaitTimeInitial(180.0),
_releasedTick(0), _releasedTick(0),
_syncInterval(100), _syncInterval(100),
_useThrottle(true) { _useThrottle(true),
_debugLogging(false) {
startsAfter("BasicsPhase"); startsAfter("BasicsPhase");
#ifdef _WIN32 #ifdef _WIN32
@ -230,7 +231,7 @@ void RocksDBEngine::collectOptions(
"when this number of " "when this number of "
"operations is reached in a transaction", "operations is reached in a transaction",
new UInt64Parameter(&_intermediateCommitCount)); new UInt64Parameter(&_intermediateCommitCount));
options->addOption("--rocksdb.sync-interval", options->addOption("--rocksdb.sync-interval",
"interval for automatic, non-requested disk syncs (in milliseconds, use 0 to turn automatic syncing off)", "interval for automatic, non-requested disk syncs (in milliseconds, use 0 to turn automatic syncing off)",
new UInt64Parameter(&_syncInterval)); new UInt64Parameter(&_syncInterval));
@ -238,7 +239,7 @@ void RocksDBEngine::collectOptions(
options->addOption("--rocksdb.wal-file-timeout", options->addOption("--rocksdb.wal-file-timeout",
"timeout after which unused WAL files are deleted", "timeout after which unused WAL files are deleted",
new DoubleParameter(&_pruneWaitTime)); new DoubleParameter(&_pruneWaitTime));
options->addHiddenOption("--rocksdb.wal-file-timeout-initial", options->addHiddenOption("--rocksdb.wal-file-timeout-initial",
"initial timeout after which unused WAL files deletion kicks in after server start", "initial timeout after which unused WAL files deletion kicks in after server start",
new DoubleParameter(&_pruneWaitTimeInitial)); new DoubleParameter(&_pruneWaitTimeInitial));
@ -247,6 +248,10 @@ void RocksDBEngine::collectOptions(
"enable write-throttling", "enable write-throttling",
new BooleanParameter(&_useThrottle)); new BooleanParameter(&_useThrottle));
options->addHiddenOption("--rocksdb.debug-logging",
"true to enable rocksdb debug logging",
new BooleanParameter(&_debugLogging));
#ifdef USE_ENTERPRISE #ifdef USE_ENTERPRISE
collectEnterpriseOptions(options); collectEnterpriseOptions(options);
#endif #endif
@ -260,7 +265,7 @@ void RocksDBEngine::validateOptions(
#ifdef USE_ENTERPRISE #ifdef USE_ENTERPRISE
validateEnterpriseOptions(options); validateEnterpriseOptions(options);
#endif #endif
if (_syncInterval > 0 && _syncInterval < minSyncInterval) { if (_syncInterval > 0 && _syncInterval < minSyncInterval) {
// _syncInterval = 0 means turned off! // _syncInterval = 0 means turned off!
LOG_TOPIC(FATAL, arangodb::Logger::ROCKSDB) << "invalid value for --rocksdb.sync-interval. Please use a value " LOG_TOPIC(FATAL, arangodb::Logger::ROCKSDB) << "invalid value for --rocksdb.sync-interval. Please use a value "
@ -268,7 +273,7 @@ void RocksDBEngine::validateOptions(
FATAL_ERROR_EXIT(); FATAL_ERROR_EXIT();
} }
#ifdef _WIN32 #ifdef _WIN32
if (_syncInterval > 0) { if (_syncInterval > 0) {
LOG_TOPIC(WARN, arangodb::Logger::ROCKSDB) << "automatic syncing of RocksDB WAL via background thread is not supported on this platform"; LOG_TOPIC(WARN, arangodb::Logger::ROCKSDB) << "automatic syncing of RocksDB WAL via background thread is not supported on this platform";
} }
@ -414,10 +419,18 @@ void RocksDBEngine::start() {
// intentionally set the RocksDB logger to warning because it will // intentionally set the RocksDB logger to warning because it will
// log lots of things otherwise // log lots of things otherwise
_options.info_log_level = rocksdb::InfoLogLevel::ERROR_LEVEL; if (!_debugLogging) {
_options.info_log_level = rocksdb::InfoLogLevel::ERROR_LEVEL;
} else {
_options.info_log_level = rocksdb::InfoLogLevel::DEBUG_LEVEL;
} // else
auto logger = std::make_shared<RocksDBLogger>(_options.info_log_level); auto logger = std::make_shared<RocksDBLogger>(_options.info_log_level);
_options.info_log = logger; _options.info_log = logger;
logger->disable();
if (!_debugLogging) {
logger->disable();
} // if
if (opts->_enableStatistics) { if (opts->_enableStatistics) {
_options.statistics = rocksdb::CreateDBStatistics(); _options.statistics = rocksdb::CreateDBStatistics();
@ -616,8 +629,8 @@ void RocksDBEngine::start() {
// only enable logger after RocksDB start // only enable logger after RocksDB start
logger->enable(); logger->enable();
if (_syncInterval > 0) { if (_syncInterval > 0) {
_syncThread.reset( _syncThread.reset(
new RocksDBSyncThread(this, std::chrono::milliseconds(_syncInterval))); new RocksDBSyncThread(this, std::chrono::milliseconds(_syncInterval)));
if (!_syncThread->start()) { if (!_syncThread->start()) {
@ -681,7 +694,7 @@ void RocksDBEngine::stop() {
} }
_backgroundThread.reset(); _backgroundThread.reset();
} }
if (_syncThread) { if (_syncThread) {
// _syncThread may be a nullptr, in case automatic syncing is turned off // _syncThread may be a nullptr, in case automatic syncing is turned off
_syncThread->beginShutdown(); _syncThread->beginShutdown();
@ -1363,14 +1376,14 @@ Result RocksDBEngine::createView(
view.toVelocyPack(props, true, true); view.toVelocyPack(props, true, true);
props.close(); props.close();
RocksDBValue const value = RocksDBValue::View(props.slice()); RocksDBValue const value = RocksDBValue::View(props.slice());
// Write marker + key into RocksDB inside one batch // Write marker + key into RocksDB inside one batch
batch.PutLogData(logValue.slice()); batch.PutLogData(logValue.slice());
batch.Put(RocksDBColumnFamily::definitions(), key.string(), value.string()); batch.Put(RocksDBColumnFamily::definitions(), key.string(), value.string());
auto res = _db->Write(wo, &batch); auto res = _db->Write(wo, &batch);
return rocksutils::convertStatus(res); return rocksutils::convertStatus(res);
} }
arangodb::Result RocksDBEngine::dropView( arangodb::Result RocksDBEngine::dropView(
TRI_vocbase_t& vocbase, TRI_vocbase_t& vocbase,
LogicalView& view LogicalView& view
@ -1416,15 +1429,15 @@ Result RocksDBEngine::changeView(
RocksDBKey key; RocksDBKey key;
key.constructView(vocbase.id(), view.id()); key.constructView(vocbase.id(), view.id());
VPackBuilder infoBuilder; VPackBuilder infoBuilder;
infoBuilder.openObject(); infoBuilder.openObject();
view.toVelocyPack(infoBuilder, true, true); view.toVelocyPack(infoBuilder, true, true);
infoBuilder.close(); infoBuilder.close();
RocksDBLogValue log = RocksDBLogValue::ViewChange(vocbase.id(), view.id()); RocksDBLogValue log = RocksDBLogValue::ViewChange(vocbase.id(), view.id());
RocksDBValue const value = RocksDBValue::View(infoBuilder.slice()); RocksDBValue const value = RocksDBValue::View(infoBuilder.slice());
rocksdb::WriteBatch batch; rocksdb::WriteBatch batch;
rocksdb::WriteOptions wo; // TODO: check which options would make sense rocksdb::WriteOptions wo; // TODO: check which options would make sense
rocksdb::Status s; rocksdb::Status s;
@ -1529,7 +1542,7 @@ Result RocksDBEngine::flushWal(bool waitForSync, bool waitForCollector,
// _syncThread may be a nullptr, in case automatic syncing is turned off // _syncThread may be a nullptr, in case automatic syncing is turned off
_syncThread->syncWal(); _syncThread->syncWal();
} }
if (waitForCollector) { if (waitForCollector) {
rocksdb::FlushOptions flushOptions; rocksdb::FlushOptions flushOptions;
flushOptions.wait = waitForSync; flushOptions.wait = waitForSync;
@ -1674,7 +1687,7 @@ Result RocksDBEngine::dropDatabase(TRI_voc_tick_t id) {
return; return;
} }
}); });
if (res.fail()) { if (res.fail()) {
return res; return res;
} }
@ -1688,7 +1701,7 @@ Result RocksDBEngine::dropDatabase(TRI_voc_tick_t id) {
iterateBounds(bounds, [&](rocksdb::Iterator* it) { iterateBounds(bounds, [&](rocksdb::Iterator* it) {
RocksDBKey key(it->key()); RocksDBKey key(it->key());
RocksDBValue value(RocksDBEntryType::Collection, it->value()); RocksDBValue value(RocksDBEntryType::Collection, it->value());
// remove indexes // remove indexes
VPackSlice indexes = value.slice().get("indexes"); VPackSlice indexes = value.slice().get("indexes");
if (indexes.isArray()) { if (indexes.isArray()) {
@ -1739,7 +1752,7 @@ Result RocksDBEngine::dropDatabase(TRI_voc_tick_t id) {
rocksutils::countKeyRange(rocksutils::globalRocksDB(), bounds, true); rocksutils::countKeyRange(rocksutils::globalRocksDB(), bounds, true);
#endif #endif
}); });
if (res.fail()) { if (res.fail()) {
return res; return res;
} }

View File

@ -1,7 +1,7 @@
//////////////////////////////////////////////////////////////////////////////// ////////////////////////////////////////////////////////////////////////////////
/// DISCLAIMER /// DISCLAIMER
/// ///
/// Copyright 2014-2016 ArangoDB GmbH, Cologne, Germany /// Copyright 2014-2018 ArangoDB GmbH, Cologne, Germany
/// Copyright 2004-2014 triAGENS GmbH, Cologne, Germany /// Copyright 2004-2014 triAGENS GmbH, Cologne, Germany
/// ///
/// Licensed under the Apache License, Version 2.0 (the "License"); /// Licensed under the Apache License, Version 2.0 (the "License");
@ -378,7 +378,7 @@ class RocksDBEngine final : public StorageEngine {
public: public:
static std::string const EngineName; static std::string const EngineName;
static std::string const FeatureName; static std::string const FeatureName;
rocksdb::Options const& rocksDBOptions() const { rocksdb::Options const& rocksDBOptions() const {
return _options; return _options;
} }
@ -394,7 +394,7 @@ class RocksDBEngine final : public StorageEngine {
TRI_ASSERT(_replicationManager); TRI_ASSERT(_replicationManager);
return _replicationManager.get(); return _replicationManager.get();
} }
/// @brief returns a pointer to the sync thread /// @brief returns a pointer to the sync thread
/// note: returns a nullptr if automatic syncing is turned off! /// note: returns a nullptr if automatic syncing is turned off!
RocksDBSyncThread* syncThread() const { RocksDBSyncThread* syncThread() const {
@ -447,14 +447,14 @@ class RocksDBEngine final : public StorageEngine {
// number of seconds to wait before an obsolete WAL file is actually pruned // number of seconds to wait before an obsolete WAL file is actually pruned
double _pruneWaitTime; double _pruneWaitTime;
// number of seconds to wait initially after server start before WAL file deletion // number of seconds to wait initially after server start before WAL file deletion
// kicks in // kicks in
double _pruneWaitTimeInitial; double _pruneWaitTimeInitial;
// do not release walfiles containing writes later than this // do not release walfiles containing writes later than this
TRI_voc_tick_t _releasedTick; TRI_voc_tick_t _releasedTick;
/// Background thread handling WAL syncing /// Background thread handling WAL syncing
/// note: this is a nullptr if automatic syncing is turned off! /// note: this is a nullptr if automatic syncing is turned off!
std::unique_ptr<RocksDBSyncThread> _syncThread; std::unique_ptr<RocksDBSyncThread> _syncThread;
@ -465,6 +465,9 @@ class RocksDBEngine final : public StorageEngine {
// use write-throttling // use write-throttling
bool _useThrottle; bool _useThrottle;
// activate rocksdb's debug logging
bool _debugLogging;
// code to pace ingest rate of writes to reduce chances of compactions getting // code to pace ingest rate of writes to reduce chances of compactions getting
// too far behind and blocking incoming writes // too far behind and blocking incoming writes
// (will only be set if _useThrottle is true) // (will only be set if _useThrottle is true)