add debug

foodie_engagement_tweet.py

@@ -16,12 +16,14 @@ from foodie_utils import (
     check_author_rate_limit,
     load_json_file,
     update_system_activity,
-    get_next_author_round_robin  # Added import
+    get_next_author_round_robin
 )
 from foodie_config import X_API_CREDENTIALS, AUTHOR_BACKGROUNDS_FILE
 from dotenv import load_dotenv
 
+print("Loading environment variables")
 load_dotenv()
+print(f"Environment variables loaded: OPENAI_API_KEY={bool(os.getenv('OPENAI_API_KEY'))}")
 
 SCRIPT_NAME = "foodie_engagement_tweet"
 LOCK_FILE = "/home/shane/foodie_automator/locks/foodie_engagement_tweet.lock"
@@ -32,9 +34,15 @@ RETRY_BACKOFF = 2
 
 def setup_logging():
     """Initialize logging with pruning of old logs."""
+    print("Entering setup_logging")
     try:
-        os.makedirs(os.path.dirname(LOG_FILE), exist_ok=True)
+        log_dir = os.path.dirname(LOG_FILE)
+        print(f"Ensuring log directory exists: {log_dir}")
+        os.makedirs(log_dir, exist_ok=True)
+        print(f"Log directory permissions: {os.stat(log_dir).st_mode & 0o777}, owner: {os.stat(log_dir).st_uid}")
+        
         if os.path.exists(LOG_FILE):
+            print(f"Pruning old logs in {LOG_FILE}")
             with open(LOG_FILE, 'r') as f:
                 lines = f.readlines()
             cutoff = datetime.now(timezone.utc) - timedelta(days=LOG_PRUNE_DAYS)
@@ -51,11 +59,12 @@ def setup_logging():
                 except ValueError:
                     malformed_count += 1
                     continue
-            if malformed_count > 0:
+            print(f"Skipped {malformed_count} malformed log lines during pruning")
-                logging.info(f"Skipped {malformed_count} malformed log lines during pruning")
             with open(LOG_FILE, 'w') as f:
                 f.writelines(pruned_lines)
+            print(f"Log file pruned, new size: {os.path.getsize(LOG_FILE)} bytes")
         
