Merge #1037

1037: Fix DaedalusIPC race-condition when sending 'Started' too quickly r=KtorZ a=KtorZ

# Issue Number

<!-- Put here a reference to the issue this PR relates to and which requirements it tackles -->

#1036 

# Overview

<!-- Detail in a few bullet points the work accomplished in this PR -->

- [x] I have artificially reproduced the issue in our mock-daedalus and saw it fails (wait infinitely)
- [x] I have added some retry logic to re-send `Started` every second if Daedalus has shown any sign of life.


# Comments

<!-- Additional comments or screenshots to attach if any -->

<!-- 
Don't forget to:

 ✓ Self-review your changes to make sure nothing unexpected slipped through
 ✓ Assign yourself to the PR
 ✓ Assign one or several reviewer(s)
 ✓ Once created, link this PR to its corresponding ticket
 ✓ Acknowledge any changes required to the Wiki
-->


Co-authored-by: KtorZ <matthias.benkort@gmail.com>

lib/core/src/Cardano/Wallet/DaedalusIPC.hs

@@ -26,11 +26,11 @@ import Control.Concurrent
 import Control.Concurrent.Async
     ( concurrently_, race )
 import Control.Concurrent.MVar
-    ( MVar, newEmptyMVar, putMVar, takeMVar )
+    ( MVar, isEmptyMVar, newEmptyMVar, putMVar, takeMVar, tryPutMVar )
 import Control.Exception
     ( IOException, catch, tryJust )
 import Control.Monad
-    ( forever )
+    ( forever, void )
 import Data.Aeson
     ( FromJSON (..)
     , ToJSON (..)
@@ -107,28 +107,41 @@ daedalusIPC
     -> Int
     -- ^ Port number to send to Daedalus
     -> IO ()
-daedalusIPC trace port = withNodeChannel (pure . msg) action >>= \case
-    Right runServer -> do
-        logInfo trace "Daedalus IPC server starting"
-        runServer >>= \case
-            Left (NodeChannelFinished err) ->
-                logNotice trace $ fmt $
-                "Daedalus IPC finished for this reason: "+||err||+""
-            Right () -> logError trace "Unreachable code"
-    Left NodeChannelDisabled -> do
-        logInfo trace "Daedalus IPC is not enabled."
-        sleep
-    Left (NodeChannelBadFD err) ->
-        logError trace $ fmt $ "Problem starting Daedalus IPC: "+||err||+""
+daedalusIPC trace port = do
+    started <- newEmptyMVar
+    withNodeChannel (onMsg started) (action started) >>= \case
+        Right runServer -> do
+            logInfo trace "Daedalus IPC server starting"
+            runServer >>= \case
+                Left (NodeChannelFinished err) ->
+                    logNotice trace $ fmt $
+                    "Daedalus IPC finished for this reason: "+||err||+""
+                Right () -> logError trace "Unreachable code"
+        Left NodeChannelDisabled -> do
+            logInfo trace "Daedalus IPC is not enabled."
+            sleep
+        Left (NodeChannelBadFD err) ->
+            logError trace $ fmt $ "Problem starting Daedalus IPC: "+||err||+""
   where
-    -- How to respond to an incoming message, or when there is an incoming
-    -- message that couldn't be parsed.
-    msg (Right QueryPort) = Just (ReplyPort port)
-    msg (Left e) = Just (ParseError e)
+    onMsg :: MVar Bool -> Either Text MsgIn -> IO (Maybe MsgOut)
+    onMsg started msg = do
+        -- A sign of life detected from Daedalus, means we can stop sending
+        -- "Started" every second.
+        void $ tryPutMVar started True
+        -- How to respond to an incoming message, or when there is an incoming
+        -- message that couldn't be parsed.
+        pure $ case msg of
+            Right QueryPort -> Just (ReplyPort port)
+            Left e -> Just (ParseError e)
 
     -- What to do in context of withNodeChannel
-    action :: (MsgOut -> IO ()) -> IO ()
-    action send = send Started >> sleep
+    action :: MVar Bool -> (MsgOut -> IO ()) -> IO ()
+    action started send = isEmptyMVar started >>= \case
+        False -> sleep
+        True  -> do
+            send Started
+            threadDelay (1000*1000) -- One second
+            action started send
 
     sleep = threadDelay maxBound
 

lib/jormungandr/src/Cardano/Wallet/Jormungandr.hs

@@ -91,7 +91,7 @@ import Cardano.Wallet.Primitive.Types
 import Cardano.Wallet.Transaction
     ( TransactionLayer )
 import Control.Concurrent
-    ( forkFinally, threadDelay )
+    ( forkFinally )
 import Control.Concurrent.Async
     ( race )
 import Control.DeepSeq
@@ -160,14 +160,7 @@ serveWallet (cfg, tr) sTolerance databaseDir hostPref listen lj beforeMainLoop =
         Left e -> handleApiServerStartupError e
         Right (wPort, socket) -> either (const ExitSuccess) id <$> do
             let tracerIPC = appendName "daedalus-ipc" tr
-            -- FIXME
-            -- There's an ugly pause of 1s here for lack of a better fix. There
-            -- seem to be a race-condition on Daedalus' side which isn't able to
-            -- pick up the 'Started' message if we send it too quickly...
-            -- There shouldn't be any issue for us to resend the 'Started'
-            -- message multiple time if we haven't received 'QueryPort' after a
-            -- while and that would be a better way to fix this!
-            race (threadDelay oneSecond *> daedalusIPC tracerIPC wPort) $ do
+            race (daedalusIPC tracerIPC wPort) $ do
                 withNetworkLayer tr lj $ \case
                     Left e -> handleNetworkStartupError e
                     Right (cp, nl) -> do
@@ -320,10 +313,6 @@ serveWallet (cfg, tr) sTolerance databaseDir hostPref listen lj beforeMainLoop =
 -- Exported Utilities
 --------------------------------------------------------------------------------
 
--- | One second in micro seconds
-oneSecond :: Int
-oneSecond = 1000 * 1000
-
 -- | Covert a raw block to one that the "Cardano.Pool.Metrics" module accepts.
 toSPBlock :: J.Block -> Pool.Block
 toSPBlock b = Pool.Block

lib/jormungandr/test/integration/js/mock-daedalus.js

@@ -35,34 +35,42 @@ function main() {
     process.exit(4);
   });
 
