pyln: Plugin methods and hooks refuse to set results twice

We had a couple of instances where a plugin would be killed by `lightningd`
because we were returning a result of an exception twice, and it was hard to
trace down the logic error in the user plugin that caused that. This patch
adds a traceback the first time we return a result/exception, and raise an
exception with a stacktrace of the first termination when a second one comes
in.

This can still terminate the plugin, but the programmer gets a clear
indication where the result was set, and can potentially even recover from it.

Changelog-Added: pyln: Plugin method and hook requests prevent the plugin developer from accidentally setting the result multiple times, and will raise an exception detailing where the result was first set.

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

@@ -69,6 +69,7 @@ def __init__(self, plugin: 'Plugin', req_id: Optional[int], method: str,
         self.plugin = plugin
         self.state = RequestState.PENDING
         self.id = req_id
+        self.termination_tb: Optional[str] = None
 
     def getattr(self, key: str) -> Union[Method, Any, int]:
         if key == "params":
@@ -84,21 +85,27 @@ def getattr(self, key: str) -> Union[Method, Any, int]:
 
     def set_result(self, result: Any) -> None:
         if self.state != RequestState.PENDING:
+            assert(self.termination_tb is not None)
             raise ValueError(
                 "Cannot set the result of a request that is not pending, "
-                "current state is {state}".format(state=self.state))
+                "current state is {state}. Request previously terminated at\n"
+                "{tb}".format(state=self.state, tb=self.termination_tb))
         self.result = result
         self._write_result({
             'jsonrpc': '2.0',
             'id': self.id,
             'result': self.result
         })
+        self.state = RequestState.FINISHED
+        self.termination_tb = "".join(traceback.extract_stack().format()[:-1])
 
     def set_exception(self, exc: Exception) -> None:
         if self.state != RequestState.PENDING:
+            assert(self.termination_tb is not None)
             raise ValueError(
                 "Cannot set the exception of a request that is not pending, "
-                "current state is {state}".format(state=self.state))
+                "current state is {state}. Request previously terminated at\n"
+                "{tb}".format(state=self.state, tb=self.termination_tb))
         self.exc = exc
         self._write_result({
             'jsonrpc': '2.0',
@@ -111,6 +118,8 @@ def set_exception(self, exc: Exception) -> None:
                 "traceback": traceback.format_exc(),
             },
         })
+        self.state = RequestState.FAILED
+        self.termination_tb = "".join(traceback.extract_stack().format()[:-1])
 
     def _write_result(self, result: dict) -> None:
         self.plugin._write_locked(result)

contrib/pyln-client/tests/test_plugin.py

@@ -362,3 +362,43 @@ def test1(msat: Millisatoshi):
 
     ba = p._bind_pos(test1, ["100msat"], None)
     test1(*ba.args, **ba.kwargs)
+
+
+def test_duplicate_result():
+    p = Plugin(autopatch=False)
+
+    def test1(request):
+        request.set_result(1)     # MARKER1
+        request.set_result(1)
+
+    req = Request(p, req_id=1, method="test1", params=[])
+    ba = p._bind_kwargs(test1, {}, req)
+    with pytest.raises(ValueError, match=r'current state is RequestState\.FINISHED(.*\n.*)*MARKER1'):
+        test1(*ba.args)
+
+    def test2(request):
+        request.set_exception(1)  # MARKER2
+        request.set_exception(1)
+
+    req = Request(p, req_id=2, method="test2", params=[])
+    ba = p._bind_kwargs(test2, {}, req)
+    with pytest.raises(ValueError, match=r'current state is RequestState\.FAILED(.*\n*.*)*MARKER2'):
+        test2(*ba.args)
+
+    def test3(request):
+        request.set_exception(1)  # MARKER3
+        request.set_result(1)
+
+    req = Request(p, req_id=3, method="test3", params=[])
+    ba = p._bind_kwargs(test3, {}, req)
+    with pytest.raises(ValueError, match=r'current state is RequestState\.FAILED(.*\n*.*)*MARKER3'):
+        test3(*ba.args)
+
+    def test4(request):
+        request.set_result(1)     # MARKER4
+        request.set_exception(1)
+
+    req = Request(p, req_id=4, method="test4", params=[])
+    ba = p._bind_kwargs(test4, {}, req)
+    with pytest.raises(ValueError, match=r'current state is RequestState\.FINISHED(.*\n*.*)*MARKER4'):
+        test4(*ba.args)