trading-bot/main.py

import os
import time
import logging
import pytz
import threading
import csv
import random
from datetime import datetime, time as dtime
from dotenv import load_dotenv

from src.api.client import Trading212Client
from src.strategy.touch_turn import TouchTurnStrategy
from src.execution.manager import ExecutionManager
from scripts.find_isa_candidates import find_best_isa_tickers
from scripts.backtest import backtest_ticker

# Force flush handler to ensure bot logs are written to disk immediately
class FlushHandler(logging.FileHandler):
    def emit(self, record):
        super().emit(record)
        self.flush()

# Ensure logs directory exists
os.makedirs("logs", exist_ok=True)
log_filename = datetime.now().strftime("logs/bot_%Y-%m-%d.log")

# Configure logging to both console and file
file_handler = FlushHandler(log_filename)
stream_handler = logging.StreamHandler()

logging.basicConfig(
    level=logging.INFO, 
    format='%(asctime)s [%(threadName)s] %(levelname)s - %(message)s',
    handlers=[file_handler, stream_handler]
)
logger = logging.getLogger(__name__)

# Force flush helper to ensure bot logs are written to disk before thread exit
def flush_logs():
    for handler in logging.getLogger().handlers:
        handler.flush()

PNL_FILE = "pnl_tracking.csv"

def record_pnl(ticker, direction, entry_price, exit_price, reason, pnl_r, trading_ticker=None):
    """Appends the result of a closed trade to the PnL CSV."""
    file_exists = os.path.isfile(PNL_FILE)
    
    # Safety: Fix potential 0.0 exit price in logs causing extreme PnL values
    if exit_price <= 0:
        exit_price = entry_price 
        
    with open(PNL_FILE, mode='a', newline='') as file:
        writer = csv.writer(file)
        if not file_exists:
            writer.writerow(["Date", "Ticker", "Trading Ticker", "Direction", "Entry Price", "Exit Price", "Reason", "PnL (R)"])
            
        today = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
        writer.writerow([today, ticker, trading_ticker or ticker, direction, round(entry_price, 2), round(exit_price, 2), reason, round(pnl_r, 2)])
    
    label = f"{ticker} ({trading_ticker})" if trading_ticker else ticker
    logger.info(f"Recorded trade in {PNL_FILE}: {label} {direction} | Result: {reason} | PnL: {pnl_r:.2f} R")
    flush_logs()

def calculate_r_multiple(direction, entry_price, exit_price, stop_loss):
    """Calculates the PnL in terms of Risk Multiples (R)."""
    # Safety: Prevent Division by Zero if SL is somehow same as entry
    if abs(entry_price - stop_loss) < 0.001:
        return 0.0
        
    if direction == "BUY": # LONG
        risk = entry_price - stop_loss
        return (exit_price - entry_price) / risk if risk != 0 else 0
    else: # SHORT
        risk = stop_loss - entry_price
        return (entry_price - exit_price) / risk if risk != 0 else 0

def run_ticker_lifecycle(client, yf_ticker, t212_ticker, tz, num_tickers):
    """Handles the full strategy lifecycle for a single ticker in its own thread, then exits."""
    strategy = TouchTurnStrategy(yf_ticker)
    execution = ExecutionManager(client)
    
    logger.info(f"Bot thread started for {yf_ticker} ({t212_ticker}).")
    
    # Initialize variables outside the retry loop to prevent UnboundLocalError
    risk_share = 2.50 / num_tickers
    capital_share = 250.0 / num_tickers
    
    try:
        now = datetime.now(tz)
        target_entry_time = now.replace(hour=9, minute=45, second=0, microsecond=0)
        
        # 1. Wait until 09:45 EST
        if now < target_entry_time:
            wait_seconds = (target_entry_time - now).total_seconds()
            logger.info(f"Waiting {wait_seconds:.0f} seconds until 09:45 EST evaluation...")
            time.sleep(wait_seconds)
        
        # Re-evaluate current time
        now = datetime.now(tz)
        
        if now.hour == 9 and now.minute >= 45:
            logger.info(f"Evaluating opening candle for {yf_ticker}...")
            
            # Retry loop: wait for yfinance to publish the 09:30-09:45 candle
            setup_found = False
            max_retries = 12
            for attempt in range(max_retries):
                if strategy.check_setup():
                    setup_found = True
                    break
                elif attempt < max_retries - 1:
                    logger.debug(f"Data not ready for {yf_ticker} yet, waiting 15s...")
                    time.sleep(15)
                    
            if setup_found:
                params = strategy.get_trade_params()
                params['ticker'] = t212_ticker
                
                # Anti-thundering-herd: Random jitter to prevent 429s from parallel threads
                # Use a larger range (1-10s) to better stagger independent threads
                time.sleep(random.uniform(1.0, 10.0))
                
                # Fetch Account Balance to calculate risk with backoff
                for attempt in range(3):
                    try:
                        account_info = client.get_account_info()
                        actual_balance = float(account_info.get('totalValue', 5000.0))
                        virtual_balance = max(0, actual_balance - 4750.0)
                        
                        risk_share = (virtual_balance * 0.01) / num_tickers
                        capital_share = virtual_balance / num_tickers
                        
                        logger.info(f"Account: {actual_balance:.2f} | Virtual: {virtual_balance:.2f} | Share: {capital_share:.2f}")
                        break 
                    except Exception as e:
                        if '429' in str(e):
                            wait_time = (attempt + 1) * 5 + random.uniform(1, 3)
                            logger.warning(f"Rate limited on account fetch for {yf_ticker}. Retrying in {wait_time:.1f}s...")
                            time.sleep(wait_time)
                        else:
                            logger.error(f"Failed to fetch account info: {e}")
                            break

                if execution.execute_trade(params, target_risk_amount=risk_share, max_capital=capital_share):
                    if execution.monitor_and_bracket(params):
                        # Position is open, monitor for exit via SL/TP
                        while datetime.now(tz).hour < 11:
                            is_closed, reason, exit_price = execution.check_exit_status()
                            if is_closed:
                                final_entry = execution.params.get('final_entry', params['entry_price'])
                                final_sl = execution.params.get('final_sl', params['stop_loss'])
                                trading_ticker = execution.params.get('trading_ticker', yf_ticker)
                                
                                pnl_r = calculate_r_multiple("BUY" if execution.is_etp else params['direction'], final_entry, exit_price, final_sl)
                                record_pnl(yf_ticker, params['direction'], final_entry, exit_price, reason, pnl_r, trading_ticker=trading_ticker)
                                break 
                                
                            time.sleep(15)
                            now = datetime.now(tz)
            else:
                logger.info(f"No valid setup today for {yf_ticker}. Thread exiting.")
                return

        # 2. Wait until 11:00 EST for Forced Exit
        now = datetime.now(tz)
        target_exit_time = now.replace(hour=11, minute=0, second=0, microsecond=0)
        
        if now < target_exit_time and execution.is_in_position:
            wait_seconds = (target_exit_time - now).total_seconds()
            logger.info(f"Waiting {wait_seconds:.0f} seconds until 11:00 EST forced exit...")
            time.sleep(wait_seconds)

    except Exception as e:
        logger.error(f"Unexpected error in {yf_ticker} lifecycle: {e}", exc_info=True)
    finally:
        # 3. 11:00 EST - Cleanup (ensures closing even on thread crash)
        time.sleep(random.uniform(0.1, 5.0))
        
        logger.info(f"Cleanup phase reached for {yf_ticker}.")
        if execution.is_in_position:
            exit_price = execution.close_all(t212_ticker)
            if hasattr(execution, 'params') and exit_price > 0:
                final_entry = execution.params.get('final_entry', execution.params['entry_price'])
                final_sl = execution.params.get('final_sl', execution.params['stop_loss'])
                trading_ticker = execution.params.get('trading_ticker', yf_ticker)
                
                pnl_r = calculate_r_multiple("BUY" if execution.is_etp else execution.params['direction'], final_entry, exit_price, final_sl)
                record_pnl(yf_ticker, execution.params['direction'], final_entry, exit_price, "Forced Exit (Final)", pnl_r, trading_ticker=trading_ticker)
        else:
            execution.close_all(t212_ticker)

        logger.info(f"Lifecycle complete for {yf_ticker}. Thread exiting.")
        flush_logs()

