diff --git a/Code/GraphMol/Deprotect/Deprotect.cpp b/Code/GraphMol/Deprotect/Deprotect.cpp index cbf319937..8ca62901d 100644 --- a/Code/GraphMol/Deprotect/Deprotect.cpp +++ b/Code/GraphMol/Deprotect/Deprotect.cpp @@ -126,7 +126,7 @@ std::unique_ptr deprotect( for (auto &prods : deprotect.rxn->runReactant(m, 0)) { m = prods[0]; try { - RDLog::BlockLogs blocker; + RDLog::LogStateSetter blocker; MolOps::sanitizeMol(*dynamic_cast(m.get())); } catch (MolSanitizeException &) { continue; @@ -164,7 +164,7 @@ bool deprotectInPlace(RWMol &mol, bool changes = deprotect.rxn->runReactant(mol); if (changes) { try { - RDLog::BlockLogs blocker; + RDLog::LogStateSetter blocker; MolOps::sanitizeMol(mol); } catch (MolSanitizeException &) { continue; diff --git a/Code/GraphMol/ForceFieldHelpers/CrystalFF/TorsionPreferences.cpp b/Code/GraphMol/ForceFieldHelpers/CrystalFF/TorsionPreferences.cpp index fdb0b97c7..a9dead701 100644 --- a/Code/GraphMol/ForceFieldHelpers/CrystalFF/TorsionPreferences.cpp +++ b/Code/GraphMol/ForceFieldHelpers/CrystalFF/TorsionPreferences.cpp @@ -160,6 +160,8 @@ void getExperimentalTorsions(const RDKit::ROMol &mol, CrystalFFDetails &details, throw ValueErrorException("molecule has no atoms"); } + RDLog::LogStateSetter logs( + RDLog::RDLoggerList({rdInfoLog, rdErrorLog, rdWarningLog})); // check that vectors are empty details.expTorsionAtoms.clear(); details.expTorsionAngles.clear(); diff --git a/Code/GraphMol/MolDraw2D/MolDraw2D.cpp b/Code/GraphMol/MolDraw2D/MolDraw2D.cpp index 4c5f0df87..75a2e68c5 100644 --- a/Code/GraphMol/MolDraw2D/MolDraw2D.cpp +++ b/Code/GraphMol/MolDraw2D/MolDraw2D.cpp @@ -900,7 +900,7 @@ void MolDraw2D::makeReactionDrawMol( if (drawOptions().prepareMolsBeforeDrawing) { mol.updatePropertyCache(false); try { - RDLog::BlockLogs blocker; + RDLog::LogStateSetter blocker; MolOps::Kekulize(mol, false); // kekulize, but keep the aromatic flags! } catch (const MolSanitizeException &) { // don't need to do anything diff --git a/Code/GraphMol/MolEnumerator/LinkNode.cpp b/Code/GraphMol/MolEnumerator/LinkNode.cpp index ae5c0a90f..a1735c231 100644 --- a/Code/GraphMol/MolEnumerator/LinkNode.cpp +++ b/Code/GraphMol/MolEnumerator/LinkNode.cpp @@ -151,7 +151,7 @@ std::unique_ptr LinkNodeOp::operator()( ROMOL_SPTR reactant(new ROMol(*res)); std::vector ps; { - RDLog::BlockLogs blocker; + RDLog::LogStateSetter blocker; ps = rxn->runReactant(reactant, 0); } ASSERT_INVARIANT(!ps.empty(), "no products from reaction"); diff --git a/Code/GraphMol/MolStandardize/testNormalize.cpp b/Code/GraphMol/MolStandardize/testNormalize.cpp index d65045f43..91aa3422d 100644 --- a/Code/GraphMol/MolStandardize/testNormalize.cpp +++ b/Code/GraphMol/MolStandardize/testNormalize.cpp @@ -455,6 +455,8 @@ Azide to N=N+=N- [N:2]=[N:3]#[N:4]>>[N:2]=[N+:3]=[N-:4] Broken azide to N=N+=N- [N:2]=[N:3]=[N:4]>>[NH0:2]=[NH0+:3]=[NH0-:4])DATA"; std::stringstream azideNormalizationsStream(azideNormalizations); std::stringstream captureLog; + auto ostate = rdInfoLog->df_enabled; + rdInfoLog->df_enabled = true; rdInfoLog->SetTee(captureLog); Normalizer nn(azideNormalizationsStream, 200); const std::string brokenAzideSmi = "CN=[N+]=[NH-]"; @@ -470,6 +472,7 @@ Broken azide to N=N+=N- [N:2]=[N:3]=[N:4]>>[NH0:2]=[NH0+:3]=[NH0-:4])DATA"; ++count; } } + rdInfoLog->df_enabled = ostate; TEST_ASSERT(count == 1); BOOST_LOG(rdInfoLog) << "Finished" << std::endl; } @@ -479,12 +482,15 @@ void testGithub3460() { "Normalization rule incorrectly matches sulfones" << std::endl; std::stringstream captureLog; + auto ostate = rdInfoLog->df_enabled; + rdInfoLog->df_enabled = true; rdInfoLog->SetTee(captureLog); Normalizer nn; auto mol = "[O-][S+]1Nc2c(Cl)cc(Cl)c3c(Cl)cc(Cl)c(c23)N1"_smiles; TEST_ASSERT(mol); ROMOL_SPTR normalized(nn.normalize(*mol)); rdInfoLog->ClearTee(); + rdInfoLog->df_enabled = ostate; auto logged = captureLog.str(); TEST_ASSERT(logged.find("Running Normalizer") != std::string::npos); TEST_ASSERT(logged.find("Rule applied: C/S+NtoC/S=N+") == std::string::npos); @@ -509,9 +515,12 @@ void testGithub4281() { auto mol = "Cn1c(=O)c2nc[nH][n+](=O)c2n(C)c1=O"_smiles; std::stringstream captureLog; rdInfoLog->SetTee(captureLog); + auto ostate = rdInfoLog->df_enabled; + rdInfoLog->df_enabled = true; Normalizer nn; std::unique_ptr normalized(nn.normalize(*mol)); rdInfoLog->ClearTee(); + rdInfoLog->df_enabled = ostate; auto logged = captureLog.str(); TEST_ASSERT(logged.find("FAILED sanitizeMol") == std::string::npos); } diff --git a/Code/GraphMol/RGroupDecomposition/RGroupDecompData.h b/Code/GraphMol/RGroupDecomposition/RGroupDecompData.h index 1e7593958..7c4899a8e 100644 --- a/Code/GraphMol/RGroupDecomposition/RGroupDecompData.h +++ b/Code/GraphMol/RGroupDecomposition/RGroupDecompData.h @@ -404,7 +404,7 @@ struct RGroupDecompData { addAtoms(mol, atomsToAdd); if (params.removeHydrogensPostMatch) { - RDLog::BlockLogs blocker; + RDLog::LogStateSetter blocker; bool implicitOnly = false; bool updateExplicitCount = false; bool sanitize = false; diff --git a/Code/RDBoost/Wrap/RDBase.cpp b/Code/RDBoost/Wrap/RDBase.cpp index 32c885329..04fe4f609 100644 --- a/Code/RDBoost/Wrap/RDBase.cpp +++ b/Code/RDBoost/Wrap/RDBase.cpp @@ -319,7 +319,7 @@ BOOST_PYTHON_MODULE(rdBase) { python_streambuf_wrapper::wrap(); python_ostream_wrapper::wrap(); - python::class_( + python::class_( "BlockLogs", "Temporarily block logs from outputting while this instance is in " "scope."); diff --git a/Code/RDGeneral/CMakeLists.txt b/Code/RDGeneral/CMakeLists.txt index 82ef14df5..f6fd861ef 100644 --- a/Code/RDGeneral/CMakeLists.txt +++ b/Code/RDGeneral/CMakeLists.txt @@ -80,4 +80,7 @@ rdkit_test(testConcurrentQueue testConcurrentQueue.cpp LINK_LIBRARIES RDGeneral) endif(RDK_BUILD_THREADSAFE_SSS) rdkit_catch_test(dictTestsCatch catch_dict.cpp catch_main.cpp + LINK_LIBRARIES RDGeneral ) + +rdkit_catch_test(logTestsCatch catch_logs.cpp catch_main.cpp LINK_LIBRARIES RDGeneral ) \ No newline at end of file diff --git a/Code/RDGeneral/RDLog.cpp b/Code/RDGeneral/RDLog.cpp index 214148044..0758e6897 100644 --- a/Code/RDGeneral/RDLog.cpp +++ b/Code/RDGeneral/RDLog.cpp @@ -1,6 +1,5 @@ -// $Id$ // -// Copyright (C) 2005-2010 Greg Landrum and Rational Discovery LLC +// Copyright (C) 2005-2022 Greg Landrum and other RDKit contributors // // @@ All Rights Reserved @@ // This file is part of the RDKit. @@ -23,7 +22,37 @@ RDLogger rdInfoLog = nullptr; RDLogger rdErrorLog = nullptr; RDLogger rdWarningLog = nullptr; RDLogger rdStatusLog = nullptr; +namespace RDLog { +LogStateSetter::LogStateSetter() { + std::vector allLogs = {rdAppLog, rdDebugLog, rdInfoLog, + rdErrorLog, rdWarningLog, rdStatusLog}; + for (auto i = 0u; i < allLogs.size(); ++i) { + if (allLogs[i] && allLogs[i]->df_enabled) { + d_origState |= 1 << i; + allLogs[i]->df_enabled = false; + } + } +} + +LogStateSetter::LogStateSetter(RDLoggerList toEnable) : LogStateSetter() { + for (auto &log : toEnable) { + if (log) { + log->df_enabled = true; + } + } +} + +LogStateSetter::~LogStateSetter() { + std::vector allLogs = {rdAppLog, rdDebugLog, rdInfoLog, + rdErrorLog, rdWarningLog, rdStatusLog}; + for (auto i = 0u; i < allLogs.size(); ++i) { + if (allLogs[i]) { + allLogs[i]->df_enabled = d_origState & 1 << i; + } + } +} +} // namespace RDLog namespace boost { namespace logging { @@ -77,17 +106,15 @@ void disable_logs(const std::string &arg) { }; bool is_log_enabled(RDLogger log) { - if (log && log.get() != nullptr) { - if (log->df_enabled) { - return true; - } + if (log && log->df_enabled) { + return true; } return false; } void get_log_status(std::ostream &ss, const std::string &name, RDLogger log) { ss << name << ":"; - if (log && log.get() != nullptr) { + if (log) { if (log->df_enabled) { ss << "enabled"; } else { @@ -116,7 +143,9 @@ std::string log_status() { namespace RDLog { void InitLogs() { rdDebugLog = std::make_shared(&std::cerr); + rdDebugLog->df_enabled = false; rdInfoLog = std::make_shared(&std::cout); + rdInfoLog->df_enabled = false; rdWarningLog = std::make_shared(&std::cerr); rdErrorLog = std::make_shared(&std::cerr); } diff --git a/Code/RDGeneral/RDLog.h b/Code/RDGeneral/RDLog.h index a5151c8ae..568257676 100644 --- a/Code/RDGeneral/RDLog.h +++ b/Code/RDGeneral/RDLog.h @@ -1,5 +1,5 @@ // -// Copyright (C) 2005-2008 Greg Landrum and Rational Discovery LLC +// Copyright (C) 2005-2022 Greg Landrum and other RDKit contributors // // @@ All Rights Reserved @@ // This file is part of the RDKit. @@ -9,8 +9,8 @@ // #include -#ifndef _RDLOG_H_29JUNE2005_ -#define _RDLOG_H_29JUNE2005_ +#ifndef RDLOG_H_29JUNE2005 +#define RDLOG_H_29JUNE2005 #if 1 #include "BoostStartInclude.h" @@ -18,6 +18,8 @@ #include #include "BoostEndInclude.h" #include +#include + #include namespace boost { namespace logging { @@ -114,7 +116,23 @@ BOOST_DECLARE_LOG(rdStatusLog) namespace RDLog { RDKIT_RDGENERAL_EXPORT void InitLogs(); +using RDLoggerList = std::vector; +class RDKIT_RDGENERAL_EXPORT LogStateSetter { + public: + //! enables only the logs in the list, the current state will be restored when + //! this object is destroyed + LogStateSetter(RDLoggerList toEnable); + //! disables all logs, the current state will be restored when this object is + //! destroyed + LogStateSetter(); + ~LogStateSetter(); + + private: + std::uint64_t d_origState = 0; +}; + // ! Temporarily block logging until this object goes out of scope +// DEPRECATED, please use LogStateSetter() instead struct RDKIT_RDGENERAL_EXPORT BlockLogs { std::vector logs_to_reenable; BlockLogs(); diff --git a/Code/RDGeneral/catch_logs.cpp b/Code/RDGeneral/catch_logs.cpp new file mode 100644 index 000000000..27ecc2d3c --- /dev/null +++ b/Code/RDGeneral/catch_logs.cpp @@ -0,0 +1,65 @@ +// +// Copyright (C) 2022 Greg Landrum +// +// @@ All Rights Reserved @@ +// This file is part of the RDKit. +// The contents are covered by the terms of the BSD license +// which is included in the file license.txt, found at the root +// of the RDKit source tree. +// +#include +#include +#include "catch.hpp" +#include "RDLog.h" + +TEST_CASE("LogStateSetter") { + RDLog::RDLoggerList allLogs({rdErrorLog, rdWarningLog, rdInfoLog}); + SECTION("disable all") { + for (auto strm : allLogs) { + // explicitly enable the stream so that we know something is happening + std::stringstream ostrm; + strm->df_enabled = true; + strm->SetTee(ostrm); + { + RDLog::LogStateSetter disabler; + BOOST_LOG(strm) << "should be silent" << std::endl; + auto txt = ostrm.str(); + CHECK(txt.find("should") == std::string::npos); + } + BOOST_LOG(strm) << "should not be silent" << std::endl; + auto txt = ostrm.str(); + CHECK(txt.find("should") != std::string::npos); + strm->ClearTee(); + } + } + SECTION("enable one") { + for (auto strm : allLogs) { + strm->df_enabled = true; + RDLog::LogStateSetter disabler; + { + RDLog::LogStateSetter justone(RDLog::RDLoggerList({strm})); + for (auto strm2 : allLogs) { + std::stringstream ostrm; + strm2->SetTee(ostrm); + BOOST_LOG(strm2) << "should not be silent" << std::endl; + auto txt = ostrm.str(); + if (strm == strm2) { + CHECK(txt.find("should") != std::string::npos); + } else { + CHECK(txt.find("should") == std::string::npos); + } + + strm2->ClearTee(); + } + } + + // should be disabled again + std::stringstream ostrm; + strm->SetTee(ostrm); + BOOST_LOG(strm) << "should be silent" << std::endl; + auto txt = ostrm.str(); + CHECK(txt.find("should") == std::string::npos); + strm->ClearTee(); + } + } +} \ No newline at end of file diff --git a/ReleaseNotes.md b/ReleaseNotes.md index 4cff4c097..7a8a08465 100644 --- a/ReleaseNotes.md +++ b/ReleaseNotes.md @@ -4,6 +4,9 @@ ## Backwards incompatible changes - When running in Jupyter Notebook, logs are now sent only to Python's standard error stream, and no longer include the `RDKit LEVEL` prefix. +- The Debug and Info logs are now disabled by default. If you would like to + enable them within your code you can call `rdBase.EnableLog("rdApp.info")` + and/or `rdBase.EnableLog("rdApp.debug")`. - The MolHash functions now reassign stereochemistry after modifying the molecule and before calculating the hash. Previous versions would still include information about atom/bond stereochemistry in the output hash even if @@ -27,6 +30,7 @@ `rdkit.rdBase.LogWarning()`. - Python function `rdkit.Chem.LogError()` is deprecated in favor of `rdkit.rdBase.LogError()`. +- The C++ class `RDLog::BlockLogs` is deprecated in favor of the the class `RDLog::LogStateSetter`. # Release_2021.09.1 (Changes relative to Release_2021.03.1) diff --git a/rdkit/UnitTestLogging.py b/rdkit/UnitTestLogging.py index 747761b9d..20abb3296 100644 --- a/rdkit/UnitTestLogging.py +++ b/rdkit/UnitTestLogging.py @@ -221,6 +221,8 @@ class TestLogToCppStreams(unittest.TestCase): @classmethod def setUpClass(cls): rdBase.LogToCppStreams() + rdBase.EnableLog('rdApp.debug') + rdBase.EnableLog('rdApp.info') def testDebug(self): with CaptureOutput() as captured: @@ -384,6 +386,8 @@ class TestWrapLogs(unittest.TestCase): def setUpClass(cls): rdBase.LogToCppStreams() rdBase.WrapLogs() + rdBase.EnableLog('rdApp.debug') + rdBase.EnableLog('rdApp.info') def testDebug(self): with CaptureOutput() as captured: