From a78906a888fb5034304574605cb022138b4e0013 Mon Sep 17 00:00:00 2001 From: Dobromir Popov Date: Tue, 1 Apr 2025 18:30:34 +0300 Subject: [PATCH] improvements --- LOGGING.md | 106 +++++++++++++++ read_logs.py | 124 +++++++++++++++++ start_app.bat | 22 +++ train_rl_with_realtime.py | 278 +++++++++++++++++++------------------- 4 files changed, 392 insertions(+), 138 deletions(-) create mode 100644 LOGGING.md create mode 100644 read_logs.py create mode 100644 start_app.bat diff --git a/LOGGING.md b/LOGGING.md new file mode 100644 index 0000000..c19cf4e --- /dev/null +++ b/LOGGING.md @@ -0,0 +1,106 @@ +# Logging and Monitoring Tools + +This document explains how to use the logging and monitoring tools in this project for effective development and troubleshooting. + +## Log File Specification + +When running the application, you can specify a custom log file name using the `--log-file` parameter: + +``` +python train_rl_with_realtime.py --episodes 1 --no-train --visualize-only --log-file custom_log_name.log +``` + +This makes it easier to identify specific log files for particular runs during development. + +## Log Reader Utility + +The `read_logs.py` script provides a convenient way to read and filter log files: + +### List all log files + +To see all available log files sorted by modification time: + +``` +python read_logs.py --list +``` + +### Read a specific log file + +To read the last 50 lines of a specific log file: + +``` +python read_logs.py --file your_log_file.log +``` + +If you don't specify a file, it will use the most recently modified log file. + +### Filter log content + +To only show lines containing specific text: + +``` +python read_logs.py --file your_log_file.log --filter "trade" +``` + +### Follow log updates in real-time + +To monitor a log file as it grows (similar to `tail -f` in Unix): + +``` +python read_logs.py --file your_log_file.log --follow +``` + +You can also combine filtering with following: + +``` +python read_logs.py --file your_log_file.log --filter "ERROR" --follow +``` + +## Startup Scripts + +### Windows Batch Script + +The `start_app.bat` script starts the application with log monitoring in separate windows: + +``` +start_app.bat +``` + +This will: +1. Start the application with a timestamped log file +2. Open a log monitoring window +3. Open the dashboard in your default browser + +### PowerShell Script + +The `StartApp.ps1` script offers a more advanced monitoring experience: + +``` +.\StartApp.ps1 +``` + +This will: +1. Start the application in the background +2. Open the dashboard in your default browser +3. Show log output in the current window with colored formatting +4. Provide instructions for managing the background application job + +## Common Log Monitoring Patterns + +### Monitor for errors + +``` +python read_logs.py --filter "ERROR|Error|error" --follow +``` + +### Watch trading activity + +``` +python read_logs.py --filter "trade|position|BUY|SELL" --follow +``` + +### Monitor performance metrics + +``` +python read_logs.py --filter "reward|balance|PnL|win rate" --follow +``` \ No newline at end of file diff --git a/read_logs.py b/read_logs.py new file mode 100644 index 0000000..e120f51 --- /dev/null +++ b/read_logs.py @@ -0,0 +1,124 @@ +#!/usr/bin/env python +""" +Log Reader Utility + +This script provides a convenient way to read and filter log files during +development. +""" + +import os +import sys +import time +import argparse +from datetime import datetime + +def parse_args(): + """Parse command line arguments""" + parser = argparse.ArgumentParser(description='Read and filter log files') + parser.add_argument('--file', type=str, help='Log file to read (defaults to most recent .log file)') + parser.add_argument('--tail', type=int, default=50, help='Number of lines to show from the end') + parser.add_argument('--follow', '-f', action='store_true', help='Follow the file as it grows') + parser.add_argument('--filter', type=str, help='Only show lines containing this string') + parser.add_argument('--list', action='store_true', help='List all log files sorted by modification time') + return parser.parse_args() + +def get_most_recent_log(): + """Find the most recently modified log file""" + log_files = [f for f in os.listdir('.') if f.endswith('.log')] + if not log_files: + print("No log files found in current directory.") + sys.exit(1) + + # Sort by modification time (newest first) + log_files.sort(key=lambda x: os.path.getmtime(x), reverse=True) + return log_files[0] + +def list_log_files(): + """List all log files sorted by modification time""" + log_files = [f for f in os.listdir('.') if f.endswith('.log')] + if not log_files: + print("No log files found in current directory.") + sys.exit(1) + + # Sort by modification time (newest first) + log_files.sort(key=lambda x: os.path.getmtime(x), reverse=True) + + print(f"{'LAST MODIFIED':<20} {'SIZE':<10} FILENAME") + print("-" * 60) + for log_file in log_files: + mtime = datetime.fromtimestamp(os.path.getmtime(log_file)) + size = os.path.getsize(log_file) + size_str = f"{size / 1024:.1f} KB" if size > 1024 else f"{size} B" + print(f"{mtime.strftime('%Y-%m-%d %H:%M:%S'):<20} {size_str:<10} {log_file}") + +def read_log_tail(file_path, num_lines, filter_text=None): + """Read the last N lines of a file""" + try: + with open(file_path, 'r', encoding='utf-8') as f: + # Read all lines (inefficient but simple) + lines = f.readlines() + + # Filter if needed + if filter_text: + lines = [line for line in lines if filter_text in line] + + # Get the last N lines + last_lines = lines[-num_lines:] if len(lines) > num_lines else lines + return last_lines + except Exception as e: + print(f"Error reading file: {str(e)}") + sys.exit(1) + +def follow_log(file_path, filter_text=None): + """Follow the log file as it grows (like tail -f)""" + try: + with open(file_path, 'r', encoding='utf-8') as f: + # Go to the end of the file + f.seek(0, 2) + + while True: + line = f.readline() + if line: + if not filter_text or filter_text in line: + # Remove newlines at the end to avoid double spacing + print(line.rstrip()) + else: + time.sleep(0.1) # Sleep briefly to avoid consuming CPU + except KeyboardInterrupt: + print("\nLog reading stopped.") + except Exception as e: + print(f"Error following file: {str(e)}") + sys.exit(1) + +def main(): + """Main function""" + args = parse_args() + + # List all log files if requested + if args.list: + list_log_files() + return + + # Determine which file to read + file_path = args.file + if not file_path: + file_path = get_most_recent_log() + print(f"Reading most recent log file: {file_path}") + + # Follow mode (like tail -f) + if args.follow: + print(f"Following {file_path} (Press Ctrl+C to stop)...") + # First print the tail + for line in read_log_tail(file_path, args.tail, args.filter): + print(line.rstrip()) + print("-" * 80) + print("Waiting for new content...") + # Then follow + follow_log(file_path, args.filter) + else: + # Just print the tail + for line in read_log_tail(file_path, args.tail, args.filter): + print(line.rstrip()) + +if __name__ == "__main__": + main() \ No newline at end of file diff --git a/start_app.bat b/start_app.bat new file mode 100644 index 0000000..4c5558d --- /dev/null +++ b/start_app.bat @@ -0,0 +1,22 @@ +@echo off +rem Start the real-time chart application with log monitoring + +set LOG_FILE=realtime_%date:~10,4%%date:~4,2%%date:~7,2%_%time:~0,2%%time:~3,2%%time:~6,2%.log +set LOG_FILE=%LOG_FILE: =0% + +echo Starting application with log file: %LOG_FILE% + +rem Start the application in one window +start "RealTime Trading Chart" cmd /k python train_rl_with_realtime.py --episodes 1 --no-train --visualize-only --log-file %LOG_FILE% + +rem Wait for the log file to be created +timeout /t 3 > nul + +rem Start log monitoring in another window (tail -f equivalent) +start "Log Monitor" cmd /k python read_logs.py --file %LOG_FILE% --follow + +rem Open the dashboard in the browser +timeout /t 5 > nul +start http://localhost:8050/ + +echo Application started. Check the opened windows for details. \ No newline at end of file diff --git a/train_rl_with_realtime.py b/train_rl_with_realtime.py index 078a883..65e8f57 100644 --- a/train_rl_with_realtime.py +++ b/train_rl_with_realtime.py @@ -19,14 +19,25 @@ import torch import json from threading import Thread import pandas as pd +import argparse from scipy.signal import argrelextrema +# Parse command line arguments +parser = argparse.ArgumentParser(description='Integrated RL Trading with Realtime Visualization') +parser.add_argument('--episodes', type=int, default=100, help='Number of episodes to train') +parser.add_argument('--no-train', action='store_true', help='Skip training, just visualize') +parser.add_argument('--visualize-only', action='store_true', help='Only run the visualization') +parser.add_argument('--manual-trades', action='store_true', help='Enable manual trading mode') +parser.add_argument('--log-file', type=str, help='Specify custom log filename') +args = parser.parse_args() + # Configure logging +log_filename = args.log_file or f'rl_realtime_training_{datetime.now().strftime("%Y%m%d_%H%M%S")}.log' logging.basicConfig( level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', handlers=[ - logging.FileHandler(f'rl_realtime_training_{datetime.now().strftime("%Y%m%d_%H%M%S")}.log'), + logging.FileHandler(log_filename), logging.StreamHandler() ] ) @@ -132,111 +143,80 @@ class RLTrainingIntegrator: # Define callbacks for the training process def on_action(step, action, price, reward, info): - """Callback for each action taken by the agent""" - # Only visualize non-hold actions - if action != 2: # 0=Buy, 1=Sell, 2=Hold - # Convert to string action - action_str = "BUY" if action == 0 else "SELL" - - # Get timestamp - we'll use current time as a proxy - timestamp = datetime.now() - - # Track position state - if action == 0 and not self.in_position: # Buy and not already in position - self.in_position = True - self.entry_price = price - self.entry_time = timestamp - - # Send to chart - visualize buy signal - if self.chart and hasattr(self.chart, 'add_nn_signal'): - self.chart.add_nn_signal(action_str, timestamp, probability=abs(reward)) - - elif action == 1 and self.in_position: # Sell and in position (complete trade) - self.in_position = False - - # Calculate profit if we have entry data - pnl = None - if self.entry_price is not None: - # Calculate percentage change - pnl_pct = (price - self.entry_price) / self.entry_price - - # Cap extreme PnL values to more realistic levels (-90% to +100%) - pnl_pct = max(min(pnl_pct, 1.0), -0.9) - - # Apply to current balance - trade_amount = self.session_balance * 0.1 # Use 10% of balance per trade - trade_profit = trade_amount * pnl_pct - self.session_balance += trade_profit - - # Ensure session balance doesn't go below $1 - self.session_balance = max(self.session_balance, 1.0) - - # For normalized display in charts and logs - pnl = pnl_pct - - # Update session-wide PnL - self.session_pnl += pnl - self.session_trades += 1 - if pnl > 0: - self.session_wins += 1 - - # Log the complete trade on the chart - if self.chart: - # Show sell signal - if hasattr(self.chart, 'add_nn_signal'): - self.chart.add_nn_signal(action_str, timestamp, probability=abs(reward)) - - # Record the trade with PnL - if hasattr(self.chart, 'add_trade'): - self.chart.add_trade( - price=price, - timestamp=timestamp, - pnl=pnl, - amount=0.1, - action=action_str, - type=action_str # Add explicit type - ) - - # Update trade counts - self.trade_count += 1 - if pnl is not None and pnl > 0: - self.win_count += 1 - - # Reset entry data - self.entry_price = None - self.entry_time = None - - # Track all actions - self.action_history.append({ - 'step': step, - 'action': action_str, - 'price': price, - 'reward': reward, - 'timestamp': timestamp.isoformat() - }) - else: - # Hold action - action_str = "HOLD" - timestamp = datetime.now() + """Called after each action in the episode""" - # Update chart trading info - if self.chart and hasattr(self.chart, 'update_trading_info'): - # Determine current position size (0.1 if in position, 0 if not) - position_size = 0.1 if self.in_position else 0.0 - self.chart.update_trading_info( - signal=action_str, - position=position_size, - balance=self.session_balance, - pnl=self.session_pnl - ) + # Log the action + action_str = "BUY" if action == 0 else "SELL" if action == 1 else "HOLD" + action_price = price - # Track reward for all actions (including hold) - self.reward_history.append(reward) + # Update session PnL and balance + self.session_step += 1 + self.session_pnl += reward - # Log periodically - if len(self.reward_history) % 100 == 0: - avg_reward = sum(self.reward_history[-100:]) / 100 - logger.info(f"Step {step}: Avg reward (last 100): {avg_reward:.4f}, Actions: {len(self.action_history)}, Trades: {self.trade_count}") + # Increase balance based on reward + self.session_balance += reward + + # Handle win/loss tracking + if reward != 0: # If this was a trade with P&L + self.session_trades += 1 + if reward > 0: + self.session_wins += 1 + + # Only log a subset of actions to avoid excessive output + if step % 100 == 0 or step < 10 or self.session_step % 100 == 0: + logger.info(f"Step {step}, Action: {action_str}, Price: {action_price:.2f}, Reward: {reward:.4f}, PnL: {self.session_pnl:.4f}, Balance: ${self.session_balance:.2f}") + + # Update the chart with the action - note positions are currently tracked in env + if action == 0: # BUY + # Only add to chart for visualization if we have a chart + if self.chart and hasattr(self.chart, "add_trade"): + # Adding a BUY trade + try: + self.chart.add_trade( + price=action_price, + timestamp=datetime.now(), + amount=0.1, # Standard amount + pnl=reward, + action="BUY" + ) + self.chart.last_action = "BUY" + except Exception as e: + logger.error(f"Failed to add BUY trade to chart: {str(e)}") + + elif action == 1: # SELL + # Only add to chart for visualization if we have a chart + if self.chart and hasattr(self.chart, "add_trade"): + # Adding a SELL trade + try: + self.chart.add_trade( + price=action_price, + timestamp=datetime.now(), + amount=0.1, # Standard amount + pnl=reward, + action="SELL" + ) + self.chart.last_action = "SELL" + except Exception as e: + logger.error(f"Failed to add SELL trade to chart: {str(e)}") + + # Update the trading info display on chart + if self.chart and hasattr(self.chart, "update_trading_info"): + try: + # Update the trading info panel with latest data + self.chart.update_trading_info( + signal=action_str, + position=0.1 if action == 0 else 0, + balance=self.session_balance, + pnl=self.session_pnl + ) + except Exception as e: + logger.warning(f"Failed to update trading info: {str(e)}") + + # Check for manual termination + if self.stop_event.is_set(): + return False # Signal to stop episode + + return True # Continue episode def on_episode(episode, reward, info): """Callback for each completed episode""" @@ -492,28 +472,19 @@ class RLTrainingIntegrator: logger.error(traceback.format_exc()) async def start_realtime_chart(symbol="BTC/USDT", port=8050): - """ - Start the realtime chart display in a separate thread + """Start the realtime trading chart in a separate thread Returns: - tuple: (chart, websocket_task) + tuple: (RealTimeChart instance, websocket task) """ from realtime import RealTimeChart try: logger.info(f"Initializing RealTimeChart for {symbol}") - # Create the chart with sample data enabled and no-ticks warnings disabled - chart = RealTimeChart(symbol, use_sample_data=True, log_no_ticks_warning=False) + # Create the chart with the new parameter interface + chart = RealTimeChart(symbol, data_path=None, historical_data=None) - # Start the WebSocket connection in a separate thread - # The _start_websocket_thread method already handles this correctly - - # Run the Dash server in a separate thread - thread = Thread(target=lambda c=chart, p=port: c.run(host='localhost', port=p)) - thread.daemon = True - thread.start() - - # Give the server a moment to start + # Give the server a moment to start (the app is started automatically in __init__ now) await asyncio.sleep(2) logger.info(f"Started realtime chart for {symbol} on port {port}") @@ -527,16 +498,28 @@ async def start_realtime_chart(symbol="BTC/USDT", port=8050): logger.error(traceback.format_exc()) raise -def run_training_thread(chart): +def run_training_thread(chart, num_episodes=5000, skip_training=False): """Start the RL training in a separate thread""" integrator = RLTrainingIntegrator(chart) def training_thread_func(): try: - # Use a small number of episodes to test termination handling - integrator.start_training(num_episodes=100, max_steps=1000) + # Create stop event + integrator.stop_event = threading.Event() + # Initialize session tracking + integrator.session_step = 0 + + if skip_training: + logger.info("Skipping training as requested (--no-train flag)") + # Just sleep for a bit to keep the thread alive + time.sleep(10) + else: + # Use a small number of episodes to test termination handling + integrator.start_training(num_episodes=num_episodes, max_steps=2000) except Exception as e: logger.error(f"Error in training thread: {str(e)}") + import traceback + logger.error(traceback.format_exc()) thread = threading.Thread(target=training_thread_func) thread.daemon = True @@ -545,37 +528,44 @@ def run_training_thread(chart): return thread, integrator def test_signals(chart): - """Add test signals to the chart to verify functionality""" + """Add test signals and trades to the chart to verify functionality""" from datetime import datetime - logger.info("Adding test signals to chart") + logger.info("Adding test trades to chart") - # Add a test BUY signal - chart.add_nn_signal("BUY", datetime.now(), 0.95) - - # Sleep briefly - time.sleep(1) - - # Add a test SELL signal - chart.add_nn_signal("SELL", datetime.now(), 0.85) - - # Add a test trade if the method exists + # Add test trades if hasattr(chart, 'add_trade'): + # Add a BUY trade chart.add_trade( price=83000.0, timestamp=datetime.now(), + amount=0.1, pnl=0.05, - action="BUY", - type="BUY" # Add explicit type + action="BUY" ) + + # Wait briefly + time.sleep(1) + + # Add a SELL trade + chart.add_trade( + price=83050.0, + timestamp=datetime.now(), + amount=0.1, + pnl=0.2, + action="SELL" + ) + + logger.info("Test trades added successfully") else: - logger.warning("RealTimeChart has no add_trade method - skipping test trade") + logger.warning("RealTimeChart has no add_trade method - skipping test trades") async def main(): """Main function that coordinates the realtime chart and RL training""" global realtime_chart, realtime_websocket_task, running logger.info("Starting integrated RL training with realtime visualization") + logger.info(f"Using log file: {log_filename}") # Start the realtime chart realtime_chart, realtime_websocket_task = await start_realtime_chart() @@ -586,12 +576,24 @@ async def main(): # Test signals first test_signals(realtime_chart) - # Start the training in a separate thread - training_thread, integrator = run_training_thread(realtime_chart) + # If visualize-only is set, don't start the training thread + if not args.visualize_only or not args.no_train: + # Start the training in a separate thread + num_episodes = args.episodes if not args.no_train else 1 + training_thread, integrator = run_training_thread(realtime_chart, num_episodes=num_episodes, + skip_training=args.no_train) + else: + # Create a dummy integrator for the final stats + integrator = RLTrainingIntegrator(realtime_chart) + integrator.session_pnl = 0.0 + integrator.session_trades = 0 + integrator.session_wins = 0 + integrator.session_balance = 100.0 + training_thread = None try: # Keep the main task running until interrupted - while running and training_thread.is_alive(): + while running and (training_thread is None or training_thread.is_alive()): await asyncio.sleep(1) except KeyboardInterrupt: logger.info("Shutting down...")