def main():
    load_dotenv()
    api_key_id = os.getenv("TRADING212_API_KEY_ID")
    api_key = os.getenv("TRADING212_API_KEY")
    base_url = os.getenv("TRADING212_BASE_URL", "https://demo.trading212.com/api/v0/")
    tz = pytz.timezone('US/Eastern')
    
    now = datetime.now(tz)
    
    if now.weekday() >= 5: 
        logger.warning("Weekend detected. The market is closed. Exiting cleanly.")
        return
        
    if now.hour < 9 or (now.hour == 9 and now.minute > 40) or now.hour >= 10:
        logger.warning(f"Bot executed at {now.strftime('%H:%M')} EST. Expected launch window is 09:00 - 09:40 EST. Exiting cleanly.")
        return

    if not api_key_id or not api_key:
        logger.error("API credentials not found in .env")
        return

    client = Trading212Client(api_key_id, api_key, base_url)

    # Early verification: Check connection before starting the day
    try:
        logger.info("Verifying API connection...")
        client.get_account_info()
        logger.info("API Connection verified successfully.")
    except Exception as e:
        logger.error(f"API Connection check failed: {e}")
        logger.error("Please check your API key and permissions in .env. Exiting.")
        return

    logger.info("Starting Morning Routine: Finding ISA Candidates...")
    candidates_df = find_best_isa_tickers()
    
    if candidates_df is None or candidates_df.empty:
        logger.error("No candidates found. Exiting.")
        return

    logger.info("Running Backtests on candidates to find current winners...")
    profitable_tickers = []
    
    for _, row in candidates_df.head(10).iterrows():
        yf_t = row['Ticker']
        t212_t = row['T212_Ticker']
        
        res = backtest_ticker(yf_t, quiet=True)
        if res and res['Net PnL (R)'] > 0:
            profitable_tickers.append({
                'yf': yf_t,
                't212': t212_t,
                'pnl': res['Net PnL (R)']
            })

    profitable_tickers.sort(key=lambda x: x['pnl'], reverse=True)
    final_watchlist = profitable_tickers[:3]
    
    if not final_watchlist:
        logger.warning("No tickers showed a positive backtest return. Bot will not trade today.")
        return

    logger.info(f"Final Watchlist for today: {[t['yf'] for t in final_watchlist]}")

    threads = []
    num_active = len(final_watchlist)
    for ticker_info in final_watchlist:
        t = threading.Thread(
            target=run_ticker_lifecycle, 
            args=(client, ticker_info['yf'], ticker_info['t212'], tz, num_active),
            name=f"Bot-{ticker_info['yf']}"
        )
        t.start()
        threads.append(t)

    logger.info("All execution threads launched. Waiting for completion...")

    for t in threads:
        t.join()
        
    logger.info("All threads completed. Bot shutting down for the day.")
    flush_logs()

if __name__ == "__main__":
    try:
        main()
    except Exception as e:
        logger.critical(f"FATAL ERROR in main: {e}", exc_info=True)
    finally:
        flush_logs()
        logger.info("Bot process terminated.")