From d73d153978adf5fbec9ce92b0a14dac557b325f9 Mon Sep 17 00:00:00 2001 From: antoniofilipovic <61245998+antoniofilipovic@users.noreply.github.com> Date: Mon, 22 Aug 2022 13:47:52 +0200 Subject: [PATCH] Add logging API (#417) --- include/mg_procedure.h | 9 ++ include/mgp.py | 78 +++++++++++ src/query/procedure/mg_procedure_impl.cpp | 26 ++++ src/query/procedure/py_module.cpp | 82 +++++++++++ tests/e2e/write_procedures/procedures/read.py | 18 ++- tests/e2e/write_procedures/simple_write.py | 130 ++++++++++-------- 6 files changed, 281 insertions(+), 62 deletions(-) diff --git a/include/mg_procedure.h b/include/mg_procedure.h index d4f3d903f..e5c6faa3e 100644 --- a/include/mg_procedure.h +++ b/include/mg_procedure.h @@ -1292,6 +1292,12 @@ struct mgp_proc; /// Describes a Memgraph magic function. struct mgp_func; +/// All available log levels that can be used in mgp_log function +MGP_ENUM_CLASS mgp_log_level{ + MGP_LOG_LEVEL_TRACE, MGP_LOG_LEVEL_DEBUG, MGP_LOG_LEVEL_INFO, + MGP_LOG_LEVEL_WARN, MGP_LOG_LEVEL_ERROR, MGP_LOG_LEVEL_CRITICAL, +}; + /// Entry-point for a query module read procedure, invoked through openCypher. /// /// Passed in arguments will not live longer than the callback's execution. @@ -1386,6 +1392,9 @@ enum mgp_error mgp_proc_add_result(struct mgp_proc *proc, const char *name, stru /// Return mgp_error::MGP_ERROR_INVALID_ARGUMENT if `name` is not a valid result name. /// RETURN mgp_error::MGP_ERROR_LOGIC_ERROR if a result field with the same name was already added. enum mgp_error mgp_proc_add_deprecated_result(struct mgp_proc *proc, const char *name, struct mgp_type *type); + +/// Log a message on a certain level. +enum mgp_error mgp_log(enum mgp_log_level log_level, const char *output); ///@} /// @name Execution diff --git a/include/mgp.py b/include/mgp.py index 72e958c7a..1e93a392b 100644 --- a/include/mgp.py +++ b/include/mgp.py @@ -2004,4 +2004,82 @@ def _wrap_exceptions(): setattr(module, name, wrap_function(obj)) +class Logger: + """Represents a Logger through which it is possible + to send logs via API to the graph database. + + The best way to use this Logger is to have one per query module.""" + + __slots__ = ("_logger",) + + def __init__(self): + self._logger = _mgp._LOGGER + + def info(self, out: str) -> None: + """ + Log message on INFO level.. + Args: + out: String message to be logged. + + Examples: + ```logger.info("Hello from query module.")``` + """ + self._logger.info(out) + + def warning(self, out: str) -> None: + """ + Log message on WARNING level.. + Args: + out: String message to be logged. + + Examples: + ```logger.warning("Hello from query module.")``` + """ + self._logger.warning(out) + + def critical(self, out: str) -> None: + """ + Log message on CRITICAL level.. + Args: + out: String message to be logged. + + Examples: + ```logger.critical("Hello from query module.")``` + """ + self._logger.critical(out) + + def error(self, out: str) -> None: + """ + Log message on ERROR level.. + Args: + out: String message to be logged. + + Examples: + ```logger.error("Hello from query module.")``` + """ + self._logger.error(out) + + def trace(self, out: str) -> None: + """ + Log message on TRACE level.. + Args: + out: String message to be logged. + + Examples: + ```logger.trace("Hello from query module.")``` + """ + self._logger.trace(out) + + def debug(self, out: str) -> None: + """ + Log message on DEBUG level.. + Args: + out: String message to be logged. + + Examples: + ```logger.debug("Hello from query module.")``` + """ + self._logger.debug(out) + + _wrap_exceptions() diff --git a/src/query/procedure/mg_procedure_impl.cpp b/src/query/procedure/mg_procedure_impl.cpp index 0e707baf7..7ec4104c6 100644 --- a/src/query/procedure/mg_procedure_impl.cpp +++ b/src/query/procedure/mg_procedure_impl.cpp @@ -2796,3 +2796,29 @@ mgp_error mgp_module_add_function(mgp_module *module, const char *name, mgp_func }, result); } + +mgp_error mgp_log(const mgp_log_level log_level, const char *output) { + return WrapExceptions([=] { + switch (log_level) { + case mgp_log_level::MGP_LOG_LEVEL_TRACE: + spdlog::trace(output); + return; + case mgp_log_level::MGP_LOG_LEVEL_DEBUG: + spdlog::debug(output); + return; + case mgp_log_level::MGP_LOG_LEVEL_INFO: + spdlog::info(output); + return; + case mgp_log_level::MGP_LOG_LEVEL_WARN: + spdlog::warn(output); + return; + case mgp_log_level::MGP_LOG_LEVEL_ERROR: + spdlog::error(output); + return; + case mgp_log_level::MGP_LOG_LEVEL_CRITICAL: + spdlog::critical(output); + return; + } + throw std::invalid_argument{fmt::format("Invalid log level: {}", log_level)}; + }); +} diff --git a/src/query/procedure/py_module.cpp b/src/query/procedure/py_module.cpp index f106ca284..981608703 100644 --- a/src/query/procedure/py_module.cpp +++ b/src/query/procedure/py_module.cpp @@ -2052,6 +2052,81 @@ PyObject *PyPathMakeWithStart(PyTypeObject *type, PyObject *vertex) { return py_path; } +// clang-format off +struct PyLogger { + PyObject_HEAD +}; +// clang-format on + +PyObject *PyLoggerLog(PyLogger *self, PyObject *args, const mgp_log_level level) { + MG_ASSERT(self); + const char *out = nullptr; + if (!PyArg_ParseTuple(args, "s", &out)) { + return nullptr; + } + + if (RaiseExceptionFromErrorCode(mgp_log(level, out))) { + return nullptr; + } + + Py_RETURN_NONE; +} + +PyObject *PyLoggerLogInfo(PyLogger *self, PyObject *args) { + return PyLoggerLog(self, args, mgp_log_level::MGP_LOG_LEVEL_INFO); +} + +PyObject *PyLoggerLogWarning(PyLogger *self, PyObject *args) { + return PyLoggerLog(self, args, mgp_log_level::MGP_LOG_LEVEL_WARN); +} + +PyObject *PyLoggerLogError(PyLogger *self, PyObject *args) { + return PyLoggerLog(self, args, mgp_log_level::MGP_LOG_LEVEL_ERROR); +} + +PyObject *PyLoggerLogCritical(PyLogger *self, PyObject *args) { + return PyLoggerLog(self, args, mgp_log_level::MGP_LOG_LEVEL_CRITICAL); +} + +PyObject *PyLoggerLogTrace(PyLogger *self, PyObject *args) { + return PyLoggerLog(self, args, mgp_log_level::MGP_LOG_LEVEL_TRACE); +} + +PyObject *PyLoggerLogDebug(PyLogger *self, PyObject *args) { + return PyLoggerLog(self, args, mgp_log_level::MGP_LOG_LEVEL_DEBUG); +} + +// NOLINTNEXTLINE(cppcoreguidelines-avoid-non-const-global-variables) +static PyMethodDef PyLoggerMethods[] = { + {"__reduce__", reinterpret_cast(DisallowPickleAndCopy), METH_NOARGS, "__reduce__ is not supported"}, + {"info", reinterpret_cast(PyLoggerLogInfo), METH_VARARGS, + "Logs a message with level INFO on this logger."}, + {"warning", reinterpret_cast(PyLoggerLogWarning), METH_VARARGS, + "Logs a message with level WARNNING on this logger."}, + {"error", reinterpret_cast(PyLoggerLogError), METH_VARARGS, + "Logs a message with level ERROR on this logger."}, + {"critical", reinterpret_cast(PyLoggerLogCritical), METH_VARARGS, + "Logs a message with level CRITICAL on this logger."}, + {"trace", reinterpret_cast(PyLoggerLogTrace), METH_VARARGS, + "Logs a message with level TRACE on this logger."}, + {"debug", reinterpret_cast(PyLoggerLogDebug), METH_VARARGS, + "Logs a message with level DEBUG on this logger."}, + {nullptr}, +}; + +// clang-format off +// NOLINTNEXTLINE(cppcoreguidelines-avoid-non-const-global-variables) +static PyTypeObject PyLoggerType = { + PyVarObject_HEAD_INIT(nullptr, 0) + .tp_name = "_mgp.Logger", + .tp_basicsize = sizeof(PyLogger), + // NOLINTNEXTLINE(hicpp-signed-bitwise) + .tp_flags = Py_TPFLAGS_DEFAULT, + .tp_doc = "Logging API.", + .tp_methods = PyLoggerMethods, +}; +// clang-format on + struct PyMgpError { const char *name; PyObject *&exception; @@ -2103,6 +2178,7 @@ PyObject *PyInitMgpModule() { if (!register_type(&PyCypherTypeType, "Type")) return nullptr; if (!register_type(&PyMessagesType, "Messages")) return nullptr; if (!register_type(&PyMessageType, "Message")) return nullptr; + if (!register_type(&PyLoggerType, "Logger")) return nullptr; std::array py_mgp_errors{ PyMgpError{"_mgp.UnknownError", gMgpUnknownError, PyExc_RuntimeError, nullptr}, @@ -2169,8 +2245,14 @@ auto WithMgpModule(mgp_module *module_def, const TFun &fun) { "import a new module. Is some other thread also importing Python " "modules?"); auto *py_query_module = MakePyQueryModule(module_def); + MG_ASSERT(py_query_module); MG_ASSERT(py_mgp.SetAttr("_MODULE", py_query_module)); + + // NOLINTNEXTLINE(cppcoreguidelines-pro-type-cstyle-cast) + auto *py_logger = reinterpret_cast(PyObject_New(PyLogger, &PyLoggerType)); + MG_ASSERT(py_mgp.SetAttr("_LOGGER", py_logger)); + auto ret = fun(); auto maybe_exc = py::FetchError(); MG_ASSERT(py_mgp.SetAttr("_MODULE", Py_None)); diff --git a/tests/e2e/write_procedures/procedures/read.py b/tests/e2e/write_procedures/procedures/read.py index 3f791a37a..b24138c38 100644 --- a/tests/e2e/write_procedures/procedures/read.py +++ b/tests/e2e/write_procedures/procedures/read.py @@ -13,11 +13,25 @@ import mgp @mgp.read_proc -def underlying_graph_is_mutable(ctx: mgp.ProcCtx, - object: mgp.Any) -> mgp.Record(mutable=bool): +def underlying_graph_is_mutable(ctx: mgp.ProcCtx, object: mgp.Any) -> mgp.Record(mutable=bool): return mgp.Record(mutable=object.underlying_graph_is_mutable()) @mgp.read_proc def graph_is_mutable(ctx: mgp.ProcCtx) -> mgp.Record(mutable=bool): return mgp.Record(mutable=ctx.graph.is_mutable()) + + +@mgp.read_proc +def log_message(ctx: mgp.ProcCtx, message: str) -> mgp.Record(success=bool): + logger = mgp.Logger() + try: + logger.info(message) + logger.critical(message) + logger.trace(message) + logger.debug(message) + logger.warning(message) + logger.error(message) + except RuntimeError: + return mgp.Record(success=False) + return mgp.Record(success=True) diff --git a/tests/e2e/write_procedures/simple_write.py b/tests/e2e/write_procedures/simple_write.py index 30a43f626..804e2edfd 100644 --- a/tests/e2e/write_procedures/simple_write.py +++ b/tests/e2e/write_procedures/simple_write.py @@ -13,8 +13,7 @@ import typing import mgclient import sys import pytest -from common import (execute_and_fetch_all, - has_one_result_row, has_n_result_row) +from common import execute_and_fetch_all, has_one_result_row, has_n_result_row def test_is_write(connection): @@ -22,15 +21,19 @@ def test_is_write(connection): result_order = "name, signature, is_write" cursor = connection.cursor() for proc in execute_and_fetch_all( - cursor, "CALL mg.procedures() YIELD * WITH name, signature, " - "is_write WHERE name STARTS WITH 'write' " - f"RETURN {result_order}"): + cursor, + "CALL mg.procedures() YIELD * WITH name, signature, " + "is_write WHERE name STARTS WITH 'write' " + f"RETURN {result_order}", + ): assert proc[is_write] is True for proc in execute_and_fetch_all( - cursor, "CALL mg.procedures() YIELD * WITH name, signature, " - "is_write WHERE NOT name STARTS WITH 'write' " - f"RETURN {result_order}"): + cursor, + "CALL mg.procedures() YIELD * WITH name, signature, " + "is_write WHERE NOT name STARTS WITH 'write' " + f"RETURN {result_order}", + ): assert proc[is_write] is False assert cursor.description[0].name == "name" @@ -41,8 +44,7 @@ def test_is_write(connection): def test_single_vertex(connection): cursor = connection.cursor() assert has_n_result_row(cursor, "MATCH (n) RETURN n", 0) - result = execute_and_fetch_all( - cursor, "CALL write.create_vertex() YIELD v RETURN v") + result = execute_and_fetch_all(cursor, "CALL write.create_vertex() YIELD v RETURN v") vertex = result[0][0] assert isinstance(vertex, mgclient.Node) assert has_one_result_row(cursor, "MATCH (n) RETURN n") @@ -50,14 +52,10 @@ def test_single_vertex(connection): assert vertex.properties == {} def add_label(label: str): - execute_and_fetch_all( - cursor, f"MATCH (n) CALL write.add_label(n, '{label}') " - "YIELD * RETURN *") + execute_and_fetch_all(cursor, f"MATCH (n) CALL write.add_label(n, '{label}') " "YIELD * RETURN *") def remove_label(label: str): - execute_and_fetch_all( - cursor, f"MATCH (n) CALL write.remove_label(n, '{label}') " - "YIELD * RETURN *") + execute_and_fetch_all(cursor, f"MATCH (n) CALL write.remove_label(n, '{label}') " "YIELD * RETURN *") def get_vertex() -> mgclient.Node: return execute_and_fetch_all(cursor, "MATCH (n) RETURN n")[0][0] @@ -65,8 +63,10 @@ def test_single_vertex(connection): def set_property(property_name: str, property: typing.Any): nonlocal cursor execute_and_fetch_all( - cursor, f"MATCH (n) CALL write.set_property(n, '{property_name}', " - "$property) YIELD * RETURN *", {"property": property}) + cursor, + f"MATCH (n) CALL write.set_property(n, '{property_name}', " "$property) YIELD * RETURN *", + {"property": property}, + ) label_1 = "LABEL1" label_2 = "LABEL2" @@ -89,24 +89,23 @@ def test_single_vertex(connection): set_property(property_name, None) assert get_vertex().properties == {} - execute_and_fetch_all( - cursor, "MATCH (n) CALL write.delete_vertex(n) YIELD * RETURN 1") + execute_and_fetch_all(cursor, "MATCH (n) CALL write.delete_vertex(n) YIELD * RETURN 1") assert has_n_result_row(cursor, "MATCH (n) RETURN n", 0) def test_single_edge(connection): cursor = connection.cursor() assert has_n_result_row(cursor, "MATCH (n) RETURN n", 0) - v1_id = execute_and_fetch_all( - cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id - v2_id = execute_and_fetch_all( - cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id + v1_id = execute_and_fetch_all(cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id + v2_id = execute_and_fetch_all(cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id edge_type = "EDGE" edge = execute_and_fetch_all( - cursor, f"MATCH (n) WHERE id(n) = {v1_id} " - f"MATCH (m) WHERE id(m) = {v2_id} " - f"CALL write.create_edge(n, m, '{edge_type}') " - "YIELD e RETURN e")[0][0] + cursor, + f"MATCH (n) WHERE id(n) = {v1_id} " + f"MATCH (m) WHERE id(m) = {v2_id} " + f"CALL write.create_edge(n, m, '{edge_type}') " + "YIELD e RETURN e", + )[0][0] assert edge.type == edge_type assert edge.properties == {} @@ -120,9 +119,10 @@ def test_single_edge(connection): def set_property(property_name: str, property: typing.Any): nonlocal cursor execute_and_fetch_all( - cursor, "MATCH ()-[e]->() " - f"CALL write.set_property(e, '{property_name}', " - "$property) YIELD * RETURN *", {"property": property}) + cursor, + "MATCH ()-[e]->() " f"CALL write.set_property(e, '{property_name}', " "$property) YIELD * RETURN *", + {"property": property}, + ) set_property(property_name, property_value_1) assert get_edge().properties == {property_name: property_value_1} @@ -130,64 +130,74 @@ def test_single_edge(connection): assert get_edge().properties == {property_name: property_value_2} set_property(property_name, None) assert get_edge().properties == {} - execute_and_fetch_all( - cursor, "MATCH ()-[e]->() CALL write.delete_edge(e) YIELD * RETURN 1") + execute_and_fetch_all(cursor, "MATCH ()-[e]->() CALL write.delete_edge(e) YIELD * RETURN 1") assert has_n_result_row(cursor, "MATCH ()-[e]->() RETURN e", 0) def test_detach_delete_vertex(connection): cursor = connection.cursor() assert has_n_result_row(cursor, "MATCH (n) RETURN n", 0) - v1_id = execute_and_fetch_all( - cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id - v2_id = execute_and_fetch_all( - cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id + v1_id = execute_and_fetch_all(cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id + v2_id = execute_and_fetch_all(cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id execute_and_fetch_all( - cursor, f"MATCH (n) WHERE id(n) = {v1_id} " + cursor, + f"MATCH (n) WHERE id(n) = {v1_id} " f"MATCH (m) WHERE id(m) = {v2_id} " f"CALL write.create_edge(n, m, 'EDGE') " - "YIELD e RETURN e") + "YIELD e RETURN e", + ) assert has_one_result_row(cursor, "MATCH (n)-[e]->(m) RETURN n, e, m") execute_and_fetch_all( - cursor, f"MATCH (n) WHERE id(n) = {v1_id} " - "CALL write.detach_delete_vertex(n) YIELD * RETURN 1") + cursor, f"MATCH (n) WHERE id(n) = {v1_id} " "CALL write.detach_delete_vertex(n) YIELD * RETURN 1" + ) assert has_n_result_row(cursor, "MATCH (n)-[e]->(m) RETURN n, e, m", 0) assert has_n_result_row(cursor, "MATCH ()-[e]->() RETURN e", 0) - assert has_one_result_row( - cursor, f"MATCH (n) WHERE id(n) = {v2_id} RETURN n") + assert has_one_result_row(cursor, f"MATCH (n) WHERE id(n) = {v2_id} RETURN n") def test_graph_mutability(connection): cursor = connection.cursor() assert has_n_result_row(cursor, "MATCH (n) RETURN n", 0) - v1_id = execute_and_fetch_all( - cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id - v2_id = execute_and_fetch_all( - cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id + v1_id = execute_and_fetch_all(cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id + v2_id = execute_and_fetch_all(cursor, "CALL write.create_vertex() YIELD v RETURN v")[0][0].id execute_and_fetch_all( - cursor, f"MATCH (n) WHERE id(n) = {v1_id} " + cursor, + f"MATCH (n) WHERE id(n) = {v1_id} " f"MATCH (m) WHERE id(m) = {v2_id} " f"CALL write.create_edge(n, m, 'EDGE') " - "YIELD e RETURN e") + "YIELD e RETURN e", + ) def test_mutability(is_write: bool): module = "write" if is_write else "read" - assert execute_and_fetch_all( - cursor, f"CALL {module}.graph_is_mutable() " - "YIELD mutable RETURN mutable")[0][0] is is_write - assert execute_and_fetch_all( - cursor, "MATCH (n) " - f"CALL {module}.underlying_graph_is_mutable(n) " - "YIELD mutable RETURN mutable")[0][0] is is_write - assert execute_and_fetch_all( - cursor, "MATCH (n)-[e]->(m) " - f"CALL {module}.underlying_graph_is_mutable(e) " - "YIELD mutable RETURN mutable")[0][0] is is_write + assert ( + execute_and_fetch_all(cursor, f"CALL {module}.graph_is_mutable() " "YIELD mutable RETURN mutable")[0][0] + is is_write + ) + assert ( + execute_and_fetch_all( + cursor, "MATCH (n) " f"CALL {module}.underlying_graph_is_mutable(n) " "YIELD mutable RETURN mutable" + )[0][0] + is is_write + ) + assert ( + execute_and_fetch_all( + cursor, + "MATCH (n)-[e]->(m) " f"CALL {module}.underlying_graph_is_mutable(e) " "YIELD mutable RETURN mutable", + )[0][0] + is is_write + ) test_mutability(True) test_mutability(False) +def test_log_message(connection): + cursor = connection.cursor() + success = execute_and_fetch_all(cursor, f"CALL read.log_message('message') YIELD success RETURN success")[0][0] + assert (success) is True + + if __name__ == "__main__": sys.exit(pytest.main([__file__, "-rA"]))