Improve shutdown, add more logs.

We get an unexpected 1 minute delay at shutdown. This should help to find out why it happens Signed-off-by: HenrikJannsen <[email protected]>
HenrikJannsen · Aug 11, 2024 · 602549e · 602549e
1 parent bbd53f1
commit 602549e
Show file tree

Hide file tree

Showing 5 changed files with 36 additions and 29 deletions.
diff --git a/core/src/main/java/bisq/core/app/misc/ExecutableForAppWithP2p.java b/core/src/main/java/bisq/core/app/misc/ExecutableForAppWithP2p.java
@@ -203,23 +203,30 @@ public void gracefulShutDown(ResultHandler resultHandler) {
                 injector.getInstance(RpcService.class).shutDown();
                 injector.getInstance(DaoSetup.class).shutDown();
                 injector.getInstance(ArbitratorManager.class).shutDown();
-                injector.getInstance(OpenOfferManager.class).shutDown(() -> injector.getInstance(P2PService.class).shutDown(() -> {
-                    injector.getInstance(WalletsSetup.class).shutDownComplete.addListener((ov, o, n) -> {
-                        module.close(injector);
-
-                        PersistenceManager.flushAllDataToDiskAtShutdown(() -> {
-                            resultHandler.handleResult();
-                            log.info("Graceful shutdown completed. Exiting now.");
-                            UserThread.runAfter(() -> System.exit(BisqExecutable.EXIT_SUCCESS), 1);
+                injector.getInstance(OpenOfferManager.class).shutDown(() -> {
+                    log.info("OpenOfferManager shutdown done");
+                    injector.getInstance(P2PService.class).shutDown(() -> {
+                        log.info("P2PService shutdown done");
+                        injector.getInstance(WalletsSetup.class).shutDownComplete.addListener((ov, o, n) -> {
+                            log.info("WalletsSetup shutdown done");
+                            module.close(injector);
+                            PersistenceManager.flushAllDataToDiskAtShutdown(() -> {
+                                log.info("flushAllDataToDiskAtShutdown done");
+                                resultHandler.handleResult();
+                                log.info("Graceful shutdown completed. Exiting now.");
+                                UserThread.runAfter(() -> System.exit(BisqExecutable.EXIT_SUCCESS), 1);
+                            });
                         });
+
+                        injector.getInstance(WalletsSetup.class).shutDown();
+                        injector.getInstance(BtcWalletService.class).shutDown();
+                        injector.getInstance(BsqWalletService.class).shutDown();
                     });
-                    injector.getInstance(WalletsSetup.class).shutDown();
-                    injector.getInstance(BtcWalletService.class).shutDown();
-                    injector.getInstance(BsqWalletService.class).shutDown();
-                }));
+                });
                 // we wait max 5 sec.
                 UserThread.runAfter(() -> {
                     PersistenceManager.flushAllDataToDiskAtShutdown(() -> {
+                        log.info("flushAllDataToDiskAtShutdown done from timeout");
                         resultHandler.handleResult();
                         log.info("Graceful shutdown caused a timeout. Exiting now.");
                         UserThread.runAfter(() -> System.exit(BisqExecutable.EXIT_SUCCESS), 1);
@@ -232,11 +239,10 @@ public void gracefulShutDown(ResultHandler resultHandler) {
                 }, 1);
             }
         } catch (Throwable t) {
-            log.debug("App shutdown failed with exception");
-            t.printStackTrace();
+            log.warn("App shutdown failed with exception", t);
             PersistenceManager.flushAllDataToDiskAtShutdown(() -> {
                 resultHandler.handleResult();
-                log.info("Graceful shutdown resulted in an error. Exiting now.");
+                log.warn("Graceful shutdown resulted in an error. Exiting now.");
                 UserThread.runAfter(() -> System.exit(BisqExecutable.EXIT_FAILURE), 1);
             });
 

diff --git a/p2p/src/main/java/bisq/network/p2p/network/Connection.java b/p2p/src/main/java/bisq/network/p2p/network/Connection.java
@@ -475,14 +475,14 @@ public void shutDown(CloseConnectionReason closeConnectionReason) {
     }
 
     public void shutDown(CloseConnectionReason closeConnectionReason, @Nullable Runnable shutDownCompleteHandler) {
-        log.debug("shutDown: peersNodeAddressOptional={}, closeConnectionReason={}",
+        log.info("shutDown: peersNodeAddressOptional={}, closeConnectionReason={}",
                 peersNodeAddressOptional, closeConnectionReason);
 
         connectionState.shutDown();
 
         if (!stopped) {
             String peersNodeAddress = peersNodeAddressOptional.map(NodeAddress::toString).orElse("null");
-            log.debug("\n\n%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%\n" +
+            log.info("\n\n%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%\n" +
                     "ShutDown connection:"
                     + "\npeersNodeAddress=" + peersNodeAddress
                     + "\ncloseConnectionReason=" + closeConnectionReason
@@ -506,42 +506,41 @@ public void shutDown(CloseConnectionReason closeConnectionReason, @Nullable Runn
                         stopped = true;
                         UserThread.execute(() -> doShutDown(closeConnectionReason, shutDownCompleteHandler));
                     }
-                }, "Connection:SendCloseConnectionMessage-" + this.uid).start();
+                }, "Connection:SendCloseConnectionMessage-" + this.uid)
+                        .start();
             } else {
                 stopped = true;
                 doShutDown(closeConnectionReason, shutDownCompleteHandler);
             }
         } else {
             //TODO find out why we get called that
-            log.debug("stopped was already at shutDown call");
+            log.warn("stopped was already at shutDown call");
             UserThread.execute(() -> doShutDown(closeConnectionReason, shutDownCompleteHandler));
         }
     }
 
     private void doShutDown(CloseConnectionReason closeConnectionReason, @Nullable Runnable shutDownCompleteHandler) {
         // Use UserThread.execute as it's not clear if that is called from a non-UserThread
         UserThread.execute(() -> connectionListener.onDisconnect(closeConnectionReason, this));
+
         try {
             protoOutputStream.onConnectionShutdown();
             socket.close();
         } catch (SocketException e) {
-            log.trace("SocketException at shutdown might be expected {}", e.getMessage());
+            log.error("SocketException at shutdown might be expected {}", e.getMessage());
         } catch (IOException e) {
-            log.error("Exception at shutdown. " + e.getMessage());
-            e.printStackTrace();
+            log.error("Exception at shutdown. ", e);
         } finally {
             capabilitiesListeners.clear();
 
             try {
                 protoInputStream.close();
-            } catch (IOException e) {
-                log.error(e.getMessage());
-                e.printStackTrace();
+            } catch (IOException ignore) {
             }
 
             Utilities.shutdownAndAwaitTermination(executorService, SHUTDOWN_TIMEOUT, TimeUnit.MILLISECONDS);
 
-            log.debug("Connection shutdown complete {}", this);
+            log.info("Connection shutdown complete {}", this);
             // Use UserThread.execute as it's not clear if that is called from a non-UserThread
             if (shutDownCompleteHandler != null)
                 UserThread.execute(shutDownCompleteHandler);

diff --git a/p2p/src/main/java/bisq/network/p2p/network/NetworkNode.java b/p2p/src/main/java/bisq/network/p2p/network/NetworkNode.java
@@ -363,6 +363,7 @@ public void shutDown(Runnable shutDownCompleteHandler) {
                 server.shutDown();
                 server = null;
             }
+            log.info("server shutdown completed");
 
             Set<Connection> allConnections = getAllConnections();
             int numConnections = allConnections.size();

diff --git a/p2p/src/main/java/bisq/network/p2p/network/Server.java b/p2p/src/main/java/bisq/network/p2p/network/Server.java
@@ -115,11 +115,11 @@ public void shutDown() {
                     serverSocket.close();
                 }
             } catch (SocketException e) {
-                log.debug("SocketException at shutdown might be expected " + e.getMessage());
+                log.warn("SocketException at shutdown might be expected " + e.getMessage());
             } catch (IOException e) {
-                log.debug("Exception at shutdown. " + e.getMessage());
+                log.warn("Exception at shutdown. " + e.getMessage());
             } finally {
-                log.debug("Server shutdown complete");
+                log.info("Server shutdown complete");
             }
         } else {
             log.warn("stopped already called ast shutdown");

diff --git a/seednode/src/main/java/bisq/seednode/SeedNode.java b/seednode/src/main/java/bisq/seednode/SeedNode.java
@@ -50,6 +50,7 @@ public void startApplication() {
     }
 
     public void shutDown() {
+        log.info("shutDown");
         if (getInventoryRequestHandler != null) {
             getInventoryRequestHandler.shutDown();
         }