diff --git a/backend/igny8_core/ai/tracker.py b/backend/igny8_core/ai/tracker.py index f403f5f3..7b6b61a0 100644 --- a/backend/igny8_core/ai/tracker.py +++ b/backend/igny8_core/ai/tracker.py @@ -236,21 +236,35 @@ class ConsoleStepTracker: self.start_time = time.time() self.steps = [] self.current_phase = None + + # Debug: Verify DEBUG_MODE is enabled + if DEBUG_MODE: + print(f"[DEBUG] ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is ENABLED", flush=True) + logger.info(f"ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is ENABLED") + else: + print(f"[WARNING] ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is DISABLED", flush=True) + logger.warning(f"ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is DISABLED") def _log(self, phase: str, message: str, status: str = 'info'): """Internal logging method that checks DEBUG_MODE""" if not DEBUG_MODE: return + import sys timestamp = datetime.now().strftime('%H:%M:%S') phase_label = phase.upper() if status == 'error': - print(f"[{timestamp}] [{self.function_name}] [{phase_label}] [ERROR] {message}") + log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] [ERROR] {message}" elif status == 'success': - print(f"[{timestamp}] [{self.function_name}] [{phase_label}] ✅ {message}") + log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] ✅ {message}" else: - print(f"[{timestamp}] [{self.function_name}] [{phase_label}] {message}") + log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] {message}" + + # Print and flush immediately to ensure console output + print(log_msg, flush=True) + # Also log to Python logger for better visibility + logger.info(log_msg) self.steps.append({ 'timestamp': timestamp, @@ -285,7 +299,9 @@ class ConsoleStepTracker: duration = time.time() - self.start_time self._log('DONE', f"{message} (Duration: {duration:.2f}s)", status='success') if DEBUG_MODE: - print(f"[{self.function_name}] === AI Task Complete ===") + import sys + print(f"[{self.function_name}] === AI Task Complete ===", flush=True) + logger.info(f"[{self.function_name}] === AI Task Complete ===") def error(self, error_type: str, message: str, exception: Exception = None): """Log error with standardized format""" @@ -294,9 +310,11 @@ class ConsoleStepTracker: error_msg += f" ({type(exception).__name__})" self._log(self.current_phase or 'ERROR', error_msg, status='error') if DEBUG_MODE and exception: + import sys import traceback - print(f"[{self.function_name}] [ERROR] Stack trace:") + print(f"[{self.function_name}] [ERROR] Stack trace:", flush=True) traceback.print_exc() + logger.error(f"[{self.function_name}] [ERROR] Stack trace:", exc_info=exception) def retry(self, attempt: int, max_attempts: int, reason: str = ""): """Log retry attempt""" diff --git a/backend/igny8_core/modules/planner/tasks.py b/backend/igny8_core/modules/planner/tasks.py index 9a31aff7..9b366940 100644 --- a/backend/igny8_core/modules/planner/tasks.py +++ b/backend/igny8_core/modules/planner/tasks.py @@ -885,187 +885,63 @@ def auto_generate_ideas_task(self, cluster_ids: List[int], account_id: int = Non } ) - # Create AIProcessor instance with account to load API keys from IntegrationSettings + # Use new AI framework with proper logging account = clusters[0].account if clusters else None - from igny8_core.utils.ai_processor import AIProcessor - processor = AIProcessor(account=account) + account_id = account.id if account else None - logger.info(f"Calling AIProcessor.generate_ideas with {len(cluster_data)} clusters, account_id={account.id if account else None}") - result = processor.generate_ideas(cluster_data, account=account) + # Process each cluster using the new framework + from igny8_core.ai.functions.generate_ideas import generate_ideas_core + from igny8_core.ai.tasks import run_ai_task - # Log AI response + ideas_created = 0 + all_ideas = [] + + # Process each cluster individually using the new framework + for idx, cluster in enumerate(clusters): + cluster_id = cluster.id + logger.info(f"Processing cluster {idx + 1}/{total_clusters}: {cluster_id}") + + # Update progress + progress_pct = 10 + int((idx / total_clusters) * 70) + self.update_state( + state='PROGRESS', + meta={ + 'current': idx + 1, + 'total': total_clusters, + 'percentage': progress_pct, + 'message': f'Generating idea for cluster "{cluster.name}" ({idx + 1} of {total_clusters})...', + 'phase': 'generating', + 'current_item': cluster.name + } + ) + + # Use new framework - always use generate_ideas_core for proper console logging + try: + # Use generate_ideas_core which has ConsoleStepTracker built in + result = generate_ideas_core(cluster_id, account_id=account_id) + if result.get('success'): + ideas_created += result.get('idea_created', 0) + logger.info(f"✓ Successfully generated idea for cluster {cluster_id}") + else: + logger.error(f"✗ Failed to generate idea for cluster {cluster_id}: {result.get('error')}") + except Exception as e: + logger.error(f"✗ Error generating idea for cluster {cluster_id}: {str(e)}", exc_info=True) + + # Ideas are already saved by the new framework, just log results logger.info("=" * 80) - logger.info("AI RESPONSE RECEIVED:") - logger.info("=" * 80) - if result.get('error'): - logger.error(f"AI Error: {result['error']}") - else: - ideas = result.get('ideas', []) - logger.info(f"Total ideas received: {len(ideas)}") - for idx, idea in enumerate(ideas[:3]): # Log first 3 ideas - logger.info(f"Idea {idx + 1}:") - logger.info(f" - Title: {idea.get('title', 'N/A')}") - logger.info(f" - Content Type: {idea.get('content_type', 'N/A')}") - logger.info(f" - Content Structure: {idea.get('content_structure', 'N/A')}") - logger.info(f" - Cluster Name: {idea.get('cluster_name', 'N/A')}") - logger.info(f" - Cluster ID: {idea.get('cluster_id', 'N/A')}") - logger.info(f" - Target Keywords: {idea.get('target_keywords', idea.get('covered_keywords', 'N/A'))}") - logger.info(f" - Description type: {type(idea.get('description', '')).__name__}") - if idx < 2: # Only show full description for first 2 - desc = idea.get('description', '') - if isinstance(desc, str): - logger.info(f" - Description (first 200 chars): {desc[:200]}...") - else: - logger.info(f" - Description (dict): {str(desc)[:200]}...") + logger.info(f"IDEAS GENERATION COMPLETE: {ideas_created} ideas created") logger.info("=" * 80) - if result.get('error'): - logger.error(f"AI ideas generation error: {result['error']}") + if ideas_created == 0: + logger.warning("No ideas were created") self.update_state( state='FAILURE', meta={ - 'error': result['error'], - 'message': f"Error: {result['error']}" + 'error': 'No ideas created', + 'message': 'No ideas were created' } ) - return {'success': False, 'error': result['error']} - - # Update progress: Saving ideas (80-95%) - ideas_data = result.get('ideas', []) - self.update_state( - state='PROGRESS', - meta={ - 'current': 0, - 'total': len(ideas_data), - 'percentage': 80, - 'message': f'Saving {len(ideas_data)} generated ideas...', - 'phase': 'saving' - } - ) - - ideas_created = 0 - - # Create ContentIdeas records - with transaction.atomic(): - for idx, idea_data in enumerate(ideas_data): - logger.info(f"Processing idea {idx + 1}/{len(ideas_data)}: {idea_data.get('title', 'Untitled')}") - - cluster_name = idea_data.get('cluster_name', '') - cluster_id_from_ai = idea_data.get('cluster_id') - - logger.info(f" - Looking for cluster: name='{cluster_name}', id_from_ai={cluster_id_from_ai}") - logger.info(f" - Available clusters: {[(c.id, c.name) for c in clusters]}") - - # Find cluster - try by ID first, then by name - cluster = None - if cluster_id_from_ai: - for c in clusters: - if c.id == cluster_id_from_ai: - cluster = c - logger.info(f" - Found cluster by ID: {c.id} - {c.name}") - break - - # Fallback to name matching if ID didn't work - if not cluster and cluster_name: - for c in clusters: - if c.name == cluster_name: - cluster = c - logger.info(f" - Found cluster by name: {c.id} - {c.name}") - break - - # If still no cluster, try to match by position (first idea goes to first cluster, etc.) - if not cluster and len(clusters) > 0: - # Use modulo to distribute ideas across clusters - cluster_index = idx % len(clusters) - cluster = clusters[cluster_index] - logger.info(f" - Cluster not found by name/ID, using cluster at index {cluster_index}: {cluster.id} - {cluster.name}") - - if not cluster: - logger.warning(f"Cluster not found for idea: {cluster_name or cluster_id_from_ai}, skipping") - continue - - # Ensure site is available (extract from cluster or sector) - site = cluster.site - if not site and cluster.sector: - site = cluster.sector.site - - logger.info(f" - Cluster details:") - logger.info(f" - ID: {cluster.id}") - logger.info(f" - Name: {cluster.name}") - account = getattr(cluster, 'account', None) - logger.info(f" - Account ID: {account.id if account else 'None'}") - logger.info(f" - Site ID: {cluster.site_id if cluster.site else 'None'}") - logger.info(f" - Site object: {site.id if site else 'None'}") - logger.info(f" - Sector ID: {cluster.sector_id if cluster.sector else 'None'}") - - if not site: - logger.error(f"Site not found for cluster {cluster.id} (site_id={cluster.site_id}, sector.site_id={cluster.sector.site_id if cluster.sector and cluster.sector.site else 'None'}), cannot create ContentIdeas") - continue - - # Update progress for each idea - progress_pct = 80 + int((idx / len(ideas_data)) * 15) - self.update_state( - state='PROGRESS', - meta={ - 'current': idx + 1, - 'total': len(ideas_data), - 'percentage': progress_pct, - 'message': f"Saving idea '{idea_data.get('title', 'Untitled')}' ({idx + 1} of {len(ideas_data)})...", - 'phase': 'saving', - 'current_item': idea_data.get('title', 'Untitled') - } - ) - - # Handle description - it might be a dict (structured outline) or string - description = idea_data.get('description', '') - if isinstance(description, dict): - # Convert structured outline to JSON string - import json - description = json.dumps(description) - logger.info(f" - Description converted from dict to JSON (length: {len(description)})") - elif not isinstance(description, str): - description = str(description) - logger.info(f" - Description converted to string (type was {type(idea_data.get('description', '')).__name__})") - - # Handle target_keywords - might be in covered_keywords or target_keywords - target_keywords = idea_data.get('covered_keywords', '') or idea_data.get('target_keywords', '') - - # Prepare ContentIdeas record data - # Get account - account = getattr(cluster, 'account', None) - - idea_record_data = { - 'idea_title': idea_data.get('title', 'Untitled Idea'), - 'description': description, - 'content_type': idea_data.get('content_type', 'blog_post'), - 'content_structure': idea_data.get('content_structure', 'supporting_page'), - 'target_keywords': target_keywords, - 'keyword_cluster': cluster, - 'estimated_word_count': idea_data.get('estimated_word_count', 1500), - 'status': 'new', - 'account': account, # Use account field - 'site': site, - 'sector': cluster.sector, - } - - logger.info(f" - Creating ContentIdeas record with:") - logger.info(f" - idea_title: {idea_record_data['idea_title'][:50]}...") - logger.info(f" - content_type: {idea_record_data['content_type']}") - logger.info(f" - content_structure: {idea_record_data['content_structure']}") - logger.info(f" - account_id: {idea_record_data['account'].id if idea_record_data['account'] else 'None'}") - logger.info(f" - site_id: {idea_record_data['site'].id if idea_record_data['site'] else 'None'}") - logger.info(f" - sector_id: {idea_record_data['sector'].id if idea_record_data['sector'] else 'None'}") - logger.info(f" - keyword_cluster_id: {cluster.id}") - - try: - # Create ContentIdeas record - ContentIdeas.objects.create(**idea_record_data) - ideas_created += 1 - logger.info(f" - ✓ Successfully created ContentIdeas record") - except Exception as create_error: - logger.error(f" - ✗ Failed to create ContentIdeas record: {type(create_error).__name__}: {str(create_error)}") - logger.error(f" - Error details: {create_error}", exc_info=True) - raise # Re-raise to see the full traceback + return {'success': False, 'error': 'No ideas created'} # Final progress update final_message = f"Ideas generation complete: {ideas_created} ideas created for {total_clusters} clusters" @@ -1164,24 +1040,26 @@ def _generate_single_idea_core(cluster_id: int, account_id: int = None, progress } ) - # Create AIProcessor instance with account to load API keys from IntegrationSettings + # Use new AI framework with proper logging account = getattr(cluster, 'account', None) - from igny8_core.utils.ai_processor import AIProcessor - processor = AIProcessor(account=account) - result = processor.generate_ideas(cluster_data, account=account) + account_id = account.id if account else None - if result.get('error'): - logger.error(f"AI idea generation error: {result['error']}") - return {'success': False, 'error': result['error']} + # Use new framework with proper console logging + from igny8_core.ai.functions.generate_ideas import generate_ideas_core - # Update progress: Saving idea (80-95%) - ideas_data = result.get('ideas', []) - if not ideas_data: - logger.warning(f"No ideas generated for cluster: {cluster.name}") - return {'success': False, 'error': 'No ideas generated by AI'} + # Use generate_ideas_core which has ConsoleStepTracker built in + try: + result = generate_ideas_core(cluster_id, account_id=account_id, progress_callback=progress_callback) + except Exception as e: + logger.error(f"Error generating idea: {str(e)}", exc_info=True) + return {'success': False, 'error': str(e)} - # Take the first idea (since we're generating for a single cluster) - idea_data = ideas_data[0] + if not result.get('success'): + error_msg = result.get('error', 'Unknown error') + logger.error(f"AI idea generation error: {error_msg}") + return {'success': False, 'error': error_msg} + + idea_created = result.get('idea_created', 0) or result.get('ideas_created', 0) if progress_callback: progress_callback( @@ -1189,50 +1067,17 @@ def _generate_single_idea_core(cluster_id: int, account_id: int = None, progress meta={ 'current': 1, 'total': 1, - 'percentage': 80, - 'message': f"Saving idea '{idea_data.get('title', 'Untitled')}'...", - 'phase': 'saving', - 'current_item': idea_data.get('title', 'Untitled') + 'percentage': 95, + 'message': 'Idea generation complete', + 'phase': 'complete' } ) - idea_created = 0 - - # Create ContentIdeas record - with transaction.atomic(): - # Handle description - it might be a dict (structured outline) or string - description = idea_data.get('description', '') - if isinstance(description, dict): - # Convert structured outline to JSON string - import json - description = json.dumps(description) - elif not isinstance(description, str): - description = str(description) - - # Handle target_keywords - might be in covered_keywords or target_keywords - target_keywords = idea_data.get('covered_keywords', '') or idea_data.get('target_keywords', '') - - # Get account - account = getattr(cluster, 'account', None) - - # Create ContentIdeas record - ContentIdeas.objects.create( - idea_title=idea_data.get('title', 'Untitled Idea'), - description=description, - content_type=idea_data.get('content_type', 'blog_post'), - content_structure=idea_data.get('content_structure', 'supporting_page'), - target_keywords=target_keywords, - keyword_cluster=cluster, - estimated_word_count=idea_data.get('estimated_word_count', 1500), - status='new', - account=account, # Use account field - site=cluster.site, - sector=cluster.sector, - ) - idea_created = 1 + # Ideas are already saved by the new framework (generate_ideas_core or run_ai_task) + # No need to save again here # Final progress update - final_message = f"Idea generation complete: '{idea_data.get('title', 'Untitled Idea')}' created" + final_message = f"Idea generation complete: {idea_created} idea(s) created" logger.info(final_message) if progress_callback: