Add prompt logging and opt-out options for users. Additional logging and timing info added.

.gitignore

@@ -1,3 +1,4 @@
 .idea/*
 __pycache__/
-.run*/
+/.run*/
+/train.csv

app.py

@@ -1,16 +1,19 @@
 import datetime
+from uuid import uuid4
 
 from openai import OpenAI
 import gradio as gr
 
 from theme import apriel
-from utils import COMMUNITY_POSTFIX_URL, get_model_config, log_message, check_format, models_config, DEBUG_MODE
+from utils import COMMUNITY_POSTFIX_URL, get_model_config, log_message, check_format, models_config, \
+    logged_event_handler, DEBUG_MODEL
+from log_chat import log_chat
 
 MODEL_TEMPERATURE = 0.8
 BUTTON_WIDTH = 160
+DEFAULT_OPT_OUT_VALUE = False
 
-DEFAULT_MODEL_NAME = "Apriel-Nemotron-15b-Thinker" if not DEBUG_MODE else "Apriel-5b"
-# DEFAULT_MODEL_NAME = "Apriel-5b"
+DEFAULT_MODEL_NAME = "Apriel-Nemotron-15b-Thinker" if not DEBUG_MODEL else "Apriel-5b"
 
 print(f"Gradio version: {gr.__version__}")
 
@@ -31,6 +34,13 @@ model_config = {}
 openai_client = None
 
 
+def app_loaded(state, request: gr.Request):
+    message_html = setup_model(DEFAULT_MODEL_NAME, intial=False)
+    state['session'] = request.session_hash if request else uuid4().hex
+    log_message(f"app_loaded() --> Session: {state['session']}")
+    return state, message_html
+
+
 def update_model_and_clear_chat(model_name):
     actual_model_name = model_name.replace("Model: ", "")
     desc = setup_model(actual_model_name)
@@ -75,10 +85,19 @@ def stop_chat(state):
     return state
 
 
+def toggle_opt_out(state, checkbox):
+    state["opt_out"] = checkbox
+    return state
+
+
 def run_chat_inference(history, message, state):
     global chat_start_count
     state["is_streaming"] = True
     state["stop_flag"] = False
+    error = None
+
+    if len(history) == 0:
+        state["chat_id"] = uuid4().hex
 
     # outputs: model_dropdown, user_input, send_btn, stop_btn, clear_btn, session_state
     log_message(f"{'-' * 80}")
@@ -124,9 +143,21 @@ def run_chat_inference(history, message, state):
             )
         except Exception as e:
             print(f"Error: {e}")
+            error = str(e)
             yield ([{"role": "assistant",
                      "content": "😔 The model is unavailable at the moment. Please try again later."}],
                    INPUT_ENABLED, SEND_BUTTON_ENABLED, STOP_BUTTON_DISABLED, BUTTON_ENABLED, state)
+            if state["opt_out"] is not True:
+                log_chat(chat_id=state["chat_id"],
+                         session_id=state["session"],
+                         model_name=model_config.get('MODEL_NAME'),
+                         prompt=message,
+                         history=history,
+                         info={"is_reasoning": model_config.get("REASONING"), "temperature": MODEL_TEMPERATURE,
+                               "stopped": True, "error": str(e)},
+                         )
+            else:
+                log_message(f"User opted out of chat history. Not logging chat.")
             return history, INPUT_ENABLED, SEND_BUTTON_ENABLED, STOP_BUTTON_DISABLED, BUTTON_ENABLED, state
 
         if is_reasoning:
@@ -197,9 +228,21 @@ def run_chat_inference(history, message, state):
         check_format(history, "messages")
         yield history, INPUT_ENABLED, SEND_BUTTON_ENABLED, STOP_BUTTON_DISABLED, BUTTON_ENABLED, state
     finally:
+        if error is None:
+            log_message(f"chat_fn() --> Finished streaming. {chat_start_count} chats started.")
+            if state["opt_out"] is not True:
+                log_chat(chat_id=state["chat_id"],
+                         session_id=state["session"],
+                         model_name=model_config.get('MODEL_NAME'),
+                         prompt=message,
+                         history=history,
+                         info={"is_reasoning": model_config.get("REASONING"), "temperature": MODEL_TEMPERATURE,
+                               "stopped": state["stop_flag"]},
+                         )
+            else:
+                log_message(f"User opted out of chat history. Not logging chat.")
         state["is_streaming"] = False
         state["stop_flag"] = False
