Initial commit — Performance West telecom compliance platform
Includes: API (Express/TypeScript), Astro site, Python workers, document generators, FCC compliance tools, Canada CRTC formation, Ansible infrastructure, and deployment scripts. Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
This commit is contained in:
justin
commit
f8cd37ac8c
1823 changed files with 145167 additions and 0 deletions
563
scripts/formation/formation_worker.py
Normal file
563
scripts/formation/formation_worker.py
Normal file
|
|
@ -0,0 +1,563 @@
|
|||
"""
|
||||
formation_worker.py — Order queue processor for business formation filings.
|
||||
|
||||
Polls the PostgreSQL `formation_orders` table for new orders and processes them
|
||||
through the appropriate state adapter. Designed to run as a long-lived daemon
|
||||
with single-instance locking.
|
||||
|
||||
Features:
|
||||
- Polls for orders with status='received' every 60 seconds
|
||||
- Configurable human-paced delays between orders
|
||||
- Single-instance locking via fcntl.flock
|
||||
- Structured logging to ~/logs/formation-worker.log
|
||||
- ERPNext Issue creation on errors
|
||||
|
||||
Environment variables:
|
||||
DATABASE_URL PostgreSQL connection string
|
||||
FORMATION_DELAY_MIN Minimum delay between orders in minutes (default: 30)
|
||||
FORMATION_DELAY_MAX Maximum delay between orders in minutes (default: 120)
|
||||
|
||||
Usage:
|
||||
python -m formation.formation_worker
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import asyncio
|
||||
import fcntl
|
||||
import json
|
||||
import logging
|
||||
import os
|
||||
import random
|
||||
import signal
|
||||
import sys
|
||||
import time
|
||||
import traceback
|
||||
from datetime import datetime, timezone
|
||||
from pathlib import Path
|
||||
|
||||
import psycopg2
|
||||
import psycopg2.extras
|
||||
|
||||
from .base import (
|
||||
EntityType,
|
||||
FilingResult,
|
||||
FilingStatus,
|
||||
FormationOrder,
|
||||
Member,
|
||||
NameSearchResult,
|
||||
)
|
||||
from .states import get_adapter, STATES
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Configuration
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
DATABASE_URL = os.environ.get("DATABASE_URL", "")
|
||||
POLL_INTERVAL_SECONDS = 60
|
||||
DELAY_MIN_MINUTES = int(os.environ.get("FORMATION_DELAY_MIN", "30"))
|
||||
DELAY_MAX_MINUTES = int(os.environ.get("FORMATION_DELAY_MAX", "120"))
|
||||
LOCK_FILE = "/tmp/formation-worker.lock"
|
||||
LOG_DIR = Path.home() / "logs"
|
||||
LOG_FILE = LOG_DIR / "formation-worker.log"
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Logging
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
LOG_DIR.mkdir(parents=True, exist_ok=True)
|
||||
|
||||
LOG = logging.getLogger("formation.worker")
|
||||
|
||||
_file_handler = logging.FileHandler(str(LOG_FILE))
|
||||
_file_handler.setFormatter(
|
||||
logging.Formatter("%(asctime)s [%(name)s] %(levelname)s %(message)s")
|
||||
)
|
||||
_stream_handler = logging.StreamHandler(sys.stdout)
|
||||
_stream_handler.setFormatter(
|
||||
logging.Formatter("%(asctime)s [%(name)s] %(levelname)s %(message)s")
|
||||
)
|
||||
|
||||
LOG.addHandler(_file_handler)
|
||||
LOG.addHandler(_stream_handler)
|
||||
LOG.setLevel(logging.INFO)
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Alerting (ERPNext Issues)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _alert_error(order_id: str, state_code: str, error: str, detail: str = ""):
|
||||
"""Create an ERPNext Issue for a formation processing error."""
|
||||
try:
|
||||
# Import the shared alert module (one level up)
|
||||
sys.path.insert(0, str(Path(__file__).resolve().parent.parent))
|
||||
from alert import alert_account_broken
|
||||
|
||||
alert_account_broken(
|
||||
monitor="formation-worker",
|
||||
platform=f"SOS-{state_code}",
|
||||
error=f"Formation order {order_id} failed: {error}",
|
||||
detail=detail,
|
||||
)
|
||||
except Exception as exc:
|
||||
LOG.warning("Failed to send alert for order %s: %s", order_id, exc)
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Database helpers
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _get_connection():
|
||||
"""Open a PostgreSQL connection from DATABASE_URL."""
|
||||
if not DATABASE_URL:
|
||||
raise RuntimeError(
|
||||
"DATABASE_URL environment variable is not set. "
|
||||
"Expected format: postgresql://user:pass@host:5432/dbname"
|
||||
)
|
||||
return psycopg2.connect(DATABASE_URL)
|
||||
|
||||
|
||||
def _fetch_pending_orders(conn) -> list[dict]:
|
||||
"""Fetch all orders with status='received', oldest first."""
|
||||
with conn.cursor(cursor_factory=psycopg2.extras.RealDictCursor) as cur:
|
||||
cur.execute(
|
||||
"""
|
||||
SELECT *
|
||||
FROM formation_orders
|
||||
WHERE status = 'received'
|
||||
ORDER BY created_at ASC
|
||||
LIMIT 10
|
||||
"""
|
||||
)
|
||||
return [dict(row) for row in cur.fetchall()]
|
||||
|
||||
|
||||
def _update_order_status(
|
||||
conn,
|
||||
order_id: str,
|
||||
status: str,
|
||||
*,
|
||||
filing_number: str = "",
|
||||
confirmation_number: str = "",
|
||||
error_message: str = "",
|
||||
screenshots: list[str] | None = None,
|
||||
documents: list[str] | None = None,
|
||||
ein: str = "",
|
||||
):
|
||||
"""Update an order's status and related fields."""
|
||||
fields = ["status = %s", "updated_at = NOW()"]
|
||||
values: list = [status]
|
||||
|
||||
if filing_number:
|
||||
fields.append("filing_number = %s")
|
||||
values.append(filing_number)
|
||||
if confirmation_number:
|
||||
fields.append("confirmation_number = %s")
|
||||
values.append(confirmation_number)
|
||||
if error_message:
|
||||
fields.append("error_message = %s")
|
||||
values.append(error_message)
|
||||
if screenshots is not None:
|
||||
fields.append("screenshots = %s")
|
||||
values.append(json.dumps(screenshots))
|
||||
if documents is not None:
|
||||
fields.append("documents = %s")
|
||||
values.append(json.dumps(documents))
|
||||
if ein:
|
||||
fields.append("ein = %s")
|
||||
values.append(ein)
|
||||
if status == "filed":
|
||||
fields.append("filed_at = NOW()")
|
||||
|
||||
values.append(order_id)
|
||||
|
||||
with conn.cursor() as cur:
|
||||
cur.execute(
|
||||
f"UPDATE formation_orders SET {', '.join(fields)} WHERE order_id = %s",
|
||||
values,
|
||||
)
|
||||
conn.commit()
|
||||
|
||||
|
||||
def _update_automation_status(conn, order_id: str, auto_status: str, *, error: str | None = None):
|
||||
"""Update the automation_status and related fields."""
|
||||
fields = ["automation_status = %s", "last_activity_at = NOW()"]
|
||||
values: list = [auto_status]
|
||||
if error:
|
||||
fields.append("automation_error = %s")
|
||||
values.append(error)
|
||||
values.append(order_id)
|
||||
with conn.cursor() as cur:
|
||||
cur.execute(
|
||||
f"UPDATE formation_orders SET {', '.join(fields)} WHERE id = %s",
|
||||
values,
|
||||
)
|
||||
conn.commit()
|
||||
|
||||
|
||||
def _increment_attempts(conn, order_id: str):
|
||||
"""Increment the automation_attempts counter."""
|
||||
with conn.cursor() as cur:
|
||||
cur.execute(
|
||||
"UPDATE formation_orders SET automation_attempts = automation_attempts + 1 WHERE id = %s",
|
||||
[order_id],
|
||||
)
|
||||
conn.commit()
|
||||
|
||||
|
||||
def _write_audit(
|
||||
conn,
|
||||
order_id,
|
||||
order_number: str,
|
||||
action: str,
|
||||
from_status: str = "",
|
||||
to_status: str = "",
|
||||
actor_type: str = "worker",
|
||||
*,
|
||||
note: str = "",
|
||||
metadata: dict | None = None,
|
||||
):
|
||||
"""Write an entry to the order_audit_log table."""
|
||||
with conn.cursor() as cur:
|
||||
cur.execute(
|
||||
"""INSERT INTO order_audit_log
|
||||
(order_type, order_id, order_number, action, from_status, to_status,
|
||||
actor_type, actor_name, note, metadata)
|
||||
VALUES ('formation', %s, %s, %s, %s, %s, %s, 'formation_worker', %s, %s)""",
|
||||
[order_id, order_number, action, from_status or None, to_status or None,
|
||||
actor_type, note or None, json.dumps(metadata) if metadata else None],
|
||||
)
|
||||
conn.commit()
|
||||
|
||||
|
||||
def _row_to_order(row: dict) -> FormationOrder:
|
||||
"""Convert a database row dict to a FormationOrder dataclass."""
|
||||
members_raw = row.get("members")
|
||||
if isinstance(members_raw, str):
|
||||
members_raw = json.loads(members_raw)
|
||||
elif members_raw is None:
|
||||
members_raw = []
|
||||
|
||||
members = []
|
||||
for m in members_raw:
|
||||
members.append(
|
||||
Member(
|
||||
name=m.get("name", ""),
|
||||
address=m.get("address", ""),
|
||||
city=m.get("city", ""),
|
||||
state=m.get("state", ""),
|
||||
zip_code=m.get("zip_code", ""),
|
||||
title=m.get("title", "Member"),
|
||||
ownership_pct=float(m.get("ownership_pct", 0)),
|
||||
is_organizer=bool(m.get("is_organizer", False)),
|
||||
)
|
||||
)
|
||||
|
||||
entity_type_raw = row.get("entity_type", "llc")
|
||||
try:
|
||||
entity_type = EntityType(entity_type_raw)
|
||||
except ValueError:
|
||||
entity_type = EntityType.LLC
|
||||
|
||||
return FormationOrder(
|
||||
order_id=str(row["order_id"]),
|
||||
state_code=row.get("state_code", ""),
|
||||
entity_type=entity_type,
|
||||
entity_name=row.get("entity_name", ""),
|
||||
entity_name_alt=row.get("entity_name_alt", ""),
|
||||
management_type=row.get("management_type", "member_managed"),
|
||||
purpose=row.get("purpose", "Any lawful business activity"),
|
||||
members=members,
|
||||
registered_agent_name=row.get("registered_agent_name", "Northwest Registered Agent"),
|
||||
registered_agent_address=row.get("registered_agent_address", ""),
|
||||
principal_address=row.get("principal_address", ""),
|
||||
principal_city=row.get("principal_city", ""),
|
||||
principal_state=row.get("principal_state", ""),
|
||||
principal_zip=row.get("principal_zip", ""),
|
||||
mailing_address=row.get("mailing_address", ""),
|
||||
mailing_city=row.get("mailing_city", ""),
|
||||
mailing_state=row.get("mailing_state", ""),
|
||||
mailing_zip=row.get("mailing_zip", ""),
|
||||
shares_authorized=int(row.get("shares_authorized", 1500)),
|
||||
par_value=float(row.get("par_value", 0.0)),
|
||||
fiscal_year_end=row.get("fiscal_year_end", "12/31"),
|
||||
expedited=bool(row.get("expedited", False)),
|
||||
effective_date=row.get("effective_date", "") or "",
|
||||
)
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Core processing
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
async def process_order(order: FormationOrder, conn) -> FilingResult:
|
||||
"""
|
||||
Process a single formation order:
|
||||
1. Verify name availability
|
||||
2. File the entity
|
||||
3. Return the result
|
||||
"""
|
||||
state_code = order.state_code.upper()
|
||||
LOG.info(
|
||||
"Processing order %s: %s in %s (%s)",
|
||||
order.order_id,
|
||||
order.entity_name,
|
||||
state_code,
|
||||
order.entity_type.value,
|
||||
)
|
||||
|
||||
adapter = get_adapter(state_code)
|
||||
|
||||
try:
|
||||
await adapter.start_browser(headless=True)
|
||||
|
||||
# Step 1: Verify name availability
|
||||
LOG.info("[%s] Searching name: %s", order.order_id, order.entity_name)
|
||||
name_result: NameSearchResult = await adapter.search_name(order.entity_name)
|
||||
|
||||
if not name_result.available:
|
||||
# Try alternate name if provided
|
||||
if order.entity_name_alt:
|
||||
LOG.info(
|
||||
"[%s] Primary name unavailable, trying alternate: %s",
|
||||
order.order_id,
|
||||
order.entity_name_alt,
|
||||
)
|
||||
name_result = await adapter.search_name(order.entity_name_alt)
|
||||
if name_result.available:
|
||||
order.entity_name = order.entity_name_alt
|
||||
else:
|
||||
return FilingResult(
|
||||
success=False,
|
||||
status=FilingStatus.NAME_UNAVAILABLE,
|
||||
state_code=state_code,
|
||||
entity_name=order.entity_name,
|
||||
error_message=(
|
||||
f"Both names unavailable: '{order.entity_name}' "
|
||||
f"and '{order.entity_name_alt}'"
|
||||
),
|
||||
screenshot_path=await adapter.screenshot("name_unavailable"),
|
||||
)
|
||||
else:
|
||||
return FilingResult(
|
||||
success=False,
|
||||
status=FilingStatus.NAME_UNAVAILABLE,
|
||||
state_code=state_code,
|
||||
entity_name=order.entity_name,
|
||||
error_message=f"Name unavailable: '{order.entity_name}'",
|
||||
screenshot_path=await adapter.screenshot("name_unavailable"),
|
||||
)
|
||||
|
||||
LOG.info("[%s] Name available: %s", order.order_id, order.entity_name)
|
||||
|
||||
# Step 2: File the entity
|
||||
LOG.info("[%s] Filing entity...", order.order_id)
|
||||
result: FilingResult = await adapter.file_entity(order)
|
||||
LOG.info(
|
||||
"[%s] Filing result: %s (filing_number=%s, confirmation=%s)",
|
||||
order.order_id,
|
||||
result.status.value,
|
||||
result.filing_number,
|
||||
result.confirmation_number,
|
||||
)
|
||||
return result
|
||||
|
||||
except Exception as exc:
|
||||
LOG.error(
|
||||
"[%s] Unhandled error processing order: %s",
|
||||
order.order_id,
|
||||
exc,
|
||||
exc_info=True,
|
||||
)
|
||||
screenshot = ""
|
||||
try:
|
||||
screenshot = await adapter.screenshot("error")
|
||||
except Exception:
|
||||
pass
|
||||
return FilingResult(
|
||||
success=False,
|
||||
status=FilingStatus.ERROR,
|
||||
state_code=state_code,
|
||||
entity_name=order.entity_name,
|
||||
error_message=str(exc),
|
||||
screenshot_path=screenshot,
|
||||
)
|
||||
finally:
|
||||
await adapter.close_browser()
|
||||
|
||||
|
||||
async def poll_and_process():
|
||||
"""Single poll iteration: fetch pending orders and process them."""
|
||||
conn = _get_connection()
|
||||
try:
|
||||
orders = _fetch_pending_orders(conn)
|
||||
if not orders:
|
||||
return
|
||||
|
||||
LOG.info("Found %d pending order(s)", len(orders))
|
||||
|
||||
for i, row in enumerate(orders):
|
||||
order = _row_to_order(row)
|
||||
|
||||
# Mark as processing + set automation_status to running
|
||||
_update_order_status(conn, order.order_id, "processing")
|
||||
_update_automation_status(conn, order.order_id, "running")
|
||||
_write_audit(conn, order.order_id, row.get("order_number", ""),
|
||||
"status_change", "received", "processing",
|
||||
"worker", note="Automation started")
|
||||
|
||||
# Process the order
|
||||
result = await process_order(order, conn)
|
||||
|
||||
# Map result to DB status
|
||||
if result.status == FilingStatus.FILED:
|
||||
db_status = "filed"
|
||||
auto_status = "succeeded"
|
||||
elif result.status == FilingStatus.SUBMITTED:
|
||||
db_status = "submitted"
|
||||
auto_status = "running"
|
||||
elif result.status == FilingStatus.NAME_UNAVAILABLE:
|
||||
db_status = "received" # Keep in queue for admin review
|
||||
auto_status = "failed"
|
||||
else:
|
||||
db_status = "received" # Keep in queue for manual intervention
|
||||
auto_status = "failed"
|
||||
|
||||
# Update the order
|
||||
screenshots = [result.screenshot_path] if result.screenshot_path else []
|
||||
_update_order_status(
|
||||
conn,
|
||||
order.order_id,
|
||||
db_status,
|
||||
filing_number=result.filing_number,
|
||||
confirmation_number=result.confirmation_number,
|
||||
error_message=result.error_message,
|
||||
screenshots=screenshots,
|
||||
documents=result.documents,
|
||||
)
|
||||
_update_automation_status(
|
||||
conn, order.order_id, auto_status,
|
||||
error=result.error_message if auto_status == "failed" else None,
|
||||
)
|
||||
_write_audit(
|
||||
conn, order.order_id, row.get("order_number", ""),
|
||||
"automation_update" if auto_status != "succeeded" else "status_change",
|
||||
"processing", db_status, "worker",
|
||||
note=result.error_message if auto_status == "failed"
|
||||
else f"Filed: {result.filing_number}" if result.filing_number
|
||||
else f"Status: {db_status}",
|
||||
metadata={"filing_number": result.filing_number,
|
||||
"confirmation": result.confirmation_number,
|
||||
"screenshot": result.screenshot_path} if result.filing_number else None,
|
||||
)
|
||||
|
||||
if auto_status == "failed":
|
||||
# Increment attempt counter and alert
|
||||
_increment_attempts(conn, order.order_id)
|
||||
_alert_error(
|
||||
order.order_id,
|
||||
order.state_code,
|
||||
result.error_message,
|
||||
detail=f"Entity: {order.entity_name}\nState: {order.state_code}\n"
|
||||
f"Filing number: {result.filing_number}\n"
|
||||
f"Screenshot: {result.screenshot_path}\n"
|
||||
f"Status set to: {auto_status}\n"
|
||||
f"Order returned to queue for manual intervention.",
|
||||
)
|
||||
|
||||
# Human-paced delay between orders (skip after last order)
|
||||
if i < len(orders) - 1:
|
||||
delay_minutes = random.uniform(DELAY_MIN_MINUTES, DELAY_MAX_MINUTES)
|
||||
delay_seconds = delay_minutes * 60
|
||||
LOG.info(
|
||||
"Waiting %.1f minutes before next order (human-paced delay)...",
|
||||
delay_minutes,
|
||||
)
|
||||
await asyncio.sleep(delay_seconds)
|
||||
|
||||
finally:
|
||||
conn.close()
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Main loop with single-instance locking
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
_shutdown = False
|
||||
|
||||
|
||||
def _handle_signal(signum, frame):
|
||||
global _shutdown
|
||||
LOG.info("Received signal %d, shutting down gracefully...", signum)
|
||||
_shutdown = True
|
||||
|
||||
|
||||
async def run_worker():
|
||||
"""Main worker loop: poll for orders, process them, sleep, repeat."""
|
||||
LOG.info("=" * 60)
|
||||
LOG.info("Formation worker starting")
|
||||
LOG.info(" Poll interval: %ds", POLL_INTERVAL_SECONDS)
|
||||
LOG.info(" Delay range: %d–%d minutes", DELAY_MIN_MINUTES, DELAY_MAX_MINUTES)
|
||||
LOG.info(" Log file: %s", LOG_FILE)
|
||||
LOG.info("=" * 60)
|
||||
|
||||
while not _shutdown:
|
||||
try:
|
||||
await poll_and_process()
|
||||
except Exception as exc:
|
||||
LOG.error("Poll cycle failed: %s", exc, exc_info=True)
|
||||
_alert_error("N/A", "N/A", f"Poll cycle failed: {exc}", traceback.format_exc())
|
||||
|
||||
# Sleep in short increments so we can respond to shutdown signals
|
||||
for _ in range(POLL_INTERVAL_SECONDS):
|
||||
if _shutdown:
|
||||
break
|
||||
await asyncio.sleep(1)
|
||||
|
||||
LOG.info("Formation worker stopped.")
|
||||
|
||||
|
||||
def main():
|
||||
"""Entry point with single-instance locking."""
|
||||
if not DATABASE_URL:
|
||||
print(
|
||||
"Error: DATABASE_URL environment variable is not set.",
|
||||
file=sys.stderr,
|
||||
)
|
||||
sys.exit(1)
|
||||
|
||||
# Acquire single-instance lock
|
||||
lock_fd = open(LOCK_FILE, "w")
|
||||
try:
|
||||
fcntl.flock(lock_fd, fcntl.LOCK_EX | fcntl.LOCK_NB)
|
||||
except BlockingIOError:
|
||||
print(
|
||||
"Error: Another formation worker is already running (lock held).",
|
||||
file=sys.stderr,
|
||||
)
|
||||
sys.exit(1)
|
||||
|
||||
# Write PID to lock file
|
||||
lock_fd.write(str(os.getpid()))
|
||||
lock_fd.flush()
|
||||
|
||||
# Register signal handlers
|
||||
signal.signal(signal.SIGINT, _handle_signal)
|
||||
signal.signal(signal.SIGTERM, _handle_signal)
|
||||
|
||||
try:
|
||||
asyncio.run(run_worker())
|
||||
finally:
|
||||
fcntl.flock(lock_fd, fcntl.LOCK_UN)
|
||||
lock_fd.close()
|
||||
try:
|
||||
os.unlink(LOCK_FILE)
|
||||
except OSError:
|
||||
pass
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
main()
|
||||
Loading…
Add table
Add a link
Reference in a new issue