+        print(f"Configuring logging to {LOG_FILE}")
         logging.basicConfig(
             filename=LOG_FILE,
             level=logging.INFO,
@@ -67,25 +76,37 @@ def setup_logging():
         logging.getLogger().addHandler(console_handler)
         logging.getLogger("openai").setLevel(logging.WARNING)
         logging.info("Logging initialized for foodie_engagement_tweet.py")
+        print("Logging setup complete")
     except Exception as e:
         print(f"Failed to setup logging: {e}")
         sys.exit(1)
 
 def acquire_lock():
     """Acquire a lock to prevent concurrent runs."""
-    os.makedirs(os.path.dirname(LOCK_FILE), exist_ok=True)
+    print("Entering acquire_lock")
-    lock_fd = open(LOCK_FILE, 'w')
     try:
+        lock_dir = os.path.dirname(LOCK_FILE)
+        print(f"Ensuring lock directory exists: {lock_dir}")
+        os.makedirs(lock_dir, exist_ok=True)
+        print(f"Opening lock file: {LOCK_FILE}")
+        lock_fd = open(LOCK_FILE, 'w')
+        print(f"Attempting to acquire lock on {LOCK_FILE}")
         fcntl.flock(lock_fd, fcntl.LOCK_EX | fcntl.LOCK_NB)
         lock_fd.write(str(os.getpid()))
         lock_fd.flush()
+        print(f"Lock acquired, PID: {os.getpid()}")
         return lock_fd
-    except IOError:
+    except IOError as e:
+        print(f"Failed to acquire lock, another instance is running: {e}")
         logging.info("Another instance of foodie_engagement_tweet.py is running")
         sys.exit(0)
+    except Exception as e:
+        print(f"Unexpected error in acquire_lock: {e}")
+        sys.exit(1)
 
 def signal_handler(sig, frame):
     """Handle termination signals gracefully."""
+    print(f"Received signal: {sig}")
     logging.info("Received termination signal, marking script as stopped...")
     update_system_activity(SCRIPT_NAME, "stopped")
     sys.exit(0)
@@ -94,37 +115,50 @@ signal.signal(signal.SIGTERM, signal_handler)
 signal.signal(signal.SIGINT, signal_handler)
 
 # Initialize OpenAI client
+print("Initializing OpenAI client")
 try:
     client = OpenAI(api_key=os.getenv("OPENAI_API_KEY"))
     if not os.getenv("OPENAI_API_KEY"):
+        print("OPENAI_API_KEY is not set")
         logging.error("OPENAI_API_KEY is not set in environment variables")
         raise ValueError("OPENAI_API_KEY is required")
+    print("OpenAI client initialized")
 except Exception as e:
+    print(f"Failed to initialize OpenAI client: {e}")
     logging.error(f"Failed to initialize OpenAI client: {e}", exc_info=True)
     sys.exit(1)
 
 # Load author backgrounds
+print(f"Loading author backgrounds from {AUTHOR_BACKGROUNDS_FILE}")
 try:
     with open(AUTHOR_BACKGROUNDS_FILE, 'r') as f:
         AUTHOR_BACKGROUNDS = json.load(f)
+    print(f"Author backgrounds loaded: {len(AUTHOR_BACKGROUNDS)} entries")
 except Exception as e:
+    print(f"Failed to load author_backgrounds.json: {e}")
     logging.error(f"Failed to load author_backgrounds.json: {e}", exc_info=True)
     sys.exit(1)
 
 def generate_engagement_tweet(author):
     """Generate an engagement tweet using author background themes."""
+    print(f"Generating tweet for author: {author['username']}")
+    try:
         credentials = X_API_CREDENTIALS.get(author["username"])
         if not credentials:
+            print(f"No X credentials found for {author['username']}")
             logging.error(f"No X credentials found for {author['username']}")
             return None
         author_handle = credentials["x_username"]
+        print(f"Author handle: {author_handle}")
         
         background = next((bg for bg in AUTHOR_BACKGROUNDS if bg["username"] == author["username"]), {})
         if not background or "engagement_themes" not in background:
+            print(f"No background or themes for {author['username']}, using default theme")
             logging.warning(f"No background or engagement themes found for {author['username']}")
             theme = "food trends"
         else:
             theme = random.choice(background["engagement_themes"])
+            print(f"Selected theme: {theme}")
         
         prompt = (
             f"Generate a concise tweet (under 230 characters) for {author_handle}. "
@@ -133,8 +167,10 @@ def generate_engagement_tweet(author):
             f"Avoid using the word 'elevate'—use more humanized language like 'level up' or 'bring to life'. "
             f"Do not include emojis, hashtags, or reward-driven incentives (e.g., giveaways)."
         )
+        print(f"OpenAI prompt: {prompt}")
         
         for attempt in range(MAX_RETRIES):
+            print(f"Attempt {attempt + 1} to generate tweet")
             try:
                 response = client.chat.completions.create(
                     model=SUMMARY_MODEL,
@@ -148,13 +184,16 @@ def generate_engagement_tweet(author):
                 tweet = response.choices[0].message.content.strip()
                 if len(tweet) > 280:
                     tweet = tweet[:277] + "..."
+                print(f"Generated tweet: {tweet}")
                 logging.debug(f"Generated engagement tweet: {tweet}")
                 return tweet
             except Exception as e:
+                print(f"Failed to generate tweet (attempt {attempt + 1}): {e}")
                 logging.warning(f"Failed to generate engagement tweet for {author['username']} (attempt {attempt + 1}): {e}")
                 if attempt < MAX_RETRIES - 1:
                     time.sleep(RETRY_BACKOFF * (2 ** attempt))
                 else:
+                    print(f"Exhausted retries for {author['username']}")
                     logging.error(f"Failed to generate engagement tweet after {MAX_RETRIES} attempts")
                     engagement_templates = [
                         f"What's the most mouthwatering {theme} you've seen this week? Share below and follow {author_handle} for more on InsiderFoodie.com! Link: https://insiderfoodie.com",
@@ -163,69 +202,110 @@ def generate_engagement_tweet(author):
                         f"What {theme} trend are you loving right now? Let us know and like this tweet to keep up with {author_handle} on InsiderFoodie.com! Link: https://insiderfoodie.com"
                     ]
                     template = random.choice(engagement_templates)
+                    print(f"Using fallback tweet: {template}")
                     logging.info(f"Using fallback engagement tweet: {template}")
                     return template
+    except Exception as e:
+        print(f"Error in generate_engagement_tweet for {author['username']}: {e}")
+        logging.error(f"Error in generate_engagement_tweet for {author['username']}: {e}", exc_info=True)
+        return None
 
 def post_engagement_tweet():
     """Post engagement tweets for authors daily."""
+    print("Entering post_engagement_tweet")
     try:
         logging.info("Starting foodie_engagement_tweet.py")
         posted = False
         
-        # Get next available author using round-robin
+        print("Getting next author")
         author = get_next_author_round_robin()
         if not author:
+            print("No authors available due to rate limits")
             logging.info("No authors available due to rate limits")
-            sleep_time = random.randint(1200, 1800)  # 20–30 minutes
+            sleep_time = 86400  # 1 day for cron
             return False, sleep_time
+        print(f"Selected author: {author['username']}")
 
         try:
+            print("Checking rate limit")
+            if not check_author_rate_limit(author['username']):
+                print(f"Rate limit exceeded for {author['username']}")
+                logging.info(f"Rate limit exceeded for {author['username']}")
+                sleep_time = 86400  # 1 day
+                return False, sleep_time
+            
+            print("Generating tweet")
             tweet = generate_engagement_tweet(author)
             if not tweet:
+                print(f"Failed to generate tweet for {author['username']}")
                 logging.error(f"Failed to generate engagement tweet for {author['username']}, skipping")
-                sleep_time = random.randint(1200, 1800)  # 20–30 minutes
+                sleep_time = 86400  # 1 day
                 return False, sleep_time
             
+            print(f"Posting tweet: {tweet}")
             logging.info(f"Posting engagement tweet for {author['username']}: {tweet}")
             if post_tweet(author, tweet):
+                print(f"Successfully posted tweet for {author['username']}")
                 logging.info(f"Successfully posted engagement tweet for {author['username']}")
                 posted = True
             else:
+                print(f"Failed to post tweet for {author['username']}")
                 logging.warning(f"Failed to post engagement tweet for {author['username']}")
         except Exception as e:
+            print(f"Error posting tweet for {author['username']}: {e}")
             logging.error(f"Error posting engagement tweet for {author['username']}: {e}", exc_info=True)
         
+        print("Completed post_engagement_tweet")
         logging.info("Completed foodie_engagement_tweet.py")
-        sleep_time = random.randint(1200, 1800)  # 20–30 minutes
+        sleep_time = 86400  # 1 day for cron
         return posted, sleep_time
     except Exception as e:
+        print(f"Unexpected error in post_engagement_tweet: {e}")
         logging.error(f"Unexpected error in post_engagement_tweet: {e}", exc_info=True)
-        sleep_time = random.randint(1200, 1800)  # 20–30 minutes
+        sleep_time = 86400  # 1 day
         return False, sleep_time
 
 def main():
     """Main function to run the script."""
+    print("Starting main")
     lock_fd = None
     try:
+        print("Acquiring lock")
         lock_fd = acquire_lock()
+        print("Setting up logging")
         setup_logging()
-        update_system_activity(SCRIPT_NAME, "running", os.getpid())  # Record start
+        print("Updating system activity to running")
+        update_system_activity(SCRIPT_NAME, "running", os.getpid())
+        print("Checking author state file")
+        author_state_file = "/home/shane/foodie_automator/author_state.json"
+        if not os.path.exists(author_state_file):
+            print(f"Author state file not found: {author_state_file}")
+            logging.error(f"Author state file not found: {author_state_file}")
+            raise FileNotFoundError(f"Author state file not found: {author_state_file}")
+        print(f"Author state file exists: {author_state_file}")
+        print("Posting engagement tweet")
         posted, sleep_time = post_engagement_tweet()
-        update_system_activity(SCRIPT_NAME, "stopped")  # Record stop
+        print("Updating system activity to stopped")
-        logging.info(f"Run completed, sleep_time: {sleep_time} seconds")
+        update_system_activity(SCRIPT_NAME, "stopped")
+        print(f"Run completed, posted: {posted}, sleep_time: {sleep_time}")
+        logging.info(f"Run completed, posted: {posted}, sleep_time: {sleep_time} seconds")
         return posted, sleep_time
     except Exception as e:
+        print(f"Exception in main: {e}")
         logging.error(f"Fatal error in main: {e}", exc_info=True)
         print(f"Fatal error: {e}")
-        update_system_activity(SCRIPT_NAME, "stopped")  # Record stop on error
+        update_system_activity(SCRIPT_NAME, "stopped")
-        sleep_time = random.randint(1200, 1800)  # 20–30 minutes
+        sleep_time = 86400  # 1 day for cron
+        print(f"Run completed, sleep_time: {sleep_time}")
         logging.info(f"Run completed, sleep_time: {sleep_time} seconds")
         return False, sleep_time
     finally:
         if lock_fd:
+            print("Releasing lock")
             fcntl.flock(lock_fd, fcntl.LOCK_UN)
             lock_fd.close()
             os.remove(LOCK_FILE) if os.path.exists(LOCK_FILE) else None
+            print(f"Lock file removed: {LOCK_FILE}")
 
 if __name__ == "__main__":
     posted, sleep_time = main()