pub_soft/rdkit
3
0
Fork 0
mirror of https://github.com/rdkit/rdkit.git synced 2026-06-03 21:44:30 +08:00
Code Issues Packages Projects Releases Wiki Activity

Fixes #5172 (#5181)

Browse Source 
* add test

* fix LogStateSetter

* fix BlockLogs() usage in Draw module

* allow BlockLogs() as a contestmgr

* move test to more suitable location

* guarantee log restoration on __exit__

* skip test if logs cannot be grabbed before block
This commit is contained in:
Ric
2022-04-11 23:57:25 -04:00
committed by GitHub
parent a860d16700
commit 3b2916c9a4
7 changed files with 292 additions and 158 deletions
Download Patch File Download Diff File Expand all files Collapse all files

184
Code/GraphMol/Wrap/rough_test.py
View File

File diff suppressed because one or more lines are too long

84
Code/RDBoost/Wrap/RDBase.cpp
View File

@@ -29,12 +29,11 @@ namespace logging = boost::logging;
std::string _version() { return "$Id$"; }
// std::ostream wrapper around Python's stderr stream
struct PyErrStream : std::ostream, std::streambuf {
static thread_local std::string buffer;
PyErrStream(): std::ostream(this) {
PyErrStream() : std::ostream(this) {
// All done!
}
@@ -48,8 +47,7 @@ struct PyErrStream : std::ostream, std::streambuf {
PyGILStateHolder h;
PySys_WriteStderr("%s\n", buffer.c_str());
buffer.clear();
}
else {
} else {
buffer += c;
}
}
@@ -60,7 +58,7 @@ struct PyLogStream : std::ostream, std::streambuf {
static thread_local std::string buffer;
PyObject *logfn = nullptr;
PyLogStream(std::string level): std::ostream(this) {
PyLogStream(std::string level) : std::ostream(this) {
PyObject *module = PyImport_ImportModule("logging");
PyObject *logger = nullptr;
@@ -100,8 +98,7 @@ struct PyLogStream : std::ostream, std::streambuf {
PyObject *result = PyObject_CallFunction(logfn, "s", buffer.c_str());
Py_XDECREF(result);
buffer.clear();
}
else {
} else {
buffer += c;
}
}
@@ -111,17 +108,16 @@ struct PyLogStream : std::ostream, std::streambuf {
thread_local std::string PyErrStream::buffer;
thread_local std::string PyLogStream::buffer;
void LogToPythonLogger() {
static PyLogStream debug("debug");
static PyLogStream info("info");
static PyLogStream warning("warning");
static PyLogStream error("error");
rdDebugLog = std::make_shared<logging::rdLogger>(&debug);
rdInfoLog = std::make_shared<logging::rdLogger>(&info);
rdDebugLog = std::make_shared<logging::rdLogger>(&debug);
rdInfoLog = std::make_shared<logging::rdLogger>(&info);
rdWarningLog = std::make_shared<logging::rdLogger>(&warning);
rdErrorLog = std::make_shared<logging::rdLogger>(&error);
rdErrorLog = std::make_shared<logging::rdLogger>(&error);
}
void LogToPythonStderr() {
@@ -130,17 +126,17 @@ void LogToPythonStderr() {
static PyErrStream warning;
static PyErrStream error;
rdDebugLog = std::make_shared<logging::rdLogger>(&debug);
rdInfoLog = std::make_shared<logging::rdLogger>(&info);
rdDebugLog = std::make_shared<logging::rdLogger>(&debug);
rdInfoLog = std::make_shared<logging::rdLogger>(&info);
rdWarningLog = std::make_shared<logging::rdLogger>(&warning);
rdErrorLog = std::make_shared<logging::rdLogger>(&error);
rdErrorLog = std::make_shared<logging::rdLogger>(&error);
}
void WrapLogs() {
static PyErrStream debug; //("RDKit DEBUG: ");
static PyErrStream error; //("RDKit ERROR: ");
static PyErrStream warning; //("RDKit WARNING: ");
static PyErrStream info; //("RDKit INFO: ");
static PyErrStream debug; //("RDKit DEBUG: ");
static PyErrStream error; //("RDKit ERROR: ");
static PyErrStream warning; //("RDKit WARNING: ");
static PyErrStream info; //("RDKit INFO: ");
if (!rdDebugLog || !rdInfoLog || !rdErrorLog || !rdWarningLog) {
RDLog::InitLogs();
@@ -152,18 +148,11 @@ void WrapLogs() {
rdErrorLog->SetTee(error);
}
void EnableLog(std::string spec) { logging::enable_logs(spec); }
void EnableLog(std::string spec) {
logging::enable_logs(spec);
}
void DisableLog(std::string spec) { logging::disable_logs(spec); }
void DisableLog(std::string spec) {
logging::disable_logs(spec);
}
std::string LogStatus() {
return logging::log_status();
}
std::string LogStatus() { return logging::log_status(); }
void AttachFileToLog(std::string spec, std::string filename, int delay = 100) {
(void)spec;
@@ -182,7 +171,6 @@ void AttachFileToLog(std::string spec, std::string filename, int delay = 100) {
#endif
}
void LogDebugMsg(const std::string &msg) {
// NOGIL nogil;
BOOST_LOG(rdDebugLog) << msg << std::endl;
@@ -215,6 +203,24 @@ void LogMessage(std::string spec, std::string msg) {
}
}
class BlockLogs : public boost::noncopyable {
public:
BlockLogs() : m_log_setter{new RDLog::LogStateSetter} {}
~BlockLogs() = default;
BlockLogs *enter() { return this; }
void exit(python::object exc_type, python::object exc_val,
python::object traceback) {
RDUNUSED_PARAM(exc_type);
RDUNUSED_PARAM(exc_val);
RDUNUSED_PARAM(traceback);
m_log_setter.reset();
}
private:
std::unique_ptr<RDLog::LogStateSetter> m_log_setter;
};
namespace {
struct python_streambuf_wrapper {
@@ -223,7 +229,7 @@ struct python_streambuf_wrapper {
static void wrap() {
using namespace boost::python;
class_<wt, boost::noncopyable>("streambuf", no_init)
.def(init<object&, std::size_t>(
.def(init<object &, std::size_t>(
(arg("python_file_obj"), arg("buffer_size") = 0),
"documentation")[with_custodian_and_ward_postcall<0, 2>()]);
}
@@ -236,7 +242,7 @@ struct python_ostream_wrapper {
using namespace boost::python;
class_<std::ostream, boost::noncopyable>("std_ostream", no_init);
class_<wt, boost::noncopyable, bases<std::ostream>>("ostream", no_init)
.def(init<object&, std::size_t>(
.def(init<object &, std::size_t>(
(arg("python_file_obj"), arg("buffer_size") = 0)));
}
};
@@ -244,7 +250,6 @@ struct python_ostream_wrapper {
void seedRNG(unsigned int seed) { std::srand(seed); }
} // namespace
BOOST_PYTHON_MODULE(rdBase) {
python::scope().attr("__doc__") =
"Module containing basic definitions for wrapped C++ code\n"
@@ -296,14 +301,12 @@ BOOST_PYTHON_MODULE(rdBase) {
python::def("LogDebugMsg", LogDebugMsg,
"Log a message to the RDKit debug logs");
python::def("LogInfoMsg", LogInfoMsg,
"Log a message to the RDKit info logs");
python::def("LogInfoMsg", LogInfoMsg, "Log a message to the RDKit info logs");
python::def("LogWarningMsg", LogWarningMsg,
"Log a message to the RDKit warning logs");
python::def("LogErrorMsg", LogErrorMsg,
"Log a message to the RDKit error logs");
python::def("LogMessage", LogMessage,
"Log a message to any rdApp.* log");
python::def("LogMessage", LogMessage, "Log a message to any rdApp.* log");
python::def("AttachFileToLog", AttachFileToLog,
"Causes the log to write to a file",
@@ -319,8 +322,11 @@ BOOST_PYTHON_MODULE(rdBase) {
python_streambuf_wrapper::wrap();
python_ostream_wrapper::wrap();
python::class_<RDLog::LogStateSetter, boost::noncopyable>(
python::class_<BlockLogs, boost::noncopyable>(
"BlockLogs",
"Temporarily block logs from outputting while this instance is in "
"scope.");
"Temporarily block logs from outputting while this instance is in scope.",
python::init<>())
.def("__enter__", &BlockLogs::enter,
python::return_internal_reference<>())
.def("__exit__", &BlockLogs::exit);
}

26
Code/RDGeneral/RDLog.cpp
View File

@@ -24,31 +24,35 @@ RDLogger rdWarningLog = nullptr;
RDLogger rdStatusLog = nullptr;
namespace RDLog {
namespace {
const std::vector<RDLogger *> allLogs = {&rdAppLog, &rdDebugLog,
&rdInfoLog, &rdErrorLog,
&rdWarningLog, &rdStatusLog};
}
LogStateSetter::LogStateSetter() {
std::vector<RDLogger> allLogs = {rdAppLog, rdDebugLog, rdInfoLog,
rdErrorLog, rdWarningLog, rdStatusLog};
for (auto i = 0u; i < allLogs.size(); ++i) {
if (allLogs[i] && allLogs[i]->df_enabled) {
if (*allLogs[i] && (*allLogs[i])->df_enabled) {
d_origState |= 1 << i;
allLogs[i]->df_enabled = false;
(*allLogs[i])->df_enabled = false;
}
}
}
LogStateSetter::LogStateSetter(RDLoggerList toEnable) : LogStateSetter() {
for (auto &log : toEnable) {
if (log) {
log->df_enabled = true;
for (auto i = 0u; i < allLogs.size(); ++i) {
if (*allLogs[i] && std::find(toEnable.begin(), toEnable.end(),
*allLogs[i]) != toEnable.end()) {
d_origState ^= 1 << i;
(*allLogs[i])->df_enabled = true;
}
}
}
LogStateSetter::~LogStateSetter() {
std::vector<RDLogger> 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;
if (*allLogs[i]) {
(*allLogs[i])->df_enabled ^= d_origState >> i & 1;
}
}
}

2
Code/RDGeneral/RDLog.h
View File

@@ -117,7 +117,7 @@ namespace RDLog {
RDKIT_RDGENERAL_EXPORT void InitLogs();
using RDLoggerList = std::vector<RDLogger>;
class RDKIT_RDGENERAL_EXPORT LogStateSetter {
class RDKIT_RDGENERAL_EXPORT LogStateSetter : public boost::noncopyable {
public:
//! enables only the logs in the list, the current state will be restored when
//! this object is destroyed

48
Code/RDGeneral/catch_logs.cpp
View File

@@ -62,4 +62,52 @@ TEST_CASE("LogStateSetter") {
strm->ClearTee();
}
}
}
TEST_CASE("GitHub Issue #5172", "[bug][logging]") {
std::stringstream err_ostrm;
std::stringstream warn_ostrm;
rdErrorLog->df_enabled = true;
rdWarningLog->df_enabled = true;
rdErrorLog->SetTee(err_ostrm);
rdWarningLog->SetTee(warn_ostrm);
{
RDLog::LogStateSetter disabler;
BOOST_LOG(rdErrorLog) << "should be silent" << std::endl;
auto txt = err_ostrm.str();
CHECK(txt.find("should") == std::string::npos);
BOOST_LOG(rdWarningLog) << "should be silent" << std::endl;
txt = warn_ostrm.str();
CHECK(txt.find("should") == std::string::npos);
{
// The second setter overrides the first one:
RDLog::LogStateSetter disabler2({rdWarningLog});
BOOST_LOG(rdErrorLog) << "should be silent" << std::endl;
txt = err_ostrm.str();
CHECK(txt.find("should") == std::string::npos);
BOOST_LOG(rdWarningLog) << "should not be silent" << std::endl;
txt = warn_ostrm.str();
CHECK(txt.find("should") != std::string::npos);
warn_ostrm.clear();
}
}
// Both setters are destroyed, and we revert to initial state
BOOST_LOG(rdErrorLog) << "should not be silent" << std::endl;
auto txt = err_ostrm.str();
CHECK(txt.find("should") != std::string::npos);
BOOST_LOG(rdWarningLog) << "should not be silent" << std::endl;
txt = warn_ostrm.str();
CHECK(txt.find("should") != std::string::npos);
rdErrorLog->ClearTee();
rdWarningLog->ClearTee();
}

90
Contrib/FreeWilson/test/test_freewilson.py
View File

@@ -5,59 +5,61 @@ import logging
PATH = os.path.join(os.path.dirname(fw.__file__), 'data')
assert os.path.exists(PATH), PATH
def test_chembl():
logging.getLogger().setLevel(logging.INFO)
smilesfile = os.path.join(PATH, "CHEMBL2321810.smi")
scaffoldfile = os.path.join(PATH, "CHEMBL2321810_scaffold.mol")
csvfile = os.path.join(PATH, "CHEMBL2321810_act.csv")
assert os.path.exists(smilesfile)
mols = []
for line in open(smilesfile):
smiles, name = line.strip().split()
m = Chem.MolFromSmiles(smiles)
m.SetProp("_Name", name)
mols.append(m)
logging.getLogger().setLevel(logging.INFO)
smilesfile = os.path.join(PATH, "CHEMBL2321810.smi")
scaffoldfile = os.path.join(PATH, "CHEMBL2321810_scaffold.mol")
csvfile = os.path.join(PATH, "CHEMBL2321810_act.csv")
assert os.path.exists(smilesfile)
mols = []
for line in open(smilesfile):
smiles, name = line.strip().split()
m = Chem.MolFromSmiles(smiles)
m.SetProp("_Name", name)
mols.append(m)
scaffold = Chem.MolFromMolBlock(open(scaffoldfile).read())
data = {k:float(v) for k,v in list(csv.reader(open(csvfile)))[1:]}
scaffold = Chem.MolFromMolBlock(open(scaffoldfile).read())
data = {k: float(v) for k, v in list(csv.reader(open(csvfile)))[1:]}
scores = [data[m.GetProp("_Name")] for m in mols]
assert mols and len(mols) == len(scores)
scores = [data[m.GetProp("_Name")] for m in mols]
assert mols and len(mols) == len(scores)
blocker = rdBase.BlockLogs()
with rdBase.BlockLogs():
free = fw.FWDecompose(scaffold, mols, scores)
# let's make sure the r squared is decent
assert free.r2 > 0.8
# let's make sure the r squared is decent
assert free.r2 > 0.8
# assert we get something
preds = list(fw.FWBuild(free))
assert len(preds)
# assert we get something
preds = list(fw.FWBuild(free))
assert len(preds)
# check to see that the prediction filters work
preds2 = list(fw.FWBuild(free, pred_filter=lambda x: x > 8))
assert len(preds2)
assert len([p for p in preds if p.prediction > 8]) == len(list(preds2))
# check to see that the prediction filters work
preds2 = list(fw.FWBuild(free, pred_filter=lambda x: x > 8))
assert len(preds2)
assert len([p for p in preds if p.prediction > 8]) == len(list(preds2))
# check to see that the R groups are output in order, i.e. R10 after R3
s = io.StringIO()
fw.predictions_to_csv(s, free, preds2)
assert s.getvalue()
# check to see that the R groups are output in order, i.e. R10 after R3
s = io.StringIO()
fw.predictions_to_csv(s, free, preds2)
assert s.getvalue()
s2 = io.StringIO(s.getvalue())
for i,row in enumerate(csv.reader(s2)):
if i == 0:
assert row == ['smiles','prediction','Core_smiles','R1_smiles','R3_smiles','R10_smiles']
assert i>0
s2 = io.StringIO(s.getvalue())
for i, row in enumerate(csv.reader(s2)):
if i == 0:
assert row == ['smiles', 'prediction', 'Core_smiles', 'R1_smiles', 'R3_smiles', 'R10_smiles']
assert i > 0
def test_multicore():
# test that we can add rgroups for later cores and not throw an exception
scaffolds = [Chem.MolFromSmiles("c1ccccc1[*].NC=O"), Chem.MolFromSmiles("C1CCCCC1")]
mols = [Chem.MolFromSmiles(x) for x in ['c1ccccc1CC2CNC2C(=O)N', 'Cc1ccccc1CC2CNC2C(=O)N', 'Cc1ccccc1CC2CNCC(=O)NC2', 'C3c1ccccc1CC2CNC2C(=O)N3', 'C1CCCCC1F', 'ClC1CCCCC1F']]
decomp=fw.FWDecompose(scaffolds, mols, [1,2,3,4,5,6])
s = io.StringIO()
fw.predictions_to_csv(s, decomp, fw.FWBuild(decomp))
# test that we can add rgroups for later cores and not throw an exception
scaffolds = [Chem.MolFromSmiles("c1ccccc1[*].NC=O"), Chem.MolFromSmiles("C1CCCCC1")]
mols = [
Chem.MolFromSmiles(x) for x in [
'c1ccccc1CC2CNC2C(=O)N', 'Cc1ccccc1CC2CNC2C(=O)N', 'Cc1ccccc1CC2CNCC(=O)NC2',
'C3c1ccccc1CC2CNC2C(=O)N3', 'C1CCCCC1F', 'ClC1CCCCC1F'
]
]
decomp = fw.FWDecompose(scaffolds, mols, [1, 2, 3, 4, 5, 6])
s = io.StringIO()
fw.predictions_to_csv(s, decomp, fw.FWBuild(decomp))

16
rdkit/Chem/Draw/__init__.py
View File

@@ -446,8 +446,8 @@ def _okToKekulizeMol(mol, kekulize):
def _moltoimg(mol, sz, highlights, legend, returnPNG=False, drawOptions=None, **kwargs):
try:
blocker = rdBase.BlockLogs()
mol.GetAtomWithIdx(0).GetExplicitValence()
with rdBase.BlockLogs():
mol.GetAtomWithIdx(0).GetExplicitValence()
except RuntimeError:
mol.UpdatePropertyCache(False)
@@ -455,8 +455,8 @@ def _moltoimg(mol, sz, highlights, legend, returnPNG=False, drawOptions=None, **
wedge = kwargs.get('wedgeBonds', True)
try:
blocker = rdBase.BlockLogs()
mc = rdMolDraw2D.PrepareMolForDrawing(mol, kekulize=kekulize, wedgeBonds=wedge)
with rdBase.BlockLogs():
mc = rdMolDraw2D.PrepareMolForDrawing(mol, kekulize=kekulize, wedgeBonds=wedge)
except ValueError: # <- can happen on a kekulization failure
mc = rdMolDraw2D.PrepareMolForDrawing(mol, kekulize=False, wedgeBonds=wedge)
if not hasattr(rdMolDraw2D, 'MolDraw2DCairo'):
@@ -489,16 +489,16 @@ def _moltoimg(mol, sz, highlights, legend, returnPNG=False, drawOptions=None, **
def _moltoSVG(mol, sz, highlights, legend, kekulize, drawOptions=None, **kwargs):
try:
blocker = rdBase.BlockLogs()
mol.GetAtomWithIdx(0).GetExplicitValence()
with rdBase.BlockLogs():
mol.GetAtomWithIdx(0).GetExplicitValence()
except RuntimeError:
mol.UpdatePropertyCache(False)
kekulize = _okToKekulizeMol(mol, kekulize)
try:
blocker = rdBase.BlockLogs()
mc = rdMolDraw2D.PrepareMolForDrawing(mol, kekulize=kekulize)
with rdBase.BlockLogs():
mc = rdMolDraw2D.PrepareMolForDrawing(mol, kekulize=kekulize)
except ValueError: # <- can happen on a kekulization failure
mc = rdMolDraw2D.PrepareMolForDrawing(mol, kekulize=False)
d2d = rdMolDraw2D.MolDraw2DSVG(sz[0], sz[1])