Browse Source

pyln: Add logging handler that passes records to lightningd

It is often pretty usefuk to use the builtin logging module to debug things,
including libraries that a plugin may use. This adds a simple
`PluginLogHandler` that maps the python logging levels to the `lightningd`
logging levels, and formats the record in a way that it doesn't clutter up the
`lightningd` logs (no duplicate timestamps and levels).

This allow us to tweak the log level that is reported to `lightningd` simply
using the following

```python3
import logging
logging.basicConfig(level=logging.DEBUG)
```

Notice that in order for the logs to be displayed on the terminal or the
logfile, both the logging level in the plugin _and_ the `--log-level`
`lightningd` is running need to be adjusted (the python logging level only
controls which messages get forwarded to `lightningd`, it does not have the
power to overrule `lightningd` about what to actually display).

I chose `logging.INFO` as the default, since libraries have a tendency to spew
out everything in `logging.DEBUG` mode

Changelog-Added: pyln: Plugins have been integrated with the `logging` module for easier debugging and error reporting.
travis-experimental
Christian Decker 4 years ago
parent
commit
556725c5ff
  1. 48
      contrib/pyln-client/pyln/client/plugin.py

48
contrib/pyln-client/pyln/client/plugin.py

@ -8,6 +8,7 @@ from typing import Any, Callable, Dict, List, Optional, Tuple, Union
import inspect import inspect
import io import io
import json import json
import logging
import math import math
import os import os
import re import re
@ -210,6 +211,13 @@ class Plugin(object):
self.write_lock = RLock() self.write_lock = RLock()
# Initialize the logging system with a handler that passes the logs to
# lightning for display.
log_handler = PluginLogHandler(self)
formatter = logging.Formatter('%(name)-12s: %(message)s')
log_handler.setFormatter(formatter)
logging.getLogger('').addHandler(log_handler)
def add_method(self, name: str, func: Callable[..., Any], def add_method(self, name: str, func: Callable[..., Any],
background: bool = False, background: bool = False,
category: Optional[str] = None, category: Optional[str] = None,
@ -790,3 +798,43 @@ def monkey_patch(plugin: Plugin, stdout: bool = True,
setattr(sys, "stdout", PluginStream(plugin, level="info")) setattr(sys, "stdout", PluginStream(plugin, level="info"))
if stderr: if stderr:
setattr(sys, "stderr", PluginStream(plugin, level="warn")) setattr(sys, "stderr", PluginStream(plugin, level="warn"))
class PluginLogHandler(logging.StreamHandler):
def __init__(self, plugin: Plugin) -> None:
logging.StreamHandler.__init__(self, stream=None)
self.plugin = plugin
# Map the numeric levels to the string levels lightningd understands.
self.levels = {
logging.CRITICAL: 'error',
logging.ERROR: 'error',
logging.WARNING: 'info',
logging.INFO: 'info',
logging.DEBUG: 'debug',
logging.NOTSET: 'debug',
}
def emit(self, record: logging.LogRecord) -> None:
"""Emit a record.
If a formatter is specified, it is used to format the record. Numeric
levels are translated into strings that lightningd understands. If
exception information is present, it is formatted using
traceback.print_exception and appended to the stream.
"""
try:
msg = self.format(record)
level = self.levels.get(record.levelno, 'info')
self.plugin.log(msg, level=level)
except RecursionError: # See issue https://bugs.python.org/issue36272
raise
except Exception:
self.handleError(record) # Writes errors in logging system to stderr
pass
def flush(self) -> None:
"""Flushing is a no-op since each message is written as it comes in.
"""
pass

Loading…
Cancel
Save