Merge #52: Add logging support

README.md

@@ -17,6 +17,7 @@ A [customizable](/config/template_config.ini), [multilanguage](/strings) Telegra
 
 1. Download the project files through `git clone https://github.com/Steffo99/greed.git` (recommended) or [this link](https://github.com/Steffo99/greed/archive/master.zip).
 2. Install the project requirements with `pip install -r requirements.txt`
+3. _Optional: run `pip install coloredlogs` to have colored logging output._
 3. Run `python -OO core.py` to generate the configuration file.
 4. Open the config folder and edit the `config.ini` file following the contained instructions.  
 Ensure the `is_template` field is set to `no`.

config/template_config.ini

@@ -5,7 +5,7 @@
 # Config file parameters
 [Config]
 ; Config file version. DO NOT EDIT THIS!
-version = 16
+version = 17
 ; Set this to no when you are done editing the file
 is_template = yes
 ; Language code for string file
@@ -87,3 +87,12 @@ refill_on_checkout = yes
 ; Optional sentry token: get the token at https://sentry.io/ or ask @Steffo for one
 ; Needed to automatically report bugs found by the users in the code.
 sentry_token = https://00000000000000000000000000000000:00000000000000000000000000000000@sentry.io/0000000
+
+# Logging settings
+[Logging]
+; The output format for the messages printed to the console
+; See https://docs.python.org/3/library/logging.html#logrecord-attributes for information about the {}-attributes
+format = {asctime} | {threadName} | {name} | {message}
+; Logging level: ignore all log entries with a level lower than the specified one
+; Valid options are FATAL, ERROR, WARNING, INFO, and DEBUG
+level = INFO

configloader.py

@@ -1,9 +1,16 @@
 import sys
 import os
 import configparser
+import logging
+
+
+# Logs won't show up for this file as it is imported before logging is configured
+log = logging.getLogger(__name__)
+
 
 # Check if the config file exists, and create one if it doesn't
 if not os.path.isfile("config/config.ini"):
+    log.debug("Creating config.ini from template_config.ini")
     # Open the template file and create the config file
     with open("config/template_config.ini", encoding="utf8") as template_file, \
          open("config/config.ini", "w", encoding="utf8") as config_file:
@@ -15,27 +22,34 @@ with open("config/template_config.ini", encoding="utf8") as template_file:
     config = configparser.ConfigParser()
     config.read_file(template_file)
     template_version = int(config["Config"]["version"])
+    log.debug(f"Template is version {template_version}")
 
 # Overwrite the template config with the values in the config
 with open("config/config.ini", encoding="utf8") as config_file:
     config.read_file(config_file)
+    config_version = int(config["Config"]["version"])
+    log.debug(f"Config is version {template_version}")
 
 # Check if the file has been edited
 if config["Config"]["is_template"] == "yes":
-    print("A config file has been created in config/config.ini.\n"
+    log.debug("Config is a template, aborting...")
-          "Edit it with your configuration, set the is_template flag to false and restart this script.")
+    log.fatal("A config file has been created in config/config.ini.\n"
+              "Edit it with your configuration, set the is_template flag to 'no' and restart this script.")
     sys.exit(1)
 
 # Check if the version has changed from the template
-if template_version > int(config["Config"]["version"]):
+if template_version > config_version:
+    log.debug("Config is older than Template, trying to merge...")
     # Reset the is_template flag
     config["Config"]["is_template"] = "yes"
     # Update the config version
     config["Config"]["version"] = str(template_version)
     # Save the file
     with open("config/config.ini", "w", encoding="utf8") as config_file:
+        log.debug("Writing merged config file...")
         config.write(config_file)
     # Notify the user and quit
-    print("The config file in config/config.ini has been updated.\n"
+    log.debug("Config is now a template, aborting...")
+    log.fatal("The config file in config/config.ini has been updated.\n"
               "Edit it with the new required data, set the is_template flag to true and restart this script.")
     sys.exit(1)

core.py

@@ -5,6 +5,12 @@ import configloader
 import utils
 import threading
 import importlib
+import logging
+
+try:
+    import coloredlogs
+except ImportError:
+    coloredlogs = None
 
 language = configloader.config["Config"]["language"]
 strings = importlib.import_module("strings." + language)
@@ -12,34 +18,50 @@ strings = importlib.import_module("strings." + language)
 
 def main():
     """The core code of the program. Should be run only in the main process!"""
-
     # Rename the main thread for presentation purposes
     threading.current_thread().name = "Core"
 
+    # Setup logging
+    log = logging.getLogger("core")
+    logging.root.setLevel(configloader.config["Logging"]["level"])
+    stream_handler = logging.StreamHandler()
+    if coloredlogs is not None:
+        stream_handler.formatter = coloredlogs.ColoredFormatter(configloader.config["Logging"]["format"], style="{")
+    else:
+        stream_handler.formatter = logging.Formatter(configloader.config["Logging"]["format"], style="{")
+    logging.root.handlers.clear()
+    logging.root.addHandler(stream_handler)
+    log.debug("Logging setup successfully!")
+
+    # Ignore most python-telegram-bot logs, as they are useless most of the time
+    logging.getLogger("telegram").setLevel("ERROR")
+
     # Create a bot instance
     bot = utils.DuckBot(configloader.config["Telegram"]["token"])
 
     # Test the specified token
+    log.debug("Testing bot token...")
     try:
         bot.get_me()
     except telegram.error.Unauthorized:
-        print("The token you have entered in the config file is invalid.\n"
+        logging.fatal("The token you have entered in the config file is invalid. Fix it, then restart greed.")
-              "Fix it, then restart this script.")
         sys.exit(1)
+    log.debug("Bot token is valid!")
 
-    # Create a dictionary linking the chat ids to the ChatWorker objects
+    # Create a dictionary linking the chat ids to the Worker objects
-    # {"1234": <ChatWorker>}
+    # {"1234": <Worker>}
     chat_workers = {}
 
     # Current update offset; if None it will get the last 100 unparsed messages
     next_update = None
 
     # Notify on the console that the bot is starting
-    print("greed-bot is now starting!")
+    log.info("greed is starting!")
 
     # Main loop of the program
     while True:
         # Get a new batch of 100 updates and mark the last 100 parsed as read
+        log.debug("Getting updates from Telegram")
         updates = bot.get_updates(offset=next_update,
                                   timeout=int(configloader.config["Telegram"]["long_polling_timeout"]))
         # Parse all the updates
@@ -48,20 +70,24 @@ def main():
             if update.message is not None:
                 # Ensure the message has been sent in a private chat
                 if update.message.chat.type != "private":
+                    log.debug(f"Received a message from a non-private chat: {update.message.chat.id}")
                     # Notify the chat
                     bot.send_message(update.message.chat.id, strings.error_nonprivate_chat)
                     # Skip the update
                     continue
                 # If the message is a start command...
                 if isinstance(update.message.text, str) and update.message.text.startswith("/start"):
+                    log.info(f"Received /start from: {update.message.chat.id}")
                     # Check if a worker already exists for that chat
                     old_worker = chat_workers.get(update.message.chat.id)
                     # If it exists, gracefully stop the worker
                     if old_worker:
+                        log.debug(f"Received request to stop {old_worker.name}")
                         old_worker.stop("request")
                     # Initialize a new worker for the chat
-                    new_worker = worker.ChatWorker(bot, update.message.chat)
+                    new_worker = worker.Worker(bot, update.message.chat)
                     # Start the worker
+                    log.debug(f"Starting {new_worker.name}")
                     new_worker.start()
                     # Store the worker in the dictionary
                     chat_workers[update.message.chat.id] = new_worker
@@ -71,6 +97,7 @@ def main():
                 receiving_worker = chat_workers.get(update.message.chat.id)
                 # Ensure a worker exists for the chat and is alive
                 if receiving_worker is None or not receiving_worker.is_alive():
+                    log.debug(f"Received a message in a chat without worker: {update.message.chat.id}")
                     # Suggest that the user restarts the chat with /start
                     bot.send_message(update.message.chat.id, strings.error_no_worker_for_chat,
                                      reply_markup=telegram.ReplyKeyboardRemove())
@@ -78,9 +105,11 @@ def main():
                     continue
                 # If the message contains the "Cancel" string defined in the strings file...
                 if update.message.text == strings.menu_cancel:
+                    log.debug(f"Forwarding CancelSignal to {receiving_worker}")
                     # Send a CancelSignal to the worker instead of the update
                     receiving_worker.queue.put(worker.CancelSignal())
                 else:
+                    log.debug(f"Forwarding message to {receiving_worker}")
                     # Forward the update to the worker
                     receiving_worker.queue.put(update)
             # If the update is a inline keyboard press...
@@ -89,17 +118,20 @@ def main():
                 receiving_worker = chat_workers.get(update.callback_query.from_user.id)
                 # Ensure a worker exists for the chat
                 if receiving_worker is None:
+                    log.debug(f"Received a callback query in a chat without worker: {update.callback_query.from_user.id}")
                     # Suggest that the user restarts the chat with /start
                     bot.send_message(update.callback_query.from_user.id, strings.error_no_worker_for_chat)
                     # Skip the update
                     continue
                 # Check if the pressed inline key is a cancel button
                 if update.callback_query.data == "cmd_cancel":
+                    log.debug(f"Forwarding CancelSignal to {receiving_worker}")
                     # Forward a CancelSignal to the worker
                     receiving_worker.queue.put(worker.CancelSignal())
                     # Notify the Telegram client that the inline keyboard press has been received
                     bot.answer_callback_query(update.callback_query.id)
                 else:
+                    log.debug(f"Forwarding callback query to {receiving_worker}")
                     # Forward the update to the worker
                     receiving_worker.queue.put(update)
             # If the update is a precheckoutquery, ensure it hasn't expired before forwarding it
@@ -107,17 +139,19 @@ def main():
                 # Forward the update to the corresponding worker
                 receiving_worker = chat_workers.get(update.pre_checkout_query.from_user.id)
                 # Check if it's the active invoice for this chat
-                if receiving_worker is None or\
+                if receiving_worker is None or \
                         update.pre_checkout_query.invoice_payload != receiving_worker.invoice_payload:
                     # Notify the user that the invoice has expired
+                    log.debug(f"Received a pre-checkout query for an expired invoice in: {update.message.chat.id}")
                     try:
                         bot.answer_pre_checkout_query(update.pre_checkout_query.id,
                                                       ok=False,
                                                       error_message=strings.error_invoice_expired)
                     except telegram.error.BadRequest:
-                        print(f"ERROR: pre_checkout_query expired before an answer could be sent")
+                        log.error("pre-checkout query expired before an answer could be sent!")
                     # Go to the next update
                     continue
+                log.debug(f"Forwarding pre-checkout query to {receiving_worker}")
                 # Forward the update to the worker
                 receiving_worker.queue.put(update)
         # If there were any updates...

utils.py

@@ -6,6 +6,12 @@ import typing
 import os
 import sys
 import importlib
+import logging
+import traceback
+
+
+log = logging.getLogger(__name__)
+
 
 language = config["Config"]["language"]
 try:
@@ -132,38 +138,38 @@ def catch_telegram_errors(func):
                 return func(*args, **kwargs)
             # Bot was blocked by the user
             except telegram.error.Unauthorized:
-                print(f"Unauthorized to call {func.__name__}(), skipping.")
+                log.debug(f"Unauthorized to call {func.__name__}(), skipping.")
                 break
             # Telegram API didn't answer in time
             except telegram.error.TimedOut:
-                print(f"Timed out while calling {func.__name__}(),"
+                log.warning(f"Timed out while calling {func.__name__}(),"
                             f" retrying in {config['Telegram']['timed_out_pause']} secs...")
                 time.sleep(int(config["Telegram"]["timed_out_pause"]))
             # Telegram is not reachable
             except telegram.error.NetworkError as error:
-                print(f"Network error while calling {func.__name__}(),"
+                log.error(f"Network error while calling {func.__name__}(),"
-                      f" retrying in {config['Telegram']['error_pause']} secs...")
+                          f" retrying in {config['Telegram']['error_pause']} secs...\n"
-                # Display the full NetworkError
+                          f"Full error: {error.message}")
-                print(f"Full error: {error.message}")
                 time.sleep(int(config["Telegram"]["error_pause"]))
             # Unknown error
             except telegram.error.TelegramError as error:
                 if error.message.lower() in ["bad gateway", "invalid server response"]:
-                    print(f"Bad Gateway while calling {func.__name__}(),"
+                    log.warning(f"Bad Gateway while calling {func.__name__}(),"
                                 f" retrying in {config['Telegram']['error_pause']} secs...")
                     time.sleep(int(config["Telegram"]["error_pause"]))
                 elif error.message.lower() == "timed out":
-                    print(f"Timed out while calling {func.__name__}(),"
+                    log.warning(f"Timed out while calling {func.__name__}(),"
                                 f" retrying in {config['Telegram']['timed_out_pause']} secs...")
                     time.sleep(int(config["Telegram"]["timed_out_pause"]))
                 else:
-                    print(f"Telegram error while calling {func.__name__}(),"
+                    log.error(f"Telegram error while calling {func.__name__}(),"
-                          f" retrying in {config['Telegram']['error_pause']} secs...")
+                              f" retrying in {config['Telegram']['error_pause']} secs...\n"
-                    # Display the full TelegramError
+                              f"Full error: {error.message}")
-                    print(f"Full error: {error.message}")
                     # Send the error to the Sentry server
                     if sentry_client is not None:
                         sentry_client.captureException(exc_info=sys.exc_info())
+                    else:
+                        traceback.print_exception(*sys.exc_info())
                     time.sleep(int(config["Telegram"]["error_pause"]))
 
     return result_func

worker.py

@@ -14,6 +14,9 @@ import traceback
 from html import escape
 import requests
 import importlib
+import logging
+
+log = logging.getLogger(__name__)
 
 language = configloader.config["Config"]["language"]
 strings = importlib.import_module("strings." + language)
@@ -21,7 +24,6 @@ strings = importlib.import_module("strings." + language)
 
 class StopSignal:
     """A data class that should be sent to the worker when the conversation has to be stopped abnormally."""
-
     def __init__(self, reason: str = ""):
         self.reason = reason
 
@@ -31,7 +33,7 @@ class CancelSignal:
     pass
 
 
-class ChatWorker(threading.Thread):
+class Worker(threading.Thread):
     """A worker for a single conversation. A new one is created every time the /start command is sent."""
 
     def __init__(self, bot: utils.DuckBot, chat: telegram.Chat, *args, **kwargs):
@@ -41,11 +43,12 @@ class ChatWorker(threading.Thread):
         self.bot: utils.DuckBot = bot
         self.chat: telegram.Chat = chat
         # Open a new database session
+        log.debug(f"Opening new database session for {self.name}")
         self.session = db.Session()
         # Get the user db data from the users and admin tables
         self.user: Optional[db.User] = None
         self.admin: Optional[db.Admin] = None
-        # The sending pipe is stored in the ChatWorker class, allowing the forwarding of messages to the chat process
+        # The sending pipe is stored in the Worker class, allowing the forwarding of messages to the chat process
         self.queue = queuem.Queue()
         # The current active invoice payload; reject all invoices with a different payload
         self.invoice_payload = None
@@ -56,13 +59,19 @@ class ChatWorker(threading.Thread):
             self.sentry_client = raven.Client(configloader.config["Error Reporting"]["sentry_token"],
                                               release=raven.fetch_git_sha(os.path.dirname(__file__)),
                                               environment="Dev" if __debug__ else "Prod")
+            log.debug("Sentry: enabled")
         else:
             self.sentry_client = None
+            log.debug("Sentry: disabled")
+
+    def __repr__(self):
+        return f"<{self.__class__.__qualname__} {self.chat.id}>"
 
     # noinspection PyBroadException
     def run(self):
         """The conversation code."""
         # Welcome the user to the bot
+        log.debug("Starting conversation")
         self.bot.send_message(self.chat.id, strings.conversation_after_start)
         # Get the user db data from the users and admin tables
         self.user = self.session.query(db.User).filter(db.User.user_id == self.chat.id).one_or_none()
@@ -91,6 +100,9 @@ class ChatWorker(threading.Thread):
                 self.session.add(self.admin)
             # Commit the transaction
             self.session.commit()
+            log.info(f"Created new user: {self.user}")
+            if will_be_owner:
+                log.warning(f"User was auto-promoted to Admin as no other admins existed: {self.user}")
         # Capture exceptions that occour during the conversation
         try:
             # If the user is not an admin, send him to the user menu
@@ -123,8 +135,8 @@ class ChatWorker(threading.Thread):
         self.join()
 
     def update_user(self) -> db.User:
-        """Update the user data.
+        """Update the user data."""
-        Note that this method will cause crashes if used in different threads with sqlite databases."""
+        log.debug("Fetching updated user data from the database")
         self.user = self.session.query(db.User).filter(db.User.user_id == self.chat.id).one_or_none()
         return self.user
 
@@ -150,6 +162,7 @@ class ChatWorker(threading.Thread):
                                     items: List[str],
                                     cancellable: bool = False) -> Union[str, CancelSignal]:
         """Continue getting updates until until one of the strings contained in the list is received as a message."""
+        log.debug("Waiting for a specific message...")
         while True:
             # Get the next update
             update = self.__receive_next_update()
@@ -176,6 +189,7 @@ class ChatWorker(threading.Thread):
 
     def __wait_for_regex(self, regex: str, cancellable: bool = False) -> Union[str, CancelSignal]:
         """Continue getting updates until the regex finds a match in a message, then return the first capture group."""
+        log.debug("Waiting for a regex...")
         while True:
             # Get the next update
             update = self.__receive_next_update()
@@ -206,6 +220,7 @@ class ChatWorker(threading.Thread):
                                     cancellable: bool = False) -> Union[telegram.PreCheckoutQuery, CancelSignal]:
         """Continue getting updates until a precheckoutquery is received.
         The payload is checked by the core before forwarding the message."""
+        log.debug("Waiting for a PreCheckoutQuery...")
         while True:
             # Get the next update
             update = self.__receive_next_update()
@@ -226,6 +241,7 @@ class ChatWorker(threading.Thread):
 
     def __wait_for_successfulpayment(self) -> telegram.SuccessfulPayment:
         """Continue getting updates until a successfulpayment is received."""
+        log.debug("Waiting for a SuccessfulPayment...")
         while True:
             # Get the next update
             update = self.__receive_next_update()
@@ -240,6 +256,7 @@ class ChatWorker(threading.Thread):
 
     def __wait_for_photo(self, cancellable: bool = False) -> Union[List[telegram.PhotoSize], CancelSignal]:
         """Continue getting updates until a photo is received, then return it."""
+        log.debug("Waiting for a photo...")
         while True:
             # Get the next update
             update = self.__receive_next_update()
@@ -264,6 +281,7 @@ class ChatWorker(threading.Thread):
     def __wait_for_inlinekeyboard_callback(self, cancellable: bool = False) \
             -> Union[telegram.CallbackQuery, CancelSignal]:
         """Continue getting updates until an inline keyboard callback is received, then return it."""
+        log.debug("Waiting for a CallbackQuery...")
         while True:
             # Get the next update
             update = self.__receive_next_update()
@@ -286,6 +304,7 @@ class ChatWorker(threading.Thread):
 
     def __user_select(self) -> Union[db.User, CancelSignal]:
         """Select an user from the ones in the database."""
+        log.debug("Waiting for a user selection...")
         # Find all the users in the database
         users = self.session.query(db.User).order_by(db.User.user_id).all()
         # Create a list containing all the keyboard button strings
@@ -315,6 +334,7 @@ class ChatWorker(threading.Thread):
     def __user_menu(self):
         """Function called from the run method when the user is not an administrator.
         Normal bot actions should be placed here."""
+        log.debug("Displaying __user_menu")
         # Loop used to returning to the menu after executing a command
         while True:
             # Create a keyboard with the user main menu
@@ -355,6 +375,7 @@ class ChatWorker(threading.Thread):
 
     def __order_menu(self):
         """User menu to order products from the shop."""
+        log.debug("Displaying __order_menu")
         # Get the products list from the db
         products = self.session.query(db.Product).filter_by(deleted=False).all()
         # Create a dict to be used as 'cart'
@@ -575,6 +596,7 @@ class ChatWorker(threading.Thread):
 
     def __order_status(self):
         """Display the status of the sent orders."""
+        log.debug("Displaying __order_status")
         # Find the latest orders
         orders = self.session.query(db.Order) \
             .filter(db.Order.user == self.user) \
@@ -591,6 +613,7 @@ class ChatWorker(threading.Thread):
 
     def __add_credit_menu(self):
         """Add more credit to the account."""
+        log.debug("Displaying __add_credit_menu")
         # Create a payment methods keyboard
         keyboard = list()
         # Add the supported payment methods to the keyboard
@@ -623,6 +646,7 @@ class ChatWorker(threading.Thread):
 
     def __add_credit_cc(self):
         """Add money to the wallet through a credit card payment."""
+        log.debug("Displaying __add_credit_cc")
         # Create a keyboard to be sent later
         presets = list(map(lambda s: s.strip(" "), configloader.config["Credit Card"]["payment_presets"].split('|')))
         keyboard = [[telegram.KeyboardButton(str(utils.Price(preset)))] for preset in presets]
@@ -730,11 +754,13 @@ class ChatWorker(threading.Thread):
 
     def __bot_info(self):
         """Send information about the bot."""
+        log.debug("Displaying __bot_info")
         self.bot.send_message(self.chat.id, strings.bot_info)
 
     def __admin_menu(self):
         """Function called from the run method when the user is an administrator.
         Administrative bot actions should be placed here."""
+        log.debug("Displaying __admin_menu")
         # Loop used to return to the menu after executing a command
         while True:
             # Create a keyboard with the admin main menu based on the admin permissions specified in the db
@@ -791,6 +817,7 @@ class ChatWorker(threading.Thread):
 
     def __products_menu(self):
         """Display the admin menu to select a product to edit."""
+        log.debug("Displaying __products_menu")
         # Get the products list from the db
         products = self.session.query(db.Product).filter_by(deleted=False).all()
         # Create a list of product names
@@ -827,6 +854,7 @@ class ChatWorker(threading.Thread):
 
     def __edit_product_menu(self, product: Optional[db.Product] = None):
         """Add a product to the database or edit an existing one."""
+        log.debug("Displaying __edit_product_menu")
         # Create an inline keyboard with a single skip button
         cancel = telegram.InlineKeyboardMarkup([[telegram.InlineKeyboardButton(strings.menu_skip,
                                                                                callback_data="cmd_cancel")]])
@@ -915,6 +943,7 @@ class ChatWorker(threading.Thread):
         self.bot.send_message(self.chat.id, strings.success_product_edited)
 
     def __delete_product_menu(self):
+        log.debug("Displaying __delete_product_menu")
         # Get the products list from the db
         products = self.session.query(db.Product).filter_by(deleted=False).all()
         # Create a list of product names
@@ -942,6 +971,7 @@ class ChatWorker(threading.Thread):
 
     def __orders_menu(self):
         """Display a live flow of orders."""
+        log.debug("Displaying __orders_menu")
         # Create a cancel and a stop keyboard
         stop_keyboard = telegram.InlineKeyboardMarkup([[telegram.InlineKeyboardButton(strings.menu_stop,
                                                                                       callback_data="cmd_cancel")]])
@@ -1033,6 +1063,7 @@ class ChatWorker(threading.Thread):
 
     def __create_transaction(self):
         """Edit manually the credit of an user."""
+        log.debug("Displaying __create_transaction")
         # Make the admin select an user
         user = self.__user_select()
         # Allow the cancellation of the operation
@@ -1075,6 +1106,7 @@ class ChatWorker(threading.Thread):
 
     def __help_menu(self):
         """Help menu. Allows the user to ask for assistance, get a guide or see some info about the bot."""
+        log.debug("Displaying __help_menu")
         # Create a keyboard with the user help menu
         keyboard = [[telegram.KeyboardButton(strings.menu_guide)],
                     [telegram.KeyboardButton(strings.menu_contact_shopkeeper)],
@@ -1102,6 +1134,7 @@ class ChatWorker(threading.Thread):
 
     def __transaction_pages(self):
         """Display the latest transactions, in pages."""
+        log.debug("Displaying __transaction_pages")
         # Page number
         page = 0
         # Create and send a placeholder message to be populated
@@ -1156,6 +1189,7 @@ class ChatWorker(threading.Thread):
 
     def __transactions_file(self):
         """Generate a .csv file containing the list of all transactions."""
+        log.debug("Generating __transaction_file")
         # Retrieve all the transactions
         transactions = self.session.query(db.Transaction).order_by(db.Transaction.transaction_id.asc()).all()
         # Create the file if it doesn't exists
@@ -1201,6 +1235,7 @@ class ChatWorker(threading.Thread):
 
     def __add_admin(self):
         """Add an administrator to the bot."""
+        log.debug("Displaying __add_admin")
         # Let the admin select an administrator to promote
         user = self.__user_select()
         # Allow the cancellation of the operation
@@ -1265,6 +1300,7 @@ class ChatWorker(threading.Thread):
 
     def __graceful_stop(self, stop_trigger: StopSignal):
         """Handle the graceful stop of the thread."""
+        log.debug("Gracefully stopping the conversation")
         # If the session has expired...
         if stop_trigger.reason == "timeout":
             # Notify the user that the session has expired and remove the keyboard