-        log_message(f"chat_fn() --> Finished streaming. {chat_start_count} chats started.")
         return history, INPUT_ENABLED, SEND_BUTTON_ENABLED, STOP_BUTTON_DISABLED, BUTTON_ENABLED, state
 
 
@@ -211,7 +254,13 @@ with open('styles.css', 'r') as f:
     custom_css = f.read()
 
 with gr.Blocks(theme=theme, css=custom_css) as demo:
-    session_state = gr.State(value={"is_streaming": False, "stop_flag": False})  # Store session state as a dictionary
+    session_state = gr.State(value={
+        "is_streaming": False,
+        "stop_flag": False,
+        "chat_id": None,
+        "session": None,
+        "opt_out": DEFAULT_OPT_OUT_VALUE,
+    })  # Store session state as a dictionary
 
     gr.HTML(f"""
         <style>
@@ -234,21 +283,22 @@ with gr.Blocks(theme=theme, css=custom_css) as demo:
                 min_width=400
             )
         with gr.Column(scale=4, min_width=0):
-            description_html = gr.HTML(description, elem_classes="model-message")
+            feedback_message_html = gr.HTML(description, elem_classes="model-message")
 
     chatbot = gr.Chatbot(
         type="messages",
-        height="calc(100dvh - 280px)",
+        height="calc(100dvh - 310px)",
         elem_classes="chatbot",
     )
 
     with gr.Row():
-        with gr.Column(scale=10, min_width=400, elem_classes="user-input-container"):
-            user_input = gr.Textbox(
-                show_label=False,
-                placeholder="Type your message here and press Enter",
-                container=False
-            )
+        with gr.Column(scale=10, min_width=400):
+            with gr.Row():
+                user_input = gr.Textbox(
+                    show_label=False,
+                    placeholder="Type your message here and press Enter",
+                    container=False
+                )
         with gr.Column(scale=1, min_width=BUTTON_WIDTH * 2 + 20):
             with gr.Row():
                 with gr.Column(scale=1, min_width=BUTTON_WIDTH, elem_classes="send-button-container"):
@@ -256,12 +306,28 @@ with gr.Blocks(theme=theme, css=custom_css) as demo:
                     stop_btn = gr.Button("Stop", variant="cancel", visible=False)
                 with gr.Column(scale=1, min_width=BUTTON_WIDTH, elem_classes="clear-button-container"):
                     clear_btn = gr.ClearButton(chatbot, value="New Chat", variant="secondary")
+    with gr.Row():
+        with gr.Column(min_width=400, elem_classes="opt-out-container"):
+            with gr.Row():
+                gr.HTML(
+                    "We may use your chats to improve our AI. You may opt out if you don’t want your conversations saved.",
+                    elem_classes="opt-out-message")
+            with gr.Row():
+                opt_out_checkbox = gr.Checkbox(
+                    label="Don’t save my chat history for improvements or training",
+                    value=DEFAULT_OPT_OUT_VALUE,
+                    elem_classes="opt-out-checkbox",
+                    interactive=True,
+                    container=False
+                )
 
     gr.on(
         triggers=[send_btn.click, user_input.submit],
         fn=run_chat_inference,  # this generator streams results. do not use logged_event_handler wrapper
         inputs=[chatbot, user_input, session_state],
-        outputs=[chatbot, user_input, send_btn, stop_btn, clear_btn, session_state]
+        outputs=[chatbot, user_input, send_btn, stop_btn, clear_btn, session_state],
+        concurrency_limit=4,
+        api_name=False
     ).then(
         fn=chat_finished, inputs=None, outputs=[model_dropdown, user_input, send_btn, stop_btn, clear_btn], queue=False)
 
@@ -272,22 +338,36 @@ with gr.Blocks(theme=theme, css=custom_css) as demo:
         inputs=None,
         outputs=[model_dropdown, user_input, send_btn, stop_btn, clear_btn],
         queue=False,
-        show_progress='hidden'
+        show_progress='hidden',
+        api_name=False
     )
 
     stop_btn.click(
         fn=stop_chat,
         inputs=[session_state],
-        outputs=[session_state]
+        outputs=[session_state],
+        api_name=False
     )
 
+    opt_out_checkbox.change(fn=toggle_opt_out, inputs=[session_state, opt_out_checkbox], outputs=[session_state])
+
     # Ensure the model is reset to default on page reload
-    demo.load(lambda: setup_model(DEFAULT_MODEL_NAME, intial=False), [], [description_html])
+    demo.load(
+        fn=logged_event_handler(
+            log_msg="Browser session started",
+            event_handler=app_loaded
+        ),
+        inputs=[session_state],
+        outputs=[session_state, feedback_message_html],
+        queue=True,
+        api_name=False
+    )
 
     model_dropdown.change(
         fn=update_model_and_clear_chat,
         inputs=[model_dropdown],
-        outputs=[description_html, chatbot]
+        outputs=[feedback_message_html, chatbot],
+        api_name=False
     )
 
-demo.launch(ssr_mode=False, show_api=False)
+demo.queue(default_concurrency_limit=2).launch(ssr_mode=False, show_api=False)

log_chat.py

@@ -0,0 +1,235 @@
+import csv
+import os
+import time
+from datetime import datetime
+from queue import Queue
+import threading
+
+import pandas as pd
+from gradio import ChatMessage
+from huggingface_hub import HfApi, hf_hub_download
+
+from timer import Timer
+from utils import log_warning, log_message
+
+HF_TOKEN = os.environ.get("HF_TOKEN")
+DATASET_REPO_ID = os.environ.get("APRIEL_PROMPT_DATASET")
+CSV_FILENAME = "train.csv"
+
+
+def log_chat(chat_id: str, session_id: str, model_name: str, prompt: str, history: list[str], info: dict) -> None:
+    log_chat_queue.put((chat_id, session_id, model_name, prompt, history, info))
+
+
+def _log_chat_worker():
+    while True:
+        chat_id, session_id, model_name, prompt, history, info = log_chat_queue.get()
+        try:
+            try:
+                _log_chat(chat_id, session_id, model_name, prompt, history, info)
+            except Exception as e:
+                log_warning(f"Error logging chat: {e}")
+        finally:
+            log_chat_queue.task_done()
+
+
+def _log_chat(chat_id: str, session_id: str, model_name: str, prompt: str, history: list[str], info: dict) -> bool:
+    if DATASET_REPO_ID is None:
+        log_warning("No dataset repo ID provided. Skipping logging of prompt.")
+        return False
+    if HF_TOKEN is None:
+        log_warning("No HF token provided. Skipping logging of prompt.")
+        return False
+
+    log_timer = Timer('log_chat')
+    log_timer.start()
+
+    # Initialize HF API
+    api = HfApi(token=HF_TOKEN)
+
+    # Check if the dataset repo exists, if not, create it
+    try:
+        repo_info = api.repo_info(repo_id=DATASET_REPO_ID, repo_type="dataset")
+        log_message(f"log_chat() --> Dataset repo found: {repo_info.id} private={repo_info.private}")
+    except Exception:  # Create new dataset if none exists
+        log_message(f"log_chat() --> No dataset repo found, creating a new one...")
+        api.create_repo(repo_id=DATASET_REPO_ID, repo_type="dataset", private=True)
+
+    # Ensure messages are in the correct format
+    messages = [
+        {"role": item.role, "content": item.content,
+         "type": "thought" if item.metadata else "completion"} if isinstance(
+            item, ChatMessage) else item
+        for item in history
+        if isinstance(item, dict) and "role" in item and "content" in item or isinstance(item, ChatMessage)
+    ]
+    if len(messages) != len(history):
+        log_warning("log_chat() --> Some messages in history are missing 'role' or 'content' keys.")
+
+    user_messages_count = sum(1 for item in messages if isinstance(item, dict) and item.get("role") == "user")
+
+    # These must match the keys in the new row
+    expected_headers = ["timestamp", "chat_id", "turns", "prompt", "messages", "model", "session_id", "info"]
+    # Prepare new data row
+    new_row = {
+        "timestamp": datetime.now().isoformat(),
+        "chat_id": chat_id,
+        "turns": user_messages_count,
+        "prompt": prompt,
+        "messages": messages,
+        "model": model_name,
+        "session_id": session_id,
+        "info": info,
+    }
+    log_timer.add_step("Prepared new data row")
+
+    # Try to download existing CSV with retry logic
+    max_retries = 3
+    retry_count = 0
+    file_exists = False
+    while retry_count < max_retries:
+        try:
+            csv_path = hf_hub_download(
+                repo_id=DATASET_REPO_ID,
+                filename=CSV_FILENAME,
+                repo_type="dataset",
+                token=HF_TOKEN  # Only needed if not already logged in
+            )
+            pd.read_csv(csv_path)
+            file_exists = True
+            log_message(f"log_chat() --> Downloaded existing CSV with {len(pd.read_csv(csv_path))} rows")
+            break  # Success, exit the loop
+        except Exception as e:
+            retry_count += 1
+            if retry_count < max_retries:
+                retry_delay = 2 * retry_count  # Exponential backoff: 2s, 4s, 6s, 8s
+                log_warning(
+                    f"log_chat() --> Download attempt {retry_count} failed: {e}. Retrying in {retry_delay} seconds...")
+                time.sleep(retry_delay)
+            else:
+                log_warning(f"log_chat() --> Failed to download CSV after {max_retries} attempts: {e}")
+        file_exists = False
+
+    log_timer.add_step(f"Downloaded existing CSV (attempts: {retry_count + 1})")
+
+    # Handle the case where the CSV file does not exist or is invalid
+    if file_exists and len(pd.read_csv(csv_path)) == 0:
+        log_warning(f"log_chat() --> CSV {csv_path} exists but is empty, will create a new one.")
+        dump_hub_csv()
+        file_exists = False
+    elif file_exists:
+        # Check that the headers match our standard headers of "timestamp", "chat_id", "turns", ...
+        existing_headers = pd.read_csv(csv_path).columns.tolist()
+        if set(existing_headers) != set(expected_headers):
+            log_warning(f"log_chat() --> CSV {csv_path} has unexpected headers: {existing_headers}. "
+                        f"\nExpected {existing_headers} "
+                        f"Will create a new one.")
+            dump_hub_csv()
+            file_exists = False
+        else:
+            log_message(f"log_chat() --> CSV {csv_path} has expected headers: {existing_headers}")
+
+    # Write out the new row to the CSV file (append isn't working in HF container, so recreate each time)
+    log_message(f"log_chat() --> Writing CSV file, file_exists={file_exists}")
+    try:
+        with open(CSV_FILENAME, "w", newline="\n") as f:
+            writer = csv.DictWriter(f, fieldnames=new_row.keys())
+            writer.writeheader()  # Always write the header
+            if file_exists:
+                for _, row in pd.read_csv(csv_path).iterrows():
+                    writer.writerow(row.to_dict())  # Write existing rows
+            writer.writerow(new_row)  # Write the new row
+
+        log_message("log_chat() --> Wrote out CSV with new row")
+        # dump_local_csv()
+    except Exception as e:
+        log_warning(f"log_chat() --> Error writing to CSV: {e}")
+        return False
+
+    # Upload updated CSV
+    api.upload_file(
+        path_or_fileobj=CSV_FILENAME,
+        path_in_repo=CSV_FILENAME,
+        repo_id=DATASET_REPO_ID,
+        repo_type="dataset",
+        commit_message=f"Added new chat entry at {datetime.now().isoformat()}"
+    )
+    log_timer.add_step("Uploaded updated CSV")
+    log_timer.end()
+    log_message("log_chat() --> Finished logging chat")
+    log_message(log_timer.formatted_result())
+
+    return True
+
+
+def dump_hub_csv():
+    # Verify the file contents by loading it from the hub and printing it out
+    try:
+        csv_path = hf_hub_download(
+            repo_id=DATASET_REPO_ID,
+            filename=CSV_FILENAME,
+            repo_type="dataset",
+            token=HF_TOKEN  # Only needed if not already logged in
+        )
+        df = pd.read_csv(csv_path)
+        print(df)
+        if (df.empty):
+            # show raw contents of downloaded csv file
+            print("Raw file contents:")
+            with open(csv_path, 'r') as f:
+                print(f.read())
+    except Exception as e:
+        print(f"Error loading CSV from hub: {e}")
+
+
+def dump_local_csv():
+    # Verify the file contents by loading it from the local file and printing it out
+    try:
+        df = pd.read_csv(CSV_FILENAME)
+        print(df)
+    except Exception as e:
+        print(f"Error loading CSV from local file: {e}")
+
+
+def test_log_chat():
+    # Example usage
+    chat_id = "12345"
+    session_id = "67890"
+    model_name = "Apriel-Model"
+    prompt = "Hello"
+    history = [{"role": "user", "content": prompt}, {"role": "assistant", "content": "Hi there!"}]
+    prompt = "100 + 1"
+    history = [{'role': 'user', 'content': prompt}, ChatMessage(
+        content='Okay, that\'s a simple addition problem. , answer is 2.\n', role='assistant',
+        metadata={'title': '🧠 Thought'}, options=[]),
+               ChatMessage(content='\nThe result of adding 1 and 1 is:\n\n**2**\n', role='assistant', metadata={},
+                           options=[])
+               ]
+    info = {"additional_info": "Some extra data"}
+
+    log_message("Starting test_log_chat()")
+    dump_hub_csv()
+    log_chat(chat_id, session_id, model_name, prompt, history, info)
+    log_message("log_chat 1 returned")
+    log_chat(chat_id, session_id, model_name, prompt + " + 2", history, info)
+    log_message("log_chat 2 returned")
+    log_chat(chat_id, session_id, model_name, prompt + " + 3", history, info)
+    log_message("log_chat 3 returned")
+    log_chat(chat_id, session_id, model_name, prompt + " + 4", history, info)
+    log_message("log_chat 4 returned")
+
+    sleep_seconds = 10
+    log_message(f"Sleeping {sleep_seconds} seconds to let it finish and log the result.")
+    time.sleep(sleep_seconds)
+    log_message("Finished sleeping.")
+    dump_hub_csv()
+
+
+# Create a queue for logging chat messages
+log_chat_queue = Queue()
+
+# Start the worker thread
+threading.Thread(target=_log_chat_worker, daemon=True).start()
+
+if __name__ == "__main__":
+    test_log_chat()

requirements.txt

@@ -1,3 +1,5 @@
 huggingface_hub==0.28.1
 gradio==5.29.0
-openai
+openai~=1.78.0
+pandas~=2.2.3
+datasets~=2.14.4

styles.css

@@ -42,6 +42,16 @@ button.cancel:hover, .cancel[disabled] {
     color: var(--button-cancel-text-color-hover);
 }
 
+.opt-out-message {
+    top: 8px;
+}
+
+.opt-out-message .html-container, .opt-out-checkbox label {
+    font-size: 14px !important;
+    padding: 0 !important;
+    margin: 0 !important;
+    color: var(--neutral-400) !important;
+}
 
 @media (max-width: 800px) {
     .responsive-row {
@@ -59,7 +69,7 @@ button.cancel:hover, .cancel[disabled] {
     }
 
     .chatbot {
-        max-height: 850px;
+        max-height: 800px;
     }
 }
 
@@ -79,6 +89,30 @@ button.cancel:hover, .cancel[disabled] {
     }
 
     .chatbot {
-        max-height: 400px;
+        max-height: 360px;
+    }
+}
+
+@media (max-width: 1280px) {
+    .chatbot {
+        max-height: 900px;
+    }
+}
+
+@media (max-height: 932px) {
+    .chatbot {
+        max-height: calc(100dvh - 400px);
     }
 }
+
+@media (max-height: 1280px) {
+    .chatbot {
+        max-height: calc(100dvh - 400px);
+    }
+}
+
+@media (min-height: 1281px) {
+    .chatbot {
+        /*max-height: calc(100dvh - 400px);*/
+    }
+}

timer.py

@@ -0,0 +1,114 @@
+import time
+import json
+
+
+class Timer:
+    def __init__(self, name=None):
+        self.name = name
+        self.start_time = None
+        self.steps = []
+        self.total_time = None
+
+    def clear(self):
+        self.start_time = None
+        self.steps = []
+        self.total_time = None
+
+    def start(self):
+        """Start the timer."""
+        self.start_time = time.time()
+
+    def is_running(self):
+        return self.start_time is not None
+
+    def add_step(self, step_name):
+        """Add a step with its duration since the last step or start."""
+        if self.start_time is None:
+            self.start()
+
+        current_time = time.time()
+        if not self.steps:
+            elapsed = current_time - self.start_time
+        else:
+            elapsed = current_time - self.steps[-1]['timestamp']
+
+        self.steps.append({
+            "step_name": step_name,
+            "duration": round(elapsed, 4),
+            "total_duration": round(current_time - self.start_time, 4),
+            "timestamp": current_time
+        })
+
+    def end(self):
+        """End the timer and calculate the total duration."""
+        if self.start_time is None:
+            raise RuntimeError("Timer has not been started.")
+
+        if not self.steps:
+            raise RuntimeError("No steps have been added.")
+
+        self.total_time = time.time() - self.start_time
+
+    def to_json(self):
+        """Return a JSON of the timing steps."""
+        if self.total_time is None:
+            raise RuntimeError("Timer has not been ended.")
+
+        output_steps = {}
+        for step in self.steps:
+            output_steps[step["step_name"]] = step["duration"]
+
+        highlights = {"total_time": round(self.total_time, 4)}
+
+        if self.name:
+            highlights = {"name": self.name, **highlights}
+
+        output = {
+            **highlights,
+            **output_steps
+        }
+        return output
+
+    def to_json_str(self):
+        """Return a human-readable JSON of the timing steps."""
+        return json.dumps(self.to_json(), indent=4)
+
+    def formatted_result(self):
+        """Return a list of the steps, their duration, and total duration."""
+        if self.total_time is None:
+            raise RuntimeError("Timer has not been ended.")
+        line_buffer = []
+        if self.name:
+            line_buffer.append(f"Timer: {self.name}")
+        for step in self.steps:
+            line_buffer.append(f"[{step['duration']:05.2f}s, {step['total_duration']:05.2f}s] {step['step_name']}")
+        # for step in self.steps:
+        #     line_buffer.append(f"{step['step_name']}: {step['duration']:.2f}s ({step['total_duration']:.2f}s)")
+        line_buffer.append(f"Total time: {self.total_time:.2f}s")
+        return "\n".join(line_buffer)
+
+    def log_formatted_result(self):
+        print(self.formatted_result())
+
+
+def example():
+    # Example usage
+    timer = Timer()
+    timer.start()
+
+    # Simulating some steps
+    time.sleep(1)  # Simulate work for step 1
+    timer.add_step("Step 1")
+
+    time.sleep(2)  # Simulate work for step 2
+    timer.add_step("Step 2")
+
+    timer.end()
+
+    # Print the timer output
+    print(timer.formatted_result())
+    print(timer.to_json_str())
+
+
+if __name__ == "__main__":
+    example()

utils.py

@@ -1,13 +1,14 @@
 import os
 import sys
+from functools import wraps
 from typing import Any, Literal
 
 from gradio import ChatMessage
 from gradio.components.chatbot import Message
-from functools import wraps
 
 COMMUNITY_POSTFIX_URL = "/discussions"
 DEBUG_MODE = False or os.environ.get("DEBUG_MODE") == "True"
+DEBUG_MODEL = False or os.environ.get("DEBUG_MODEL") == "True"
 
 models_config = {
     "Apriel-Nemotron-15b-Thinker": {
@@ -46,6 +47,10 @@ def log_message(message):
         print(f"≫≫≫ {message}")
 
 
+def log_warning(message):
+    print(f"‼️ {message}")
+
+
 # Gradio 5.0.1 had issues with checking the message formats.  5.29.0 does not!
 def check_format(messages: Any, type: Literal["messages", "tuples"] = "messages") -> None:
     if not DEBUG_MODE:
@@ -82,23 +87,24 @@ def check_format(messages: Any, type: Literal["messages", "tuples"] = "messages"
         )
 
 
-def logged_event_handler(log_message='', event_handler=None, timer=None, clear_timer=False):
+# Adds timing info for a gradio event handler (non-generator functions)
+def logged_event_handler(log_msg='', event_handler=None, log_timer=None, clear_timer=False):
     @wraps(event_handler)
     def wrapped_event_handler(*args, **kwargs):
         # Log before
-        if timer:
+        if log_timer:
             if clear_timer:
-                timer.clear()
-            timer.add_step(f"Start: {log_message}")
-        log_message(f"::: Before event: {log_message}")
+                log_timer.clear()
+            log_timer.add_step(f"Start: {log_message}")
+        log_message(f"::: Before event: {log_msg}")
 
         # Call the original event handler
         result = event_handler(*args, **kwargs)
 
         # Log after
-        if timer:
-            timer.add_step(f"Completed: {log_message}")
-        log_message(f"::: After event: {log_message}")
+        if log_timer:
+            log_timer.add_step(f"Completed: {log_msg}")
+        log_message(f"::: After event: {log_msg}")
 
         return result