-  proc.on("message", function(msg) {
-    console.log("JS: message received", msg);
-    // See CardanoNode.js in Daedalus for the message types in use.
-    if (msg.Started) {
-      console.log("JS: sending a bogus message");
-      proc.send("hello");
-    } else if (msg.ParseError && msg.ParseError.match(/encountered String/)) {
-      console.log("JS: sending QueryPort");
-      proc.send({ QueryPort: [] });
-    } else if (msg.ParseError) {
-      console.log("JS: i did not expect that");
-      process.exit(5);
-    } else if (msg.ReplyPort) {
-      http.get({
-        hostname: "localhost",
-        port: msg.ReplyPort,
-        path: "/v2/wallets",
-        agent: false
-      }, (res) => {
-        console.log("JS: response from wallet: " + res.statusCode);
-        res.resume();
-        res.on("end", () => {
-          console.log("JS: request response from wallet finished, exiting.");
-          process.exit(0);
+
+  const installHandler = () => {
+    proc.on("message", function(msg) {
+      console.log("JS: message received", msg);
+      // See CardanoNode.js in Daedalus for the message types in use.
+      if (msg.Started) {
+        console.log("JS: sending a bogus message");
+        proc.send("hello");
+      } else if (msg.ParseError && msg.ParseError.match(/encountered String/)) {
+        console.log("JS: sending QueryPort");
+        proc.send({ QueryPort: [] });
+      } else if (msg.ParseError) {
+        console.log("JS: i did not expect that");
+        process.exit(5);
+      } else if (msg.ReplyPort) {
+        http.get({
+          hostname: "localhost",
+          port: msg.ReplyPort,
+          path: "/v2/wallets",
+          agent: false
+        }, (res) => {
+          console.log("JS: response from wallet: " + res.statusCode);
+          res.resume();
+          res.on("end", () => {
+            console.log("JS: request response from wallet finished, exiting.");
+            process.exit(0);
+          });
         });
-      });
-    }
-  });
+      }
+    });
+  };
+
+  // NOTE
+  // We artifically install the handler after a certain delay (2s), to simulate the race
+  // condition that could actually happen in practice.
+  setTimeout(installHandler, 2000);
 }
 
 main();