Improved logging

src/gismo/application.py

@@ -21,6 +21,7 @@ class Application(ApplicationABC):
 
     async def main(self):
         try:
+            self._logger.trace(__name__, f'Try to start {BotService}')
             await self._bot.start_async()
         except Exception as e:
             self._logger.error(__name__, 'Start failed', e)

src/gismo/appsettings.edrafts-lapi.json

@@ -0,0 +1,2 @@
+{
+}

src/gismo/startup.py

@@ -1,7 +1,12 @@
+from datetime import datetime
+from typing import Optional
+
 from cpl_core.application import StartupABC
 from cpl_core.configuration import ConfigurationABC
-from cpl_core.dependency_injection import ServiceCollectionABC, ServiceProviderABC
+from cpl_core.dependency_injection import (ServiceCollectionABC,
+                                           ServiceProviderABC)
 from cpl_core.environment import ApplicationEnvironment
+from cpl_core.logging.logger_abc import LoggerABC
 
 from gismo_core.abc.bot_service_abc import BotServiceABC
 from gismo_core.service.bot_service import BotService
@@ -15,6 +20,9 @@ class Startup(StartupABC):
 
     def __init__(self):
         StartupABC.__init__(self)
+        self._start_time = datetime.now()
+        
+        self._config: Optional[ConfigurationABC] = None
 
     async def configure_configuration(self, configuration: ConfigurationABC, environment: ApplicationEnvironment) -> ConfigurationABC:
         configuration.add_environment_variables('GISMO_')
@@ -23,6 +31,9 @@ class Startup(StartupABC):
         configuration.add_json_file(f'appsettings.{environment.environment_name}.json', optional=True)
         configuration.add_json_file(f'appsettings.{environment.host_name}.json', optional=True)
         
+        configuration.add_configuration('Startup_StartTime', self._start_time)
+        
+        self._config = configuration
         return configuration
 
     async def configure_services(self, services: ServiceCollectionABC, environment: ApplicationEnvironment) -> ServiceProviderABC:
@@ -33,4 +44,11 @@ class Startup(StartupABC):
         
         services.add_transient(ModuleABC, BootLog)
         
-        return services.build_service_provider()
+        provider: ServiceProviderABC = services.build_service_provider()
+        
+        startup_init_time = round((datetime.now() - self._config.get_configuration('Startup_StartTime')).total_seconds(), 2)
+        self._config.add_configuration('Startup_InitTime', startup_init_time)
+        logger: LoggerABC = provider.get_service(LoggerABC)
+        logger.debug(__name__, f'Startup Init time:  {startup_init_time}s')
+        
+        return provider

src/gismo_core/service/bot_service.py

@@ -27,9 +27,11 @@ class BotService(BotServiceABC, commands.Bot):
         # continue at on_ready
         
     async def on_ready(self):
+        self._logger.info(__name__, 'Connected to discord')
         await self._modules.start_modules()
 
     async def stop_async(self):
+        self._logger.debug(__name__, f'Try to stop {BotService}')
         try:
             pass
             # save data

src/modules/boot_log/boot_log.py

@@ -16,13 +16,15 @@ class BootLog(ModuleABC):
         self._logger = logger
         self._bot = bot
         ModuleABC.__init__(self)
+        self._logger.trace(__name__, f'Module {type(self)} loaded')
 
     async def on_ready(self):
-        self._logger.info(__name__, f'Bot started')
+        self._logger.debug(__name__, f'Module {type(self)} started')
         try:
-            start_time = self._config.get_configuration('StartTime')
+            start_time = self._config.get_configuration('Bot_StartTime')
             init_time = round((datetime.now() - start_time).total_seconds(), 2)
-            self._logger.info(__name__, f'Init time:  {init_time}s')
+            self._config.add_configuration('InitTime', init_time)
+            self._logger.debug(__name__, f'Bot Init time:  {init_time}s')
             # print warning if initialisation took too long
             if init_time >= 30:
                 self._logger.warn(__name__, 'It takes long time to start the bot!')
@@ -36,4 +38,6 @@ class BootLog(ModuleABC):
         
         self._logger.header(f'{self._bot.user.name}:')
         if self._logging_st.console.value >= LoggingLevelEnum.INFO.value:
-            Console.banner(self._bot.user.name)
+            Console.banner(self._bot.user.name)
+        
+        self._logger.trace(__name__, f'Module {type(self)} stopped')

src/modules/boot_log/boot_log_extension.py

@@ -13,5 +13,5 @@ class BootLogExtension(ApplicationExtensionABC):
 
     async def run(self, config: ConfigurationABC, services: ServiceProviderABC):
         logger: LoggerABC = services.get_service(LoggerABC)
-        logger.trace(__name__, 'Boot extension started')
-        config.add_configuration('StartTime', datetime.now())
+        logger.debug(__name__, 'BootLog extension started')
+        config.add_configuration('Bot_StartTime', datetime.now())

src/modules_core/service/module_service.py

@@ -1,14 +1,11 @@
 from os import path
 
 import discord
-from cpl_core.dependency_injection.service_provider_abc import \
-    ServiceProviderABC
-from cpl_core.environment.application_environment_abc import \
-    ApplicationEnvironmentABC
+from cpl_core.dependency_injection import ServiceProviderABC
+from cpl_core.environment import ApplicationEnvironmentABC
 from cpl_core.logging import LoggerABC
 from cpl_query.extension import List
 from discord.ext import commands
-
 from modules_core.abc.module_abc import ModuleABC
 from modules_core.abc.module_service_abc import ModuleServiceABC
 
@@ -23,6 +20,7 @@ class ModuleService(ModuleServiceABC):
         self._modules.extend(ModuleABC.__subclasses__())
 
     async def start_modules(self):
+        self._logger.trace(__name__, 'Start loading modules')
         modules = self._modules.where(lambda m: hasattr(m, 'on_ready') and callable(m.on_ready))
         for module_type in modules:
             module = self._services.get_service(module_type)