animation/tools/iclone_bridge/TinqsBridge/main.py

"""TinqsBridge -- iClone 8 auto-load plugin.

Runs a localhost-only TCP socket server inside iClone 8 and executes Python
source sent to it on iClone's Qt main thread. RLPy is NOT thread-safe: the
socket-accept thread and per-connection handler threads never touch RLPy or
any Qt object directly. They only move bytes on/off a queue.Queue. A QTimer
created on the main thread (inside initialize_plugin()) polls that queue and
does all RLPy/exec() work.

Wire protocol: newline-delimited JSON over TCP, one request/response pair per
TCP connection (the client opens a new connection per call).

    request:  {"id": <int>, "code": "<python source>"}
    success:  {"id": <int>, "ok": true,  "result": <json|null>, "stdout": "<str>"}
    failure:  {"id": <int>, "ok": false, "error": "<traceback str>", "stdout": "<str>"}

Execution semantics:
  - `exec(code, ns, ns)` against ONE persistent namespace dict (`_ns`), shared
    across every request for the life of the iClone session, and pre-seeded
    with `RLPy`. The same dict is passed as both globals and locals so nested
    functions/comprehensions in submitted code can see top-level names (the
    classic exec-scoping trap).
  - If the code sets a variable named `result`, that becomes the response
    `result` (JSON-encoded; if it isn't JSON-serializable we fall back to
    `repr()`). `ns["result"]` is cleared to None before every exec so a stale
    value from a previous request can never leak into a response that didn't
    set one.
  - stdout/stderr during exec are captured and returned as `stdout`.
  - Any exception during exec is caught; the response is `ok: false` with
    `traceback.format_exc()`, and the bridge keeps serving further requests.

Source of truth for this file lives in the repo at
tools/iclone_bridge/TinqsBridge/main.py. tools/install_iclone_bridge.ps1
copies this folder into iClone's OpenPlugin directory. iClone must be
restarted to pick up changes to this file (there is no live-reload of
main.py itself -- but you CAN hot-swap behavior at runtime by exec-ing new
code through the bridge once it's up).

Written for iClone 8's embedded Python. Bin64 ships both python38.dll and
python310.dll and it is not obvious ahead of time which one hosts plugins,
so this file is kept 3.8-compatible on purpose: no `match` statement, no
`X | Y` union type syntax, no walrus-heavy or 3.9+-only stdlib usage. The
--ping command reports the real embedded `sys.version` back to the client so
this can be verified after the plugin loads.

See docs/iclone-bridge.md for the client-side usage, and the threading rule
above for anyone extending this file: new RLPy calls MUST happen inside
_execute()/_drain_queue() (i.e. on the QTimer callback / main thread), never
inside _handle_conn() or _accept_loop() (the socket threads).
"""

import contextlib
import io
import json
import os
import queue
import socket
import threading
import traceback
from datetime import datetime

import RLPy

try:
    from PySide2.QtCore import QTimer
except Exception:
    QTimer = None  # reported to the log in initialize_plugin() if this happens


DEFAULT_PORT = 18800
HOST = "127.0.0.1"
POLL_MS = 50
ACCEPT_POLL_TIMEOUT_S = 1.0
CONN_READ_TIMEOUT_S = 30.0

LOG_PATH = os.path.join(
    os.environ.get("TEMP", os.environ.get("TMP", ".")),
    "tinqs_iclone_bridge.log",
)

# Persistent namespace shared across every request for the life of the iClone
# session. Passed as BOTH globals and locals to exec() -- see module docstring.
_ns = {"RLPy": RLPy}

_request_queue = queue.Queue()
_server_socket = None
_accept_thread = None
_timer = None
_stop_event = threading.Event()
_stats = {"served": 0, "port": None}


def _log(msg):
    """Append a timestamped line to the log file. Must never raise."""
    try:
        line = "[{}] {}\n".format(datetime.now().strftime("%Y-%m-%d %H:%M:%S"), msg)
        with open(LOG_PATH, "a", encoding="utf-8") as f:
            f.write(line)
    except Exception:
        pass


def _get_port():
    raw = os.environ.get("TINQS_ICLONE_BRIDGE_PORT")
    if raw:
        try:
            return int(raw)
        except ValueError:
            _log("WARN: TINQS_ICLONE_BRIDGE_PORT={!r} is not an int, using default {}".format(
                raw, DEFAULT_PORT))
    return DEFAULT_PORT


