Fix and improve logging output

Author: cburgdorf

tests/trinity/integration/test_trinity_cli.py

@@ -87,7 +87,7 @@ async def test_txpool_deactivated(async_process_runner, command):
     assert await contains_all(async_process_runner.stderr, {
         "Started DB server process",
         "Started networking process",
-        "The transaction pool is not yet available in light mode",
+        "Transaction pool not available in light mode",
     })
 
 

trinity/events.py

@@ -4,4 +4,6 @@
 
 
 class ShutdownRequest(BaseEvent):
-    pass
+
+    def __init__(self, reason: str="") -> None:
+        self.reason = reason

trinity/extensibility/plugin.py

@@ -64,9 +64,9 @@ def __init__(self, endpoint: Endpoint) -> None:
         self.args: Namespace = None
         self.trinity_config: TrinityConfig = None
 
-    def shutdown_host(self) -> None:
+    def shutdown_host(self, reason: str) -> None:
         self.event_bus.broadcast(
-            ShutdownRequest(),
+            ShutdownRequest(reason),
             BroadcastConfig(filter_endpoint=MAIN_EVENTBUS_ENDPOINT)
         )
 

trinity/main.py

@@ -262,7 +262,8 @@ def trinity_boot(args: Namespace,
             networking_process,
             plugin_manager,
             main_endpoint,
-            event_bus
+            event_bus,
+            ev.reason
         )
     )
 
@@ -279,7 +280,8 @@ def trinity_boot(args: Namespace,
             networking_process,
             plugin_manager,
             main_endpoint,
-            event_bus
+            event_bus,
+            reason="CTRL+C / Keyboard Interrupt"
         )
 
 
@@ -289,7 +291,7 @@ def kill_trinity_gracefully(logger: logging.Logger,
                             plugin_manager: PluginManager,
                             main_endpoint: Endpoint,
                             event_bus: EventBus,
-                            message: str="Trinity shudown complete\n") -> None:
+                            reason: str=None) -> None:
     # When a user hits Ctrl+C in the terminal, the SIGINT is sent to all processes in the
     # foreground *process group*, so both our networking and database processes will terminate
     # at the same time and not sequentially as we'd like. That shouldn't be a problem but if
@@ -300,7 +302,9 @@ def kill_trinity_gracefully(logger: logging.Logger,
     # Notice that we still need the kill_process_gracefully() calls here, for when the user
     # simply uses 'kill' to send a signal to the main process, but also because they will
     # perform a non-gracefull shutdown if the process takes too long to terminate.
-    logger.info('Keyboard Interrupt: Stopping')
+
+    hint = f"({reason})" if reason else f""
+    logger.info('Shutting down Trinity %s', hint)
     plugin_manager.shutdown_blocking()
     main_endpoint.stop()
     event_bus.stop()
@@ -312,9 +316,7 @@ def kill_trinity_gracefully(logger: logging.Logger,
             kill_process_gracefully(process, logger)
         logger.info('%s process (pid=%d) terminated', name, process.pid)
 
-    # This is required to be within the `kill_trinity_gracefully` so that
-    # plugins can trigger a shutdown of the trinity process.
-    ArgumentParser().exit(message=message)
+    ArgumentParser().exit(message=f"Trinity shutdown complete {hint}\n")
 
 
 @setup_cprofiler('run_database_process')

trinity/plugins/builtin/ethstats/plugin.py

@@ -81,14 +81,14 @@ def ready(self) -> None:
             self.logger.error(
                 'You must provide ethstats server url using the `--ethstats-server-url`'
             )
-            self.context.shutdown_host()
+            self.context.shutdown_host("Missing EthStats Server URL")
             return
 
         if not args.ethstats_server_secret:
             self.logger.error(
                 'You must provide ethstats server secret using `--ethstats-server-secret`'
             )
-            self.context.shutdown_host()
+            self.context.shutdown_host("Missing EthStats Server Secret")
             return
 
         if (args.ethstats_server_url):

trinity/plugins/builtin/tx_pool/plugin.py

@@ -62,8 +62,9 @@ def ready(self) -> None:
         unsupported = self.context.args.tx_pool and light_mode
 
         if unsupported:
-            self.logger.error('The transaction pool is not yet available in light mode')
-            self.context.shutdown_host()
+            unsupported_msg = "Transaction pool not available in light mode"
+            self.logger.error(unsupported_msg)
+            self.context.shutdown_host(unsupported_msg)
 
         self.event_bus.subscribe(ResourceAvailableEvent, self.handle_event)