#!/usr/bin/env python3 """ Multitest command for the MeshCore Bot Listens for a period of time and collects all unique paths from incoming messages """ import asyncio import time from typing import Set, Optional from .base_command import BaseCommand from ..models import MeshMessage from ..utils import calculate_packet_hash class MultitestCommand(BaseCommand): """Handles the multitest command - listens for multiple path variations""" # Plugin metadata name = "multitest" keywords = ['multitest', 'mt'] description = "Listens for 6 seconds and collects all unique paths from incoming messages" category = "meshcore_info" def __init__(self, bot): super().__init__(bot) self.listening = False self.collected_paths: Set[str] = set() self.listening_start_time = 0 self.listening_duration = 6.0 # 6 seconds listening window self.target_packet_hash: Optional[str] = None # Hash of the message we're tracking self.triggering_timestamp: float = 0.0 # Timestamp of the triggering message self._load_config() def _load_config(self): """Load configuration for multitest command""" response_format = self.get_config_value('Multitest_Command', 'response_format', fallback='') if response_format and response_format.strip(): # Strip quotes if present (config parser may add them) response_format = self._strip_quotes_from_config(response_format).strip() # Decode escape sequences (e.g., \n -> newline) try: # Use encode/decode to convert escape sequences to actual characters self.response_format = response_format.encode('latin-1').decode('unicode_escape') except (UnicodeDecodeError, UnicodeEncodeError): # If decoding fails, use as-is (fallback) self.response_format = response_format else: self.response_format = None # Use default format def get_help_text(self) -> str: return self.translate('commands.multitest.help', fallback="Listens for 6 seconds and collects all unique paths from incoming messages") def matches_keyword(self, message: MeshMessage) -> bool: """Check if message matches multitest keyword""" content = message.content.strip() # Handle exclamation prefix if content.startswith('!'): content = content[1:].strip() content_lower = content.lower() # Check for exact match or keyword followed by space for keyword in self.keywords: if content_lower == keyword or content_lower.startswith(keyword + ' '): return True # Check for variants: "mt long", "mt xlong", "multitest long", "multitest xlong" if content_lower.startswith('mt ') or content_lower.startswith('multitest '): parts = content_lower.split() if len(parts) >= 2 and parts[0] in ['mt', 'multitest']: variant = parts[1] if variant in ['long', 'xlong']: return True return False def extract_path_from_rf_data(self, rf_data: dict) -> Optional[str]: """Extract path in prefix string format from RF data routing_info""" try: routing_info = rf_data.get('routing_info') if not routing_info: return None path_nodes = routing_info.get('path_nodes', []) if not path_nodes: # Try to extract from path_hex if path_nodes not available path_hex = routing_info.get('path_hex', '') if path_hex: # Convert hex string to node list (every 2 characters = 1 node) path_nodes = [path_hex[i:i+2] for i in range(0, len(path_hex), 2)] if path_nodes: # Validate and format path nodes valid_parts = [] for node in path_nodes: # Convert to string if needed node_str = str(node).lower().strip() # Check if it's a 2-character hex value if len(node_str) == 2 and all(c in '0123456789abcdef' for c in node_str): valid_parts.append(node_str) if valid_parts: return ','.join(valid_parts) return None except Exception as e: self.logger.debug(f"Error extracting path from RF data: {e}") return None def extract_path_from_message(self, message: MeshMessage) -> Optional[str]: """Extract path in prefix string format from a message""" if not message.path: return None # Check if it's a direct connection if "Direct" in message.path or "0 hops" in message.path: return None # Try to extract path nodes from the path string # Path strings are typically in format: "node1,node2,node3 via ROUTE_TYPE_*" # or just "node1,node2,node3" path_string = message.path # Remove route type suffix if present if " via ROUTE_TYPE_" in path_string: path_string = path_string.split(" via ROUTE_TYPE_")[0] # Check if it looks like a comma-separated path if ',' in path_string: # Clean up any extra info (like hop counts in parentheses) # Example: "01,7e,55,86 (4 hops)" -> "01,7e,55,86" if '(' in path_string: path_string = path_string.split('(')[0].strip() # Validate that all parts are 2-character hex values parts = path_string.split(',') valid_parts = [] for part in parts: part = part.strip() # Check if it's a 2-character hex value if len(part) == 2 and all(c in '0123456789abcdefABCDEF' for c in part): valid_parts.append(part.lower()) if valid_parts: return ','.join(valid_parts) return None def get_rf_data_for_message(self, message: MeshMessage) -> Optional[dict]: """Get RF data for a message by looking it up in recent RF data""" try: # Try multiple correlation strategies # Strategy 1: Use sender_pubkey to find recent RF data if message.sender_pubkey: # Try full pubkey first recent_rf_data = self.bot.message_handler.find_recent_rf_data(message.sender_pubkey) if recent_rf_data: return recent_rf_data # Try pubkey prefix (first 16 chars) if len(message.sender_pubkey) >= 16: pubkey_prefix = message.sender_pubkey[:16] recent_rf_data = self.bot.message_handler.find_recent_rf_data(pubkey_prefix) if recent_rf_data: return recent_rf_data # Strategy 2: Look through recent RF data for matching pubkey if message.sender_pubkey and self.bot.message_handler.recent_rf_data: # Search recent RF data for matching pubkey for rf_data in reversed(self.bot.message_handler.recent_rf_data): rf_pubkey = rf_data.get('pubkey_prefix', '') if rf_pubkey and message.sender_pubkey.startswith(rf_pubkey): return rf_data # Strategy 3: Use most recent RF data as fallback # This is less reliable but might work if timing is very close if self.bot.message_handler.recent_rf_data: # Get the most recent RF data entry within a short time window current_time = time.time() recent_entries = [ rf for rf in self.bot.message_handler.recent_rf_data if current_time - rf.get('timestamp', 0) < 5.0 # Within last 5 seconds ] if recent_entries: most_recent = max(recent_entries, key=lambda x: x.get('timestamp', 0)) return most_recent return None except Exception as e: self.logger.debug(f"Error getting RF data for message: {e}") return None def on_message_received(self, message: MeshMessage): """Callback method called by message handler when a message is received during listening""" if not self.listening or not self.target_packet_hash: return # Check if we're still in the listening window elapsed = time.time() - self.listening_start_time if elapsed >= self.listening_duration: return # Get RF data for this message (contains pre-calculated packet hash) rf_data = self.get_rf_data_for_message(message) if not rf_data: # Can't get RF data, skip this message self.logger.debug(f"Skipping message - no RF data found (sender: {message.sender_id})") return # Use pre-calculated packet hash if available, otherwise calculate it message_hash = rf_data.get('packet_hash') if not message_hash and rf_data.get('raw_hex'): # Fallback: calculate hash if not stored (for older RF data) try: payload_type = None routing_info = rf_data.get('routing_info', {}) if routing_info: # Try to get payload type from routing_info if available payload_type = routing_info.get('payload_type') message_hash = calculate_packet_hash(rf_data['raw_hex'], payload_type) except Exception as e: self.logger.debug(f"Error calculating packet hash: {e}") message_hash = None if not message_hash: # Can't determine hash, skip this message self.logger.debug(f"Skipping message - could not determine packet hash (sender: {message.sender_id})") return # CRITICAL: Only collect paths if this message has the same hash as the target # This ensures we only track variations of the same original message if message_hash == self.target_packet_hash: # Try to extract path from RF data first (more reliable) path = self.extract_path_from_rf_data(rf_data) # Fallback to message path if RF data extraction failed if not path: path = self.extract_path_from_message(message) if path: self.collected_paths.add(path) self.logger.info(f"✓ Collected path: {path} (hash: {message_hash[:8]}...)") else: # Log when we have a matching hash but can't extract path routing_info = rf_data.get('routing_info', {}) path_length = routing_info.get('path_length', 0) if path_length == 0: self.logger.debug(f"Matched hash {message_hash[:8]}... but path is direct (0 hops)") else: self.logger.debug(f"Matched hash {message_hash[:8]}... but couldn't extract path from routing_info: {routing_info}") else: # Log hash mismatches for debugging (but limit to avoid spam) self.logger.debug(f"✗ Hash mismatch - target: {self.target_packet_hash[:8]}..., received: {message_hash[:8]}... (sender: {message.sender_id})") def _scan_recent_rf_data(self): """Scan recent RF data for packets with matching hash (for messages that haven't been processed yet)""" if not self.target_packet_hash: return try: current_time = time.time() matching_count = 0 mismatching_count = 0 # Look at RF data from the last few seconds (before listening started, in case packets arrived just before) for rf_data in self.bot.message_handler.recent_rf_data: # Check if this RF data is recent enough rf_timestamp = rf_data.get('timestamp', 0) time_diff = current_time - rf_timestamp # Only include RF data from the triggering message timestamp onwards # This prevents collecting packets from earlier messages that happen to have the same hash rf_timestamp = rf_data.get('timestamp', 0) if rf_timestamp >= self.triggering_timestamp and time_diff <= self.listening_duration: packet_hash = rf_data.get('packet_hash') # CRITICAL: Only process if hash matches exactly and is not None/empty if packet_hash and packet_hash == self.target_packet_hash: matching_count += 1 # Extract path from this RF data path = self.extract_path_from_rf_data(rf_data) if path: self.collected_paths.add(path) self.logger.info(f"✓ Collected path from RF scan: {path} (hash: {packet_hash[:8]}..., time: {time_diff:.2f}s)") else: self.logger.debug(f"Matched hash {packet_hash[:8]}... in RF scan but couldn't extract path") elif packet_hash: mismatching_count += 1 # Only log first few mismatches to avoid spam if mismatching_count <= 3: self.logger.debug(f"✗ RF scan hash mismatch - target: {self.target_packet_hash[:8]}..., found: {packet_hash[:8]}... (time: {time_diff:.2f}s)") if matching_count > 0 or mismatching_count > 0: self.logger.debug(f"RF scan complete: {matching_count} matching, {mismatching_count} mismatching packets") except Exception as e: self.logger.debug(f"Error scanning recent RF data: {e}") async def execute(self, message: MeshMessage) -> bool: """Execute the multitest command""" # Determine listening duration based on command variant content = message.content.strip() if content.startswith('!'): content = content[1:].strip() content_lower = content.lower() # Check for variants: "mt long", "mt xlong", "multitest long", "multitest xlong" if content_lower.startswith('mt ') or content_lower.startswith('multitest '): parts = content_lower.split() if len(parts) >= 2 and parts[0] in ['mt', 'multitest']: variant = parts[1] if variant == 'long': self.listening_duration = 10.0 self.logger.info("Multitest command (long) executed - starting 10 second listening window") elif variant == 'xlong': self.listening_duration = 14.0 self.logger.info("Multitest command (xlong) executed - starting 14 second listening window") else: self.listening_duration = 6.0 self.logger.info("Multitest command executed - starting 6 second listening window") else: self.listening_duration = 6.0 self.logger.info("Multitest command executed - starting 6 second listening window") else: self.listening_duration = 6.0 self.logger.info("Multitest command executed - starting 6 second listening window") # Get RF data for the triggering message (contains pre-calculated packet hash) rf_data = self.get_rf_data_for_message(message) if not rf_data: response = "Error: Could not find packet data for this message. Please try again." await self.send_response(message, response) return True # Use pre-calculated packet hash if available, otherwise calculate it packet_hash = rf_data.get('packet_hash') if not packet_hash and rf_data.get('raw_hex'): # Fallback: calculate hash if not stored (for older RF data) # IMPORTANT: Must use same payload_type that was used during ingestion payload_type = None routing_info = rf_data.get('routing_info', {}) if routing_info: payload_type = routing_info.get('payload_type') packet_hash = calculate_packet_hash(rf_data['raw_hex'], payload_type) if not packet_hash: response = "Error: Could not calculate packet hash for this message. Please try again." await self.send_response(message, response) return True # Store the packet hash to track self.target_packet_hash = packet_hash # Store the timestamp of the triggering message to avoid collecting older packets triggering_rf_timestamp = rf_data.get('timestamp', time.time()) self.triggering_timestamp = triggering_rf_timestamp self.logger.info(f"Tracking packet hash: {self.target_packet_hash[:16]}... (full: {self.target_packet_hash})") self.logger.debug(f"Triggering message timestamp: {triggering_rf_timestamp}") # Also extract path from the triggering message itself initial_path = self.extract_path_from_message(message) # Also try to extract from RF data (more reliable) if not initial_path and rf_data: initial_path = self.extract_path_from_rf_data(rf_data) if initial_path: self.logger.debug(f"Initial path from triggering message: {initial_path}") # Register this command instance as the active listener # Store reference in message handler so it can call on_message_received self.bot.message_handler.multitest_listener = self # Start listening self.listening = True self.collected_paths = set() if initial_path: self.collected_paths.add(initial_path) # Include the initial path self.listening_start_time = time.time() # Also scan recent RF data for matching hashes (in case messages haven't been processed yet) # But only include packets that arrived at or after the triggering message self._scan_recent_rf_data() try: # Wait for the listening duration await asyncio.sleep(self.listening_duration) finally: # Stop listening and unregister (but keep target_packet_hash for error messages) self.listening = False self.bot.message_handler.multitest_listener = None # Do a final scan of RF data in case any matching packets arrived self._scan_recent_rf_data() # Store hash for error message before clearing it tracking_hash = self.target_packet_hash # Format the collected paths if self.collected_paths: # Sort paths for consistent output sorted_paths = sorted(self.collected_paths) paths_text = "\n".join(sorted_paths) path_count = len(sorted_paths) # Use configured format if available, otherwise use default if self.response_format: try: response = self.response_format.format( sender=message.sender_id or "Unknown", path_count=path_count, paths=paths_text, listening_duration=int(self.listening_duration) ) except (KeyError, ValueError) as e: # If formatting fails, fall back to default self.logger.debug(f"Error formatting multitest response: {e}, using default format") response = f"Found {path_count} unique path(s):\n{paths_text}" else: # Default format response = f"Found {path_count} unique path(s):\n{paths_text}" else: # Provide more helpful error message with diagnostic info matching_packets = 0 if self.bot.message_handler.recent_rf_data and tracking_hash: for rf_data in self.bot.message_handler.recent_rf_data: if rf_data.get('packet_hash') == tracking_hash: matching_packets += 1 if tracking_hash is None: response = ("Error: Could not determine packet hash for tracking. " "The triggering message may not have valid packet data.") elif matching_packets > 0: response = (f"No paths extracted from {matching_packets} matching packet(s) " f"(hash: {tracking_hash}). " f"Packets may be direct (0 hops) or path extraction failed.") else: response = (f"No matching packets found during {self.listening_duration}s window. " f"Tracking hash: {tracking_hash}. ") # Clear the hash after we're done with it self.target_packet_hash = None # Wait for bot TX rate limiter cooldown to expire before sending # This ensures we respond even if another command put the bot on cooldown await self.bot.bot_tx_rate_limiter.wait_for_tx() # Also wait for user rate limiter if needed if not self.bot.rate_limiter.can_send(): wait_time = self.bot.rate_limiter.time_until_next() if wait_time > 0: self.logger.info(f"Waiting {wait_time:.1f} seconds for rate limiter") await asyncio.sleep(wait_time + 0.1) # Small buffer # Send the response await self.send_response(message, response) return True