def _execute(code):
    """RLPy-touching work. Only ever called from _drain_queue() on the Qt main thread."""
    _ns["result"] = None
    out = io.StringIO()
    try:
        with contextlib.redirect_stdout(out), contextlib.redirect_stderr(out):
            exec(code, _ns, _ns)
        result = _ns.get("result")
        try:
            json.dumps(result)
        except TypeError:
            result = repr(result)
        return {"ok": True, "result": result, "stdout": out.getvalue()}
    except Exception:
        return {"ok": False, "error": traceback.format_exc(), "stdout": out.getvalue()}


def _drain_queue():
    """QTimer callback -- runs on the Qt main thread. Safe to call RLPy here."""
    while True:
        try:
            job = _request_queue.get_nowait()
        except queue.Empty:
            return
        req_id = job.get("id")
        resp = _execute(job.get("code", ""))
        resp["id"] = req_id
        _stats["served"] += 1
        if resp["ok"]:
            _log("request id={} ok=true".format(req_id))
        else:
            last_line = resp["error"].strip().splitlines()[-1] if resp["error"] else "?"
            _log("request id={} ok=false: {}".format(req_id, last_line))
        job["response"] = resp
        job["event"].set()


def _handle_conn(conn, addr):
    """Socket thread. NEVER touches RLPy -- only reads/writes bytes and the queue."""
    try:
        conn.settimeout(CONN_READ_TIMEOUT_S)
        buf = b""
        while not buf.endswith(b"\n"):
            chunk = conn.recv(4096)
            if not chunk:
                break
            buf += chunk
        if not buf.strip():
            return
        try:
            req = json.loads(buf.decode("utf-8"))
        except Exception:
            error_resp = {"id": None, "ok": False, "error": "invalid JSON request", "stdout": ""}
            conn.sendall((json.dumps(error_resp) + "\n").encode("utf-8"))
            return

        event = threading.Event()
        job = {"id": req.get("id"), "code": req.get("code", ""), "event": event, "response": None}
        _request_queue.put(job)
        event.wait()
        conn.sendall((json.dumps(job["response"]) + "\n").encode("utf-8"))
    except Exception:
        _log("connection handler error: {}".format(traceback.format_exc()))
    finally:
        try:
            conn.close()
        except Exception:
            pass


def _accept_loop(sock):
    """Daemon thread started from initialize_plugin(). NEVER touches RLPy."""
    sock.settimeout(ACCEPT_POLL_TIMEOUT_S)
    while not _stop_event.is_set():
        try:
            conn, addr = sock.accept()
        except socket.timeout:
            continue
        except OSError:
            break
        t = threading.Thread(target=_handle_conn, args=(conn, addr), daemon=True)
        t.start()
    _log("accept loop exiting")


def initialize_plugin():
    """Mandatory entry point -- iClone refuses to load a plugin without this.

    Entire body is wrapped in try/except so a load failure is logged instead
    of silently failing (plugin load failures are otherwise near-invisible).
    """
    global _server_socket, _accept_thread, _timer
    try:
        port = _get_port()
        _log("=" * 60)
        _log("TinqsBridge initialize_plugin() starting, requested port {}".format(port))

        sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
        sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
        try:
            sock.bind((HOST, port))
        except OSError:
            _log("BIND FAILED on {}:{} -- {}".format(HOST, port, traceback.format_exc()))
            _log("(A stale process or a second iClone instance may already hold this port.)")
            return
        sock.listen(5)
        _server_socket = sock
        _stats["port"] = port
        _log("bound OK on {}:{}".format(HOST, port))

        _accept_thread = threading.Thread(target=_accept_loop, args=(sock,), daemon=True)
        _accept_thread.start()
        _log("accept thread started")

        if QTimer is None:
            _log("PySide2.QtCore.QTimer unavailable -- no executor, bridge will accept "
                 "connections but never answer them")
            return

        _timer = QTimer()
        _timer.timeout.connect(_drain_queue)
        _timer.start(POLL_MS)
        _log("QTimer executor started ({} ms poll)".format(POLL_MS))
        _log("TinqsBridge ready on {}:{}. Python: {}".format(
            HOST, port, __import__("sys").version))
    except Exception:
        _log("initialize_plugin() FAILED:\n{}".format(traceback.format_exc()))


def dispose_plugin():
    """Called by iClone on plugin unload/app exit. Best-effort cleanup, never raises."""
    try:
        _stop_event.set()
        if _timer is not None:
            _timer.stop()
        if _server_socket is not None:
            try:
                _server_socket.close()
            except Exception:
                pass
        _log("dispose_plugin() -- shutting down, served {} requests total".format(
            _stats["served"]))
    except Exception:
        _log("dispose_plugin() FAILED:\n{}".format(traceback.format_exc()))