Skip to content

Commit

Permalink
Merge pull request #235 from benfred/python_logging
Browse files Browse the repository at this point in the history
Allow Python Handling of log messages
  • Loading branch information
Leonid Boytsov authored and GitHub committed Sep 6, 2017
2 parents 353b152 + d78b0f6 commit be517c5
Show file tree
Hide file tree
Showing 11 changed files with 203 additions and 64 deletions.
1 change: 1 addition & 0 deletions python_bindings/docs/index.rst
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ Contents:

Quickstart <quickstart>
API Reference <api>
Logging <logging>


Indices and tables
Expand Down
32 changes: 32 additions & 0 deletions python_bindings/docs/logging.rst
Original file line number Diff line number Diff line change
@@ -0,0 +1,32 @@
Configuring Logging for NMSLIB
==============================

This library logs to a Python logger named ``nmslib``. This lets
you fully control the log messages produced by nmslib in Python.

For instance, to log everything produced by nmslib to a default
python logger:

.. code-block:: python
# setup basic python logging
import logging
logging.basicConfig(level=logging.DEBUG)
# importing nmslib logs some debug messages on startup, that
# that will be output to the python log handler created above
import nmslib
To quiet these messages you can just set the level for nmslib
as appropiate:

.. code-block:: python
# setup basic python logging
import logging
logging.basicConfig(level=logging.DEBUG)
# Only log WARNING messages and above from nmslib
logging.getLogger('nmslib').setLevel(logging.WARNING)
import nmslib
42 changes: 40 additions & 2 deletions python_bindings/nmslib.cc
Original file line number Diff line number Diff line change
Expand Up @@ -317,9 +317,47 @@ struct IndexWrapper {
ObjectVector data;
};

class PythonLogger
: public Logger {
public:
py::object inner;
explicit PythonLogger(const py::object & inner)
: inner(inner) {
}

void log(LogSeverity severity,
const char * file,
int line,
const char * function,
const std::string & message) {
py::gil_scoped_acquire l;
switch(severity) {
case LIB_DEBUG:
inner.attr("debug")(message);
break;
case LIB_INFO:
inner.attr("info")(message);
break;
case LIB_WARNING:
inner.attr("warning")(message);
break;
case LIB_ERROR:
inner.attr("error")(message);
break;
case LIB_FATAL:
inner.attr("critical")(message);
break;
}
}
};

PYBIND11_PLUGIN(nmslib) {
// TODO(@benfred): configurable logging
initLibrary(LIB_LOGSTDERR, NULL);
// Log using the python logger, instead of defaults built in here
py::module logging = py::module::import("logging");
py::module nmslibLogger = logging.attr("getLogger")("nmslib");
setGlobalLogger(new PythonLogger(nmslibLogger));

initLibrary(LIB_LOGCUSTOM, NULL);

py::module m(module_name, "Bindings for Non-Metric Space Library (NMSLIB)");

Expand Down
2 changes: 1 addition & 1 deletion similarity_search/apps/tune_vptree.cc
Original file line number Diff line number Diff line change
Expand Up @@ -231,7 +231,7 @@ void RunExper(unsigned AddRestartQty,
}
LOG(LIB_INFO) << "Recall: " << recall;
LOG(LIB_INFO) << "Best time: " << time_best;
LOG(LIB_INFO) << "Best impr. " << impr_best << " (" << getOptimMetricName(metric) << ")" << endl;
LOG(LIB_INFO) << "Best impr. " << impr_best << " (" << getOptimMetricName(metric) << ")";
LOG(LIB_INFO) << "alpha_left: " << alpha_left;
LOG(LIB_INFO) << "exp_left: " << exp_left;
LOG(LIB_INFO) << "alpha_right: " << alpha_right;
Expand Down
82 changes: 67 additions & 15 deletions similarity_search/include/logging.h
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,8 @@
* With contributions from Lawrence Cayton (http://lcayton.com/) and others.
*
* For the complete list of contributors and further details see:
* https://github.com/searchivarius/NonMetricSpaceLib
*
* https://github.com/searchivarius/NonMetricSpaceLib
*
* Copyright (c) 2014
*
* This code is released under the
Expand All @@ -30,30 +30,82 @@ using std::stringstream;
using std::runtime_error;
using std::string;

enum LogSeverity {LIB_INFO, LIB_WARNING, LIB_ERROR, LIB_FATAL};
enum LogChoice {LIB_LOGNONE, LIB_LOGFILE, LIB_LOGSTDERR};
enum LogSeverity {LIB_DEBUG, LIB_INFO, LIB_WARNING, LIB_ERROR, LIB_FATAL};
enum LogChoice {LIB_LOGNONE, LIB_LOGFILE, LIB_LOGSTDERR, LIB_LOGCUSTOM};

std::string LibGetCurrentTime();

// write log to file
void InitializeLogger(LogChoice choice = LIB_LOGNONE, const char* logfile = NULL);

// Abstract base class that all loggers must override
class Logger {
public:
Logger(LogSeverity severity, const std::string& file, int line, const char* function);
~Logger();
virtual ~Logger();
virtual void log(LogSeverity severity,
const char * file,
int line,
const char * function,
const std::string & message) = 0;
};

static std::ostream& stream() { return *currstrm_ ; }
void setGlobalLogger(Logger * logger);
Logger * getGlobalLogger();

private:
LogSeverity severity_;
class StdErrLogger
: public Logger {
public:
void log(LogSeverity severity,
const char * file,
int line,
const char * function,
const std::string & message);
};

class FileLogger
: public Logger {
public:
FileLogger(const char * logfile);
void log(LogSeverity severity,
const char * file,
int line,
const char * function,
const std::string & message);
protected:
std::ofstream logfile;
};

static ofstream logfile_;
// A single entry in the log
class LogItem {
public:
LogItem(LogSeverity severity, const char * file, int line, const char * function,
Logger * logger)
: severity(severity), file(file), line(line), function(function), logger(logger) {
}

static ostream* currstrm_;
template <typename T>
LogItem & operator << (T t) {
message << t;
return *this;
}

// If choice != LIB_LOGFILE the second argument is ignored
friend void InitializeLogger(LogChoice choice, const char* logfile);
~LogItem() {
if (logger) {
logger->log(severity, file, line, function, message.str());
}
// TODO: probably better to throw an exception here rather than die outright
// but this matches previous behaviour
if (severity == LIB_FATAL) {
exit(1);
}
}

LogSeverity severity;
const char * file;
int line;
const char * function;
Logger * logger;
std::stringstream message;
};

class RuntimeErrorWrapper {
Expand All @@ -66,9 +118,9 @@ class RuntimeErrorWrapper {
stringstream currstrm_;
};


// TODO: zero cost log abstraction
#define LOG(severity) \
Logger(severity, __FILE__, __LINE__, __FUNCTION__).stream()
LogItem(severity, __FILE__, __LINE__, __FUNCTION__, getGlobalLogger())

#define CHECK(condition) \
if (!(condition)) {\
Expand Down
1 change: 0 additions & 1 deletion similarity_search/src/init.cc
Original file line number Diff line number Diff line change
Expand Up @@ -35,5 +35,4 @@ void initLibrary(LogChoice choice, const char* pLogFile) {
initSpaces();
initMethods();
}

}
91 changes: 54 additions & 37 deletions similarity_search/src/logging.cc
Original file line number Diff line number Diff line change
Expand Up @@ -24,23 +24,29 @@
#include <assert.h>

#include <iostream>
#include <memory>
#include <string>

#include "logging.h"

const char* log_severity[] = {"INFO", "WARNING", "ERROR", "FATAL"};
const char* log_severity[] = {"DEBUG", "INFO", "WARNING", "ERROR", "FATAL"};

using namespace std;

// allocate the static member
std::ofstream Logger::logfile_;
namespace {
std::unique_ptr<Logger> global_log(new StdErrLogger());
}

static struct voidstream : public ostream {
template <class T> ostream& operator<< (T) { return *this; }
template <class T> ostream& operator<< (T*) { return *this; }
template <class T> ostream& operator<< (T&) { return *this; }
voidstream() : ostream(0) {}
} voidstream_;
void setGlobalLogger(Logger * logger) {
global_log.reset(logger);
}

Logger * getGlobalLogger() {
return global_log.get();
}

Logger::~Logger() {
}

std::string LibGetCurrentTime() {
time_t now;
Expand All @@ -51,48 +57,59 @@ std::string LibGetCurrentTime() {
return std::string(time_string);
}

ostream* Logger::currstrm_ = &cerr;

Logger::Logger(LogSeverity severity, const std::string& _file, int line, const char* function)
: severity_(severity) {
template <typename T>
void defaultOutput(T & stream, LogSeverity severity,
const std::string& _file, int line, const char* function,
const std::string & message) {
std::string file = _file;
size_t n = file.rfind('/');
if (n != std::string::npos) {
file.erase(file.begin(), file.begin() + n + 1);
}
stream() << LibGetCurrentTime() << " " << file << ":" << line
<< " (" << function << ") [" << log_severity[severity] << "] ";
stream << LibGetCurrentTime() << " " << file << ":" << line
<< " (" << function << ") [" << log_severity[severity] << "] " << message << std::endl;
}

Logger::~Logger() {
stream() << '\n';
if (severity_ == LIB_FATAL) {
stream().flush();
if (logfile_.is_open())
logfile_.close();
// TODO(@leo/@bileg) do we want to abort here?
//abort();
exit(1);
void StdErrLogger::log(LogSeverity severity,
const char * file,
int line,
const char * function,
const std::string & message) {
defaultOutput(std::cerr, severity, file, line, function, message);
}

FileLogger::FileLogger(const char * logfilename)
: logfile(logfilename) {
if (!logfile) {
LOG(LIB_FATAL) << "Can't open the logfile: '" << logfilename << "'";
}
}

void FileLogger::log(LogSeverity severity,
const char * file,
int line,
const char * function,
const std::string & message) {
defaultOutput(logfile, severity, file, line, function, message);
}

void InitializeLogger(LogChoice choice, const char* logfile) {
if (choice == LIB_LOGNONE) {
Logger::currstrm_ = &voidstream_;
}
if (choice == LIB_LOGFILE) {
Logger::logfile_.open(logfile);
if (!Logger::logfile_) {
LOG(LIB_FATAL) << "Can't open the logfile: '" << logfile << "'";
}
Logger::currstrm_ = &Logger::logfile_;
}
if (choice == LIB_LOGSTDERR) {
Logger::currstrm_ = &cerr;
switch (choice) {
case LIB_LOGNONE:
setGlobalLogger(NULL);
break;
case LIB_LOGSTDERR:
setGlobalLogger(new StdErrLogger());
break;
case LIB_LOGFILE:
setGlobalLogger(new FileLogger(logfile));
break;
case LIB_LOGCUSTOM:
// don't set a logger here: setGlobalLogger will be called already
break;
}
}


RuntimeErrorWrapper::RuntimeErrorWrapper(const std::string& _file, int line, const char* function) {
std::string file = _file;
size_t n = file.rfind('/');
Expand Down
4 changes: 2 additions & 2 deletions similarity_search/src/space/space_bit_hamming.cc
Original file line number Diff line number Diff line change
Expand Up @@ -65,9 +65,9 @@ void SpaceBitHamming::ReadBitMaskVect(std::string line, LabelType& label, std::v
v.push_back(val);
}
} catch (const std::exception &e) {
LOG(LIB_ERROR) << "Exception: " << e.what() << std::endl;
LOG(LIB_ERROR) << "Exception: " << e.what();
PREPARE_RUNTIME_ERR(err) << "Failed to parse the line: '" << line << "'";
LOG(LIB_ERROR) << err.stream().str() << std::endl;
LOG(LIB_ERROR) << err.stream().str();
THROW_RUNTIME_ERR(err);
}
Binarize(v, 1, binVect); // Create the binary vector
Expand Down
4 changes: 2 additions & 2 deletions similarity_search/src/space/space_dummy.cc
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@ namespace similarity {

template <typename dist_t>
dist_t SpaceDummy<dist_t>::HiddenDistance(const Object* obj1, const Object* obj2) const {
LOG(LIB_INFO) << "Calculating the distance between objects: " << obj1->id() << " and " << obj2->id() << endl;
LOG(LIB_INFO) << "Calculating the distance between objects: " << obj1->id() << " and " << obj2->id();
CHECK(obj1->datalength() > 0);
CHECK(obj1->datalength() == obj2->datalength());
/*
Expand Down Expand Up @@ -83,7 +83,7 @@ bool SpaceDummy<dist_t>::ReadNextObjStr(DataFileInputState &inpStateBase, string
template <typename dist_t>
void SpaceDummy<dist_t>::WriteNextObj(const Object& obj, const string& externId, DataFileOutputState &outState) const {
string s = CreateStrFromObj(&obj, externId);
outState.out_file_ << s << endl;
outState.out_file_ << s;
}
/** End of standard functions to read/write/create objects */

Expand Down
4 changes: 2 additions & 2 deletions similarity_search/src/space/space_sparse_vector.cc
Original file line number Diff line number Diff line change
Expand Up @@ -70,9 +70,9 @@ void SpaceSparseVector<dist_t>::ReadSparseVec(std::string line, size_t line_num,
}
}
} catch (const std::exception &e) {
LOG(LIB_ERROR) << "Exception: " << e.what() << std::endl;
LOG(LIB_ERROR) << "Exception: " << e.what();
PREPARE_RUNTIME_ERR(err) << "Failed to parse the line # " << line_num << ": '" << line << "'" << std::endl;
LOG(LIB_ERROR) << err.stream().str() << std::endl;
LOG(LIB_ERROR) << err.stream().str();
THROW_RUNTIME_ERR(err);
}

Expand Down
Loading

0 comments on commit be517c5

Please sign in to comment.