"""ZeroTier reconciliation service — polling loop to sync state with the controller.""" import logging import time from datetime import datetime, timezone from gatehouse_app.extensions import db from gatehouse_app.models import ( Device, NetworkAccessRequest, ActivationSession, ZeroTierMembership, PortalNetwork, ) from gatehouse_app.services import zerotier_api_service as zt from gatehouse_app.utils.constants import ( ActivationEndReason, ApprovalState, AuditAction, ) logger = logging.getLogger(__name__) def reconcile_expired_activations() -> int: """Find expired activation sessions and deactivate their memberships. Returns the number of sessions expired. """ now = datetime.now(timezone.utc) expired = ActivationSession.query.filter( ActivationSession.expires_at < now, ActivationSession.ended_at.is_(None), ActivationSession.deleted_at.is_(None), ).all() logger.debug(f"[Reconciliation] Expiry check: {len(expired)} overdue session(s) found.") count = 0 for session in expired: try: _expire_session(session) count += 1 except Exception as exc: logger.error( f"[Reconciliation] Failed to expire session {session.id} " f"(user={session.user_id} request={session.network_access_request_id}): {exc}", exc_info=True, ) if count > 0: logger.info(f"[Reconciliation] Expired {count} activation session(s).") else: logger.debug("[Reconciliation] No activation sessions to expire.") return count def reconcile_network(portal_network_id: str) -> dict: """Full reconciliation for one portal network. Returns a dict with counts of actions taken. """ network = PortalNetwork.query.get(portal_network_id) if not network or not network.is_active: logger.debug( f"[Reconciliation] Skipping portal_network_id={portal_network_id}: " f"{'not found' if not network else 'inactive or deleted'}." ) return {"skipped": True, "reason": "network_inactive_or_deleted"} zerotier_network_id = network.zerotier_network_id network_label = f"{network.name} ({zerotier_network_id})" actions = { "zt_members_checked": 0, "zt_members_added": 0, "authorized": 0, "deauthorized": 0, "join_seen_updated": 0, "unknown_members": [], } t_start = time.monotonic() logger.debug(f"[Reconciliation] Starting network reconciliation for {network_label}.") # Get current ZT members try: zt_members = {m.node_id: m for m in zt.list_members(zerotier_network_id, organization_id=network.organization_id)} except Exception as exc: logger.error( f"[Reconciliation] Failed to list ZT members for {network_label}: {exc}", exc_info=True, ) actions["error"] = str(exc) return actions actions["zt_members_checked"] = len(zt_members) logger.debug( f"[Reconciliation] {network_label}: {len(zt_members)} member(s) fetched from ZT controller." ) # Get our portal memberships for this network our_memberships = { m.device.node_id: m for m in NetworkAccessRequest.query.filter( NetworkAccessRequest.portal_network_id == portal_network_id, NetworkAccessRequest.deleted_at.is_(None), ).all() if m.device and m.device.deleted_at is None } logger.debug( f"[Reconciliation] {network_label}: {len(our_memberships)} portal membership(s) to reconcile." ) # Reconcile each portal membership for node_id, membership in our_memberships.items(): zt_member = zt_members.pop(node_id, None) device = membership.device if not zt_member: # Member not seen in ZT yet — could be freshly joined or never connected logger.debug( f"[Reconciliation] {network_label}: node {node_id} " f"(device={device.display_name!r}, active={membership.active}) not yet seen in ZT controller." ) continue actions["join_seen_updated"] += 1 # Update observed ZT membership _sync_zt_membership(membership, zt_member) # Sync authorization state if membership.active: if not zt_member.is_authorized: # Portal says active but ZT disagrees — drift, re-authorize logger.warning( f"[Reconciliation] {network_label}: DRIFT detected — portal=active " f"but ZT says unauthorized for node {node_id} (device={device.display_name!r}). Re-authorizing." ) try: zt.authorize_member(zerotier_network_id, node_id, organization_id=network.organization_id) actions["authorized"] += 1 logger.info( f"[Reconciliation] {network_label}: Re-authorized node {node_id} (device={device.display_name!r})." ) except Exception as exc: logger.warning( f"[Reconciliation] {network_label}: Re-authorize failed for node {node_id}: {exc}" ) else: logger.debug( f"[Reconciliation] {network_label}: node {node_id} — portal=active, ZT=authorized. OK." ) else: if zt_member.is_authorized: # ZT says authorized but portal doesn't — could be manual override in ZT console logger.warning( f"[Reconciliation] {network_label}: DRIFT detected — portal=inactive " f"but ZT says authorized for node {node_id} (device={device.display_name!r}). Deauthorizing." ) try: zt.deauthorize_member(zerotier_network_id, node_id, organization_id=network.organization_id) actions["deauthorized"] += 1 logger.info( f"[Reconciliation] {network_label}: Deauthorized node {node_id} (device={device.display_name!r})." ) except Exception as exc: logger.warning( f"[Reconciliation] {network_label}: Deauthorize failed for node {node_id}: {exc}" ) else: logger.debug( f"[Reconciliation] {network_label}: node {node_id} — " f"portal=inactive, ZT=unauthorized. OK." ) # Unknown ZT members not in our portal — log only, do not touch unknown = list(zt_members.keys()) actions["unknown_members"] = unknown if unknown: logger.warning( f"[Reconciliation] {network_label}: {len(unknown)} ZT member(s) not in portal — " f"node IDs: {', '.join(unknown)}" ) elapsed_ms = int((time.monotonic() - t_start) * 1000) logger.info( f"[Reconciliation] Network {network_label}: " f"checked={actions['zt_members_checked']} " f"authorized={actions['authorized']} " f"deauthorized={actions['deauthorized']} " f"unknown={len(actions['unknown_members'])} " f"elapsed={elapsed_ms}ms" ) return actions def reconcile_all() -> dict: """Run reconciliation on all active portal networks. Returns a summary dict. """ networks = PortalNetwork.query.filter( PortalNetwork.is_active.is_(True), PortalNetwork.deleted_at.is_(None), ).all() logger.info(f"[Reconciliation] reconcile_all: {len(networks)} active network(s) to process.") results = {"networks_processed": 0, "errors": 0, "authorized": 0, "deauthorized": 0, "unknown_members": []} for network in networks: try: result = reconcile_network(network.id) if "error" in result: logger.error( f"[Reconciliation] Network {network.name} ({network.zerotier_network_id}) " f"failed: {result['error']}" ) results["errors"] += 1 elif result.get("skipped"): logger.debug( f"[Reconciliation] Network {network.name} ({network.zerotier_network_id}) " f"skipped: {result.get('reason')}" ) else: results["networks_processed"] += 1 results["authorized"] += result.get("authorized", 0) results["deauthorized"] += result.get("deauthorized", 0) results["unknown_members"].extend(result.get("unknown_members", [])) except Exception as exc: logger.error( f"[Reconciliation] Unhandled error reconciling network " f"{network.name} ({network.id}): {exc}", exc_info=True, ) results["errors"] += 1 deleted_result = reconcile_deleted_memberships() results["deleted_memberships"] = deleted_result.get("deleted", 0) results["delete_errors"] = deleted_result.get("errors", 0) logger.info( f"[Reconciliation] Complete: " f"networks={results['networks_processed']} " f"errors={results['errors']} " f"purged={results.get('deleted_memberships', 0)} " f"purge_errors={results.get('delete_errors', 0)}" ) return results def reconcile_deleted_memberships() -> dict: """Find soft-deleted memberships and hard-delete them after ZeroTier cleanup. Only processes memberships whose ZeroTier members are already de-authorized (the de-authorize step happened in revoke_request_soft). This function removes the member from ZeroTier entirely and then hard-deletes the DB record. """ deleted = NetworkAccessRequest.query.filter( NetworkAccessRequest.deleted_at.isnot(None), ).all() if not deleted: logger.debug("[Reconciliation] No soft-deleted memberships to purge.") return {"deleted": 0, "errors": 0} logger.info(f"[Reconciliation] Purging {len(deleted)} soft-deleted membership(s) from ZT and DB.") results = {"deleted": 0, "errors": 0} for membership in deleted: try: device = Device.query.get(membership.device_id) network = PortalNetwork.query.get(membership.portal_network_id) if not device or not network: logger.warning( f"[Reconciliation] Membership {membership.id}: missing " f"{'device' if not device else 'network'} — soft-deleting record only." ) membership.delete(soft=True) db.session.commit() results["deleted"] += 1 continue node_id = device.node_id zt_network_id = network.zerotier_network_id network_label = f"{network.name} ({zt_network_id})" try: zt.delete_network_member(zt_network_id, node_id, organization_id=network.organization_id) logger.info( f"[Reconciliation] Removed node {node_id} (device={device.display_name!r}) " f"from ZT network {network_label}." ) except Exception as zt_exc: logger.warning( f"[Reconciliation] ZT delete failed for node {node_id} " f"on {network_label}: {zt_exc} — proceeding with DB soft-delete." ) membership.delete(soft=True) db.session.commit() results["deleted"] += 1 logger.debug( f"[Reconciliation] Soft-deleted membership {membership.id} " f"(node={node_id}, network={network_label})." ) except Exception as exc: logger.error( f"[Reconciliation] Failed to soft-delete membership {membership.id}: {exc}", exc_info=True, ) results["errors"] += 1 if results["deleted"] > 0: logger.info(f"[Reconciliation] Purged {results['deleted']} membership(s).") return results def _sync_zt_membership(membership: NetworkAccessRequest, zt_member) -> None: """Update the ZeroTierMembership cache record from a ZT API response.""" device = membership.device network = membership.portal_network zt_membership = ZeroTierMembership.query.filter( ZeroTierMembership.zerotier_network_id == network.zerotier_network_id, ZeroTierMembership.node_id == device.node_id, ZeroTierMembership.deleted_at.is_(None), ).first() is_new = zt_membership is None if is_new: logger.debug( f"[Reconciliation] Creating new ZeroTierMembership cache record for " f"node {device.node_id} on network {network.zerotier_network_id}." ) zt_membership = ZeroTierMembership( organization_id=membership.organization_id, network_access_request_id=membership.id, zerotier_network_id=network.zerotier_network_id, node_id=device.node_id, ) prev_authorized = zt_membership.authorized if not is_new else None zt_membership.member_seen = True zt_membership.authorized = zt_member.is_authorized zt_membership.last_synced_at = datetime.now(timezone.utc) zt_membership.raw_controller_payload = zt_member.raw if zt_member.last_seen and zt_member.last_seen > 0: zt_membership.join_seen_at = datetime.fromtimestamp( zt_member.last_seen / 1000, tz=timezone.utc ) zt_membership.save() if not is_new and prev_authorized != zt_member.is_authorized: logger.info( f"[Reconciliation] ZT auth state changed for node {device.node_id} " f"(device={device.display_name!r}): {prev_authorized} → {zt_member.is_authorized}" ) # Update membership join_seen flag if not membership.join_seen: logger.info( f"[Reconciliation] First join seen for node {device.node_id} " f"(device={device.display_name!r}, membership={membership.id}). " f"Setting join_seen=True, active=False" ) membership.join_seen = True membership.active = False membership.save() else: logger.debug( f"[Reconciliation] Synced ZT membership for node {device.node_id} " f"(device={device.display_name!r}, authorized={zt_member.is_authorized})." ) def _expire_session(session: ActivationSession) -> None: """Expire an activation session and deauthorize the membership in ZT.""" session.ended_at = datetime.now(timezone.utc) session.end_reason = ActivationEndReason.EXPIRED session.save() logger.info( f"[Reconciliation] Expiring activation session {session.id} " f"(user={session.user_id}, request={session.network_access_request_id}, " f"expired_at={session.expires_at.isoformat()})." ) request = NetworkAccessRequest.query.get(session.network_access_request_id) if not request: logger.warning( f"[Reconciliation] Session {session.id}: request " f"{session.network_access_request_id} not found — skipping ZT deauth." ) else: request.active = False request.save() device = Device.query.get(request.device_id) network = PortalNetwork.query.get(request.portal_network_id) if device and network: network_label = f"{network.name} ({network.zerotier_network_id})" try: zt.deauthorize_member(network.zerotier_network_id, device.node_id, organization_id=network.organization_id) logger.info( f"[Reconciliation] Deauthorized expired node {device.node_id} " f"(device={device.display_name!r}) on {network_label}." ) # Update ZT membership cache zt_membership = ZeroTierMembership.query.filter( ZeroTierMembership.zerotier_network_id == network.zerotier_network_id, ZeroTierMembership.node_id == device.node_id, ZeroTierMembership.deleted_at.is_(None), ).first() if zt_membership: zt_membership.authorized = False zt_membership.last_synced_at = datetime.now(timezone.utc) zt_membership.save() else: logger.debug( f"[Reconciliation] No ZeroTierMembership cache record found for " f"node {device.node_id} on {network_label} — nothing to update." ) except Exception as exc: logger.warning( f"[_expire_session] Failed to deauthorize node {device.node_id} " f"on {network_label}: {exc}", exc_info=True, ) else: logger.warning( f"[Reconciliation] Session {session.id}: missing " f"{'device' if not device else 'network'} for request " f"{request.id} — ZT deauth skipped." ) from gatehouse_app.services.audit_service import AuditService AuditService.log_action( action=AuditAction.ZT_ACTIVATION_EXPIRED, user_id=session.user_id, organization_id=session.organization_id, resource_type="activation_session", resource_id=session.id, metadata={"request_id": session.network_access_request_id}, description="Activation session expired", success=True, )