fixup! pylightning: Migrate the test plugin to use the new wrapper

This is just cosmetic, and makes things like tracebacks much easier to
read.

Signed-off-by: Christian Decker <decker.christian@gmail.com>

contrib/plugins/helloworld.py

@@ -1,96 +1,28 @@
 #!/usr/bin/env python3
-"""Simple plugin to show how to build new plugins for c-lightning
-
-It demonstrates how a plugin communicates with c-lightning, how it
-registers command line arguments that should be passed through and how
-it can register JSON-RPC commands. We communicate with the main daemon
-through STDIN and STDOUT, reading and writing JSON-RPC requests.
-
-"""
-import json
-import sys
+from lightning import Plugin
 
 
-greeting = "World"
+plugin = Plugin(autopatch=True)
 
 
-def json_hello(request, name):
-    greeting = "Hello {}".format(name)
-    return greeting
+@plugin.method("hello")
+def hello(name, plugin):
+    """This is the documentation string for the hello-function.
 
+    It gets reported as the description when registering the function
+    as a method with `lightningd`.
 
-def json_fail(request):
-    raise ValueError("This will fail")
-
-
-def json_getmanifest(request):
-    global greeting
-    return {
-        "options": [
-            {"name": "greeting",
-             "type": "string",
-             "default": greeting,
-             "description": "What name should I call you?"},
-        ],
-        "rpcmethods": [
-            {
-                "name": "hello",
-                "description": "Returns a personalized greeting for {name}",
-            },
-            {
-                "name": "fail",
-                "description": "Always returns a failure for testing",
-            },
-        ]
-    }
-
-
-def json_init(request, options, configuration):
-    """The main daemon is telling us the relevant cli options
     """
-    global greeting
-
-    greeting = request['params']['options']['greeting']
-    return "ok"
+    greeting = plugin.get_option('greeting')
+    s = '{} {}'.format(greeting, name)
+    plugin.log(s)
+    return s
 
 
-methods = {
-    'hello': json_hello,
-    'fail': json_fail,
-    'getmanifest': json_getmanifest,
-    'init': json_init,
-}
+@plugin.method("init")
+def init(options, configuration, plugin):
+    plugin.log("Plugin helloworld.py initialized")
 
 
-partial = ""
-for l in sys.stdin:
-    try:
-        partial += l
-        request = json.loads(partial)
-    except Exception:
-        continue
-
-    result = None
-    method = methods[request['method']]
-    params = request['params']
-    try:
-        if isinstance(params, dict):
-            result = method(request, **params)
-        else:
-            result = method(request, *params)
-        result = {
-            "jsonrpc": "2.0",
-            "result": result,
-            "id": request['id']
-        }
-    except Exception:
-        result = {
-            "jsonrpc": "2.0",
-            "error": "Error while processing {}".format(request['method']),
-            "id": request['id']
-        }
-
-    json.dump(result, fp=sys.stdout)
-    sys.stdout.write('\n')
-    sys.stdout.flush()
-    partial = ""
+plugin.add_option('greeting', 'Hello', 'The greeting I should use.')
+plugin.run()

contrib/pylightning/lightning/__init__.py

@@ -1 +1,2 @@
 from .lightning import LightningRpc, RpcError
+from .plugin import Plugin, monkey_patch

contrib/pylightning/lightning/plugin.py

@@ -0,0 +1,261 @@
+import sys
+import os
+import json
+import inspect
+import traceback
+
+
+class Plugin(object):
+    """Controls interactions with lightningd, and bundles functionality.
+
+    The Plugin class serves two purposes: it collects RPC methods and
+    options, and offers a control loop that dispatches incoming RPC
+    calls and hooks.
+
+    """
+
+    def __init__(self, stdout=None, stdin=None, autopatch=True):
+        self.methods = {}
+        self.options = {}
+        self.option_values = {}
+
+        if not stdout:
+            self.stdout = sys.stdout
+        if not stdin:
+            self.stdin = sys.stdin
+
+        if os.getenv('LIGHTNINGD_PLUGIN') and autopatch:
+            monkey_patch(self, stdout=True, stderr=True)
+
+        self.add_method("getmanifest", self._getmanifest)
+        self.rpc_filename = None
+        self.lightning_dir = None
+        self.init = None
+
+    def add_method(self, name, func):
+        """Add a plugin method to the dispatch table.
+
+        The function will be expected at call time (see `_dispatch`)
+        and the parameters from the JSON-RPC call will be mapped to
+        the function arguments. In addition to the parameters passed
+        from the JSON-RPC call we add a few that may be useful:
+
+         - `plugin`: gets a reference to this plugin.
+
+         - `request`: gets a reference to the raw request as a
+           dict. This corresponds to the JSON-RPC message that is
+           being dispatched.
+
+        Notice that due to the python binding logic we may be mapping
+        the arguments wrongly if we inject the plugin and/or request
+        in combination with positional binding. To prevent issues the
+        plugin and request argument should always be the last two
+        arguments and have a default on None.
+
+        """
+        if name in self.methods:
+            raise ValueError(
+                "Name {} is already bound to a method.".format(name)
+            )
+
+        # Register the function with the name
+        self.methods[name] = func
+
+    def add_option(self, name, default, description):
+        """Add an option that we'd like to register with lightningd.
+
+        Needs to be called before `Plugin.run`, otherwise we might not
+        end up getting it set.
+
+        """
+        if name in self.options:
+            raise ValueError(
+                "Name {} is already used by another option".format(name)
+            )
+        self.options[name] = {
+            'name': name,
+            'default': default,
+            'description': description,
+            'type': 'string',
+        }
+
+    def get_option(self, name):
+        if name in self.option_values:
+            return self.option_values[name]
+        elif name in self.options:
+            return self.options[name]['default']
+        else:
+            raise ValueError("No option with name {} registered".format(name))
+
+    def method(self, method_name, *args, **kwargs):
+        """Decorator to add a plugin method to the dispatch table.
+
+        Internally uses add_method.
+        """
+        def decorator(f):
+            self.add_method(method_name, f)
+            return f
+        return decorator
+
+    def _dispatch(self, request):
+        name = request['method']
+        params = request['params']
+
+        if name not in self.methods:
+            raise ValueError("No method {} found.".format(name))
+
+        args = params.copy() if isinstance(params, list) else []
+        kwargs = params.copy() if isinstance(params, dict) else {}
+
+        func = self.methods[name]
+        sig = inspect.signature(func)
+
+        if 'plugin' in sig.parameters:
+            kwargs['plugin'] = self
+
+        if 'request' in sig.parameters:
+            kwargs['request'] = request
+
+        ba = sig.bind(*args, **kwargs)
+        ba.apply_defaults()
+        return func(*ba.args, **ba.kwargs)
+
+    def notify(self, method, params):
+        payload = {
+            'jsonrpc': '2.0',
+            'method': method,
+            'params': params,
+        }
+        json.dump(payload, self.stdout)
+        self.stdout.write("\n\n")
+        self.stdout.flush()
+
+    def log(self, message, level='info'):
+        # Split the log into multiple lines and print them
+        # individually. Makes tracebacks much easier to read.
+        for line in message.split('\n'):
+            self.notify('log', {'level': level, 'message': line})
+
+    def _multi_dispatch(self, msgs):
+        """We received a couple of messages, now try to dispatch them all.
+
+        Returns the last partial message that was not complete yet.
+        """
+        for payload in msgs[:-1]:
+            request = json.loads(payload)
+
+            try:
+                result = {
+                    "jsonrpc": "2.0",
+                    "result": self._dispatch(request),
+                    "id": request['id']
+                }
+            except Exception as e:
+                result = {
+                    "jsonrpc": "2.0",
+                    "error": "Error while processing {}".format(
+                        request['method']
+                    ),
+                    "id": request['id']
+                }
+                self.log(traceback.format_exc())
+            json.dump(result, fp=self.stdout)
+            self.stdout.write('\n\n')
+            self.stdout.flush()
+        return msgs[-1]
+
+    def run(self):
+        # Stash the init method handler, we'll handle opts first and
+        # then unstash this and call it.
+        if 'init' in self.methods:
+            self.init = self.methods['init']
+            self.methods['init'] = self._init
+
+        partial = ""
+        for l in self.stdin:
+            partial += l
+
+            msgs = partial.split('\n\n')
+            if len(msgs) < 2:
+                continue
+
+            partial = self._multi_dispatch(msgs)
+
+    def _getmanifest(self):
+        methods = []
+        for name, func in self.methods.items():
+            # Skip the builtin ones, they don't get reported
+            if name in ['getmanifest', 'init']:
+                continue
+
+            doc = inspect.getdoc(func)
+            if not doc:
+                self.log(
+                    'RPC method \'{}\' does not have a docstring.'.format(name)
+                )
+                doc = "Undocumented RPC method from a plugin."
+
+            methods.append({
+                'name': name,
+                'description': doc,
+            })
+
+        return {
+            'options': list(self.options.values()),
+            'rpcmethods': methods,
+        }
+
+    def _init(self, options, configuration, request):
+        self.rpc_filename = configuration['rpc-file']
+        self.lightning_dir = configuration['lightning-dir']
+        for name, value in options.items():
+            self.option_values[name] = value
+
+        # Swap the registered `init` method handler back in and
+        # re-dispatch
+        if self.init:
+            self.methods['init'] = self.init
+            self.init = None
+            return self._dispatch(request)
+        return None
+
+
+class PluginStream(object):
+    """Sink that turns everything that is written to it into a notification.
+    """
+
+    def __init__(self, plugin, level="info"):
+        self.plugin = plugin
+        self.level = level
+        self.buff = ''
+
+    def write(self, payload):
+        self.buff += payload
+
+        if payload[-1] == '\n':
+            self.flush()
+
+    def flush(self):
+        lines = self.buff.split('\n')
+        if len(lines) < 2:
+            return
+
+        for l in lines[:-1]:
+            self.plugin.log(l, self.level)
+
+        # lines[-1] is either an empty string or a partial line
+        self.buff = lines[-1]
+
+
+def monkey_patch(plugin, stdout=True, stderr=False):
+    """Monkey patch stderr and stdout so we use notifications instead.
+
+    A plugin commonly communicates with lightningd over its stdout
+    and stdin filedescriptor, so if we use them in some other way
+    (printing, logging, ...) we're breaking our communication
+    channel. This function
+    """
+    if stdout:
+        setattr(sys, "stdout", PluginStream(plugin, level="info"))
+    if stderr:
+        setattr(sys, "stderr", PluginStream(plugin, level="warn"))

contrib/pylightning/tests/test_plugin.py

@@ -0,0 +1,171 @@
+from lightning import Plugin
+
+
+import pytest
+
+
+def test_simple_methods():
+    """Test the dispatch of methods, with a variety of bindings.
+    """
+    call_list = []
+    p = Plugin(autopatch=False)
+
+    @p.method("test1")
+    def test1(name):
+        """Has a single positional argument."""
+        assert name == 'World'
+        call_list.append(test1)
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test1',
+        'params': {'name': 'World'}
+    }
+    p._dispatch(request)
+    assert call_list == [test1]
+
+    @p.method("test2")
+    def test2(name, plugin):
+        """Also asks for the plugin instance. """
+        assert plugin == p
+        call_list.append(test2)
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test2',
+        'params': {'name': 'World'}
+    }
+    p._dispatch(request)
+    assert call_list == [test1, test2]
+
+    @p.method("test3")
+    def test3(name, request):
+        """Also asks for the request instance. """
+        assert request is not None
+        call_list.append(test3)
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test3',
+        'params': {'name': 'World'}
+    }
+    p._dispatch(request)
+    assert call_list == [test1, test2, test3]
+
+    @p.method("test4")
+    def test4(name):
+        """Try the positional arguments."""
+        assert name == 'World'
+        call_list.append(test4)
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test4',
+        'params': ['World']
+    }
+    p._dispatch(request)
+    assert call_list == [test1, test2, test3, test4]
+
+    @p.method("test5")
+    def test5(name, request, plugin):
+        """Try the positional arguments, mixing in the request and plugin."""
+        assert name == 'World'
+        assert request is not None
+        assert p == plugin
+        call_list.append(test5)
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test5',
+        'params': ['World']
+    }
+    p._dispatch(request)
+    assert call_list == [test1, test2, test3, test4, test5]
+
+    answers = []
+
+    @p.method("test6")
+    def test6(name, answer=42):
+        """This method has a default value for one of its params"""
+        assert name == 'World'
+        answers.append(answer)
+        call_list.append(test6)
+
+    # Both calls should work (with and without the default param
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test6',
+        'params': ['World']
+    }
+    p._dispatch(request)
+    assert call_list == [test1, test2, test3, test4, test5, test6]
+    assert answers == [42]
+
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test6',
+        'params': ['World', 31337]
+    }
+    p._dispatch(request)
+    assert call_list == [test1, test2, test3, test4, test5, test6, test6]
+    assert answers == [42, 31337]
+
+
+def test_methods_errors():
+    """A bunch of tests that should fail calling the methods."""
+    call_list = []
+    p = Plugin(autopatch=False)
+
+    # Fails because we haven't added the method yet
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test1',
+        'params': {}
+    }
+    with pytest.raises(ValueError):
+        p._dispatch(request)
+    assert call_list == []
+
+    @p.method("test1")
+    def test1(name):
+        call_list.append(test1)
+
+    # Attempting to add it twice should fail
+    with pytest.raises(ValueError):
+        p.add_method("test1", test1)
+
+    # Fails because it is missing the 'name' argument
+    request = {'id': 1, 'jsonrpc': '2.0', 'method': 'test1', 'params': {}}
+    with pytest.raises(TypeError):
+        p._dispatch(request)
+    assert call_list == []
+
+    # The same with positional arguments
+    request = {'id': 1, 'jsonrpc': '2.0', 'method': 'test1', 'params': []}
+    with pytest.raises(TypeError):
+        p._dispatch(request)
+    assert call_list == []
+
+    # Fails because we have a non-matching argument
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test1',
+        'params': {'name': 'World', 'extra': 1}
+    }
+    with pytest.raises(TypeError):
+        p._dispatch(request)
+    assert call_list == []
+
+    request = {
+        'id': 1,
+        'jsonrpc': '2.0',
+        'method': 'test1',
+        'params': ['World', 1]
+    }
+    with pytest.raises(TypeError):
+        p._dispatch(request)
+    assert call_list == []

lightningd/plugin.c

@@ -234,6 +234,88 @@ static void plugin_request_queue(struct plugin *plugin,
 	io_wake(plugin);
 }
 
+static void plugin_log_handle(struct plugin *plugin, const jsmntok_t *paramstok)
+{
+	const jsmntok_t *msgtok, *leveltok;
+	enum log_level level;
+	msgtok = json_get_member(plugin->buffer, paramstok, "message");
+	leveltok = json_get_member(plugin->buffer, paramstok, "level");
+
+	if (!msgtok) {
+		plugin_kill(plugin, "Log notification from plugin doesn't have "
+				    "a \"message\" field");
+		return;
+	}
+
+	if (!leveltok || json_tok_streq(plugin->buffer, leveltok, "info"))
+		level = LOG_INFORM;
+	else if (json_tok_streq(plugin->buffer, leveltok, "debug"))
+		level = LOG_DBG;
+	else if (json_tok_streq(plugin->buffer, leveltok, "warn"))
+		level = LOG_UNUSUAL;
+	else if (json_tok_streq(plugin->buffer, leveltok, "error"))
+		level = LOG_BROKEN;
+	else {
+		plugin_kill(plugin,
+			    "Unknown log-level %.*s, valid values are "
+			    "\"debug\", \"info\", \"warn\", or \"error\".",
+			    json_tok_len(leveltok),
+			    json_tok_contents(plugin->buffer, leveltok));
+		return;
+	}
+
+	/* We strip the \" otherwise they'd be printed here. */
+	log_(plugin->log, level, "log: %.*s", json_tok_len(msgtok) - 2,
+	     json_tok_contents(plugin->buffer, msgtok) + 1);
+}
+
+static void plugin_notification_handle(struct plugin *plugin,
+				       const jsmntok_t *methtok,
+				       const jsmntok_t *paramstok)
+{
+	/* Dispatch incoming notifications. This is currently limited
+	 * to just a few method types, should this ever become
+	 * unwieldy we can switch to the AUTODATA construction to
+	 * register notification handlers in a variety of places. */
+	if (json_tok_streq(plugin->buffer, methtok, "log")) {
+		plugin_log_handle(plugin, paramstok);
+	} else {
+		plugin_kill(plugin, "Unknown notification method %.*s",
+			    json_tok_len(methtok),
+			    json_tok_contents(plugin->buffer, methtok));
+	}
+}
+
+static void plugin_response_handle(struct plugin *plugin,
+				   const jsmntok_t *toks,
+				   const jsmntok_t *idtok)
+{
+	struct plugin_request *request;
+	u64 id;
+	/* We only send u64 ids, so if this fails it's a critical error (note
+	 * that this also works if id is inside a JSON string!). */
+	if (!json_to_u64(plugin->buffer, idtok, &id)) {
+		plugin_kill(plugin,
+			    "JSON-RPC response \"id\"-field is not a u64");
+		return;
+	}
+
+	request = uintmap_get(&plugin->plugins->pending_requests, id);
+
+	if (!request) {
+		plugin_kill(
+		    plugin,
+		    "Received a JSON-RPC response for non-existent request");
+		return;
+	}
+
+	/* We expect the request->cb to copy if needed */
+	request->cb(request, plugin->buffer, toks, idtok, request->arg);
+
+	uintmap_del(&plugin->plugins->pending_requests, id);
+	tal_free(request);
+}
+
 /**
  * Try to parse a complete message from the plugin's buffer.
  *
@@ -242,11 +324,9 @@ static void plugin_request_queue(struct plugin *plugin,
  */
 static bool plugin_read_json_one(struct plugin *plugin)
 {
-	jsmntok_t *toks;
 	bool valid;
-	u64 id;
-	const jsmntok_t *idtok;
-	struct plugin_request *request;
+	const jsmntok_t *toks, *jrtok, *idtok, *resulttok, *errortok, *methtok,
+	    *paramstok;
 
 	/* FIXME: This could be done more efficiently by storing the
 	 * toks and doing an incremental parse, like lightning-cli
@@ -269,32 +349,70 @@ static bool plugin_read_json_one(struct plugin *plugin)
 		return false;
 	}
 
+	jrtok = json_get_member(plugin->buffer, toks, "jsonrpc");
+	methtok = json_get_member(plugin->buffer, toks, "method");
+	paramstok = json_get_member(plugin->buffer, toks, "params");
+	resulttok = json_get_member(plugin->buffer, toks, "result");
+	errortok = json_get_member(plugin->buffer, toks, "error");
 	idtok = json_get_member(plugin->buffer, toks, "id");
 
-	if (!idtok) {
-		plugin_kill(plugin, "JSON-RPC response does not contain an \"id\"-field");
+	if (!jrtok) {
+		plugin_kill(
+		    plugin,
+		    "JSON-RPC message does not contain \"jsonrpc\" field");
 		return false;
 	}
 
-	/* We only send u64 ids, so if this fails it's a critical error (note
-	 * that this also works if id is inside a JSON string!). */
-	if (!json_to_u64(plugin->buffer, idtok, &id)) {
-		plugin_kill(plugin, "JSON-RPC response \"id\"-field is not a u64");
-		return false;
+	if (!idtok && methtok && paramstok) {
+		/* A Notification is a Request object without an "id"
+		 * member. A Request object that is a Notification
+		 * signifies the Client's lack of interest in the
+		 * corresponding Response object, and as such no
+		 * Response object needs to be returned to the
+		 * client. The Server MUST NOT reply to a
+		 * Notification, including those that are within a
+		 * batch request.
+		 *
+		 * https://www.jsonrpc.org/specification#notification
+		 */
+		plugin_notification_handle(plugin, methtok, paramstok);
+
+	} else if (idtok && (errortok || resulttok)) {
+		/* When a rpc call is made, the Server MUST reply with
+		 * a Response, except for in the case of
+		 * Notifications. The Response is expressed as a
+		 * single JSON Object, with the following members:
+		 *
+		 * - jsonrpc: A String specifying the version of the
+		 *   JSON-RPC protocol. MUST be exactly "2.0".
+		 *
+		 * - result: This member is REQUIRED on success. This
+		 *   member MUST NOT exist if there was an error
+		 *   invoking the method. The value of this member is
+		 *   determined by the method invoked on the Server.
+		 *
+		 * - error: This member is REQUIRED on error. This
+		 *   member MUST NOT exist if there was no error
+		 *   triggered during invocation.
+		 *
+		 * - id: This member is REQUIRED. It MUST be the same
+		 *   as the value of the id member in the Request
+		 *   Object. If there was an error in detecting the id
+		 *   in the Request object (e.g. Parse error/Invalid
+		 *   Request), it MUST be Null. Either the result
+		 *   member or error member MUST be included, but both
+		 *   members MUST NOT be included.
+		 *
+		 * https://www.jsonrpc.org/specification#response_object
+		 */
+		plugin_response_handle(plugin, toks, idtok);
+	} else {
+		plugin_kill(plugin,
+			    "Message '%.*s' is not a valid JSON-RPC response "
+			    "or notification.",
+			    toks[0].end, plugin->buffer);
 	}
 
-	request = uintmap_get(&plugin->plugins->pending_requests, id);
-
-	if (!request) {
-		plugin_kill(plugin, "Received a JSON-RPC response for non-existent request");
-		return false;
-	}
-
-	/* We expect the request->cb to copy if needed */
-	request->cb(request, plugin->buffer, toks, idtok, request->arg);
-	tal_free(request);
-	uintmap_del(&plugin->plugins->pending_requests, id);
-
 	/* Move this object out of the buffer */
 	memmove(plugin->buffer, plugin->buffer + toks[0].end,
 		tal_count(plugin->buffer) - toks[0].end);
@@ -314,7 +432,7 @@ static struct io_plan *plugin_read_json(struct io_conn *conn UNUSED,
 	/* Read and process all messages from the connection */
 	do {
 		success = plugin_read_json_one(plugin);
-	} while (success);
+	} while (success && ! plugin->stop);
 
 	if (plugin->stop)
 		return io_close(plugin->stdout_conn);
@@ -777,6 +895,7 @@ void plugins_init(struct plugins *plugins, const char *dev_plugin_debug)
 	plugins->pending_manifests = 0;
 	uintmap_init(&plugins->pending_requests);
 
+	setenv("LIGHTNINGD_PLUGIN", "1", 1);
 	/* Spawn the plugin processes before entering the io_loop */
 	list_for_each(&plugins->plugins, p, list) {
 		bool debug;

tests/test_plugin.py

@@ -28,7 +28,7 @@ def test_option_passthrough(node_factory):
 
     # Now try to see if it gets accepted, would fail to start if the
     # option didn't exist
-    n = node_factory.get_node(options={'plugin': plugin_path, 'greeting': 'Mars'})
+    n = node_factory.get_node(options={'plugin': plugin_path, 'greeting': 'Ciao'})
     n.stop()
 
 
@@ -40,16 +40,20 @@ def test_rpc_passthrough(node_factory):
 
     """
     plugin_path = 'contrib/plugins/helloworld.py'
-    n = node_factory.get_node(options={'plugin': plugin_path, 'greeting': 'Mars'})
+    n = node_factory.get_node(options={'plugin': plugin_path, 'greeting': 'Ciao'})
 
     # Make sure that the 'hello' command that the helloworld.py plugin
     # has registered is available.
     cmd = [hlp for hlp in n.rpc.help()['help'] if 'hello' in hlp['command']]
     assert(len(cmd) == 1)
 
+    # While we're at it, let's check that helloworld.py is logging
+    # correctly via the notifications plugin->lightningd
+    assert n.daemon.is_in_log('Plugin helloworld.py initialized')
+
     # Now try to call it and see what it returns:
-    greet = n.rpc.hello(name='Sun')
-    assert(greet == "Hello Sun")
+    greet = n.rpc.hello(name='World')
+    assert(greet == "Ciao World")
     with pytest.raises(RpcError):
         n.rpc.fail()