v0.166.0
  1import json
  2import os
  3import sys
  4from contextlib import nullcontext
  5from typing import TYPE_CHECKING, Any
  6
  7import click
  8from plain.cli import register_cli
  9from plain.preflight import set_check_counts
 10from plain.runtime import settings
 11
 12from .trace import (
 13    CapturedTrace,
 14    RawSpan,
 15    analyze_traces,
 16    capture_available,
 17    capture_trace_spans,
 18)
 19
 20if TYPE_CHECKING:
 21    from plain.testing import ClientResponse
 22
 23_HTTP_METHODS = ("GET", "POST", "PUT", "PATCH", "DELETE", "HEAD", "OPTIONS", "TRACE")
 24
 25_TRACE_UNAVAILABLE = (
 26    "Trace capture skipped — the tracer provider installed in this process "
 27    "isn't the OpenTelemetry SDK's, so there is nothing here to capture from."
 28)
 29
 30_TRACE_EMPTY = (
 31    "No spans were captured. Tracing may be turned off in this environment "
 32    "(for example OTEL_SDK_DISABLED)."
 33)
 34
 35_TRACE_NOT_REACHED = (
 36    "The request failed before it was dispatched, so there is no trace."
 37)
 38
 39
 40def _trace_note(traces: list[CapturedTrace] | None) -> str | None:
 41    """Explain an unusable `traces`, or None when there is a trace to read.
 42
 43    Anything that indexes into `traces` needs something to report instead of
 44    an IndexError. `traces is None` with capture unavailable means capture was
 45    skipped; with it available it means dispatch was never reached, since the
 46    analyzer runs unconditionally and any bug in it now propagates rather than
 47    being folded into this note.
 48    """
 49    if traces is None:
 50        return _TRACE_UNAVAILABLE if not capture_available() else _TRACE_NOT_REACHED
 51    if not traces:
 52        return _TRACE_EMPTY
 53    return None
 54
 55
 56# Cap on per-query lines shown in the text Trace section. `--trace` lifts it;
 57# `--json` is never capped.
 58_QUERY_LIST_LIMIT = 10
 59
 60# Width SQL is elided to in the terminal.
 61_SQL_DISPLAY_WIDTH = 64
 62
 63
 64def _get_request_user(response: ClientResponse) -> Any:
 65    """The authenticated user for the request, or None (plain.auth optional)."""
 66    try:
 67        from plain.auth.requests import get_request_user
 68    except ImportError:
 69        return None
 70    try:
 71        return get_request_user(response.request)
 72    except Exception:
 73        return None
 74
 75
 76def _display_sql(sql: str) -> str:
 77    """Collapse a statement to one elided line for the terminal.
 78
 79    The middle goes rather than the tail. A wide SELECT is mostly column
 80    list, so two statements against different tables share a long prefix and
 81    elide to the same string — it is the FROM and WHERE at the end that tell
 82    them apart.
 83    """
 84    one_line = " ".join(sql.split())
 85    if len(one_line) <= _SQL_DISPLAY_WIDTH:
 86        return one_line
 87    head = _SQL_DISPLAY_WIDTH * 3 // 5
 88    tail = _SQL_DISPLAY_WIDTH - head - 1
 89    return f"{one_line[:head]}…{one_line[-tail:]}"
 90
 91
 92def _installed_package_path(path: str) -> str | None:
 93    """The path below `site-packages`, or None when this is not a dependency.
 94
 95    Used only to shorten an installed dependency's call site for display.
 96    """
 97    _, marker, package_path = path.rpartition(f"site-packages{os.sep}")
 98    return package_path if marker else None
 99
100
101def _format_source(source: str) -> str:
102    """Shorten a source location for display.
103
104    An installed dependency collapses to its package path; anything else is
105    shown relative to the working directory when that comes out shorter, which
106    keeps sibling checkouts readable without inventing `../../..` chains for
107    paths in a different tree entirely.
108
109    This asks whether the path is *installed*, not whether it is app code —
110    a sibling checkout is neither, and wants the relative form.
111    """
112    if (installed_path := _installed_package_path(source)) is not None:
113        return installed_path
114    try:
115        relative = os.path.relpath(source, os.getcwd())
116    except ValueError:  # different drive on Windows
117        return source
118    return relative if len(relative) < len(source) else source
119
120
121def _echo_span(span: RawSpan, *, depth: int) -> None:
122    """Print one row of the span tree, indented to its depth."""
123    name = f"{'  ' * depth}{span['name']}"
124    if span.get("status") == "ERROR":
125        name = click.style(name, fg="red")
126    kind = click.style(f"  {span['kind']}", dim=True)
127    click.echo(f"    {span['duration_ms']:>8.2f}ms  {name}{kind}")
128
129
130def _render_span_tree(spans: list[RawSpan]) -> None:
131    """Print one trace's spans as an indented tree, parents before children.
132
133    Spans arrive flat and ordered by start time; `parent_span_id` gives the
134    structure. A span whose parent was not captured — the parent hadn't ended
135    when capture stopped — is rendered as a root rather than dropped.
136    """
137    captured_ids = {span["span_id"] for span in spans}
138    children: dict[str | None, list[RawSpan]] = {}
139    for span in spans:
140        parent = span["parent_span_id"]
141        if parent not in captured_ids:
142            parent = None
143        children.setdefault(parent, []).append(span)
144
145    # Malformed instrumentation (a self-parented span, or two spans sharing an
146    # id) would otherwise recurse forever. Tracked by identity rather than by
147    # span_id so that duplicate ids still each get rendered exactly once.
148    rendered: set[int] = set()
149
150    def render(parent_id: str | None, depth: int) -> None:
151        for span in children.get(parent_id, []):
152            if id(span) in rendered:
153                continue
154            rendered.add(id(span))
155            _echo_span(span, depth=depth)
156            render(span["span_id"], depth + 1)
157
158    render(None, 0)
159    # Anything left is unreachable from a root (a parent cycle). Print it flat
160    # rather than silently dropping spans the count above already promised.
161    for span in spans:
162        if id(span) not in rendered:
163            _echo_span(span, depth=0)
164
165
166def _render_trace(*, captured: CapturedTrace, detailed: bool, show_hint: bool) -> None:
167    """Render one trace's body — metrics, queries, and recorded exceptions.
168
169    Every listed statement names its call sites. When `detailed`, the query
170    list is uncapped and the full span tree is printed after the exceptions.
171    `show_hint` advertises `--trace`, and is set on one block only however
172    many traces were captured.
173    """
174    analysis = captured["analysis"]
175
176    click.echo(f"  Duration: {analysis['duration_ms']:.2f}ms")
177
178    spans_line = f"  Spans: {analysis['span_count']}"
179    if show_hint:
180        spans_line += click.style("  (--trace for the span tree)", dim=True)
181    click.echo(spans_line)
182
183    queries_line = f"  Queries: {analysis['query_count']}"
184    if transactions := analysis["transaction_count"]:
185        plural = "" if transactions == 1 else "s"
186        queries_line += click.style(
187            f"  +{transactions} transaction statement{plural}", dim=True
188        )
189    click.echo(queries_line)
190
191    queries = analysis["queries"]
192    if detailed:
193        shown = queries
194    else:
195        # The cap trims the singleton tail only. Duration-first order would
196        # otherwise push a fast, many-times-repeated statement below the cap —
197        # the one entry the reader most needs to see.
198        shown = queries[:_QUERY_LIST_LIMIT] + [
199            q for q in queries[_QUERY_LIST_LIMIT:] if q["count"] > 1
200        ]
201    for query in shown:
202        sql = _display_sql(query["sql"])
203        click.echo(
204            f"    {query['count']:>3}×  {query['total_duration_ms']:>7.2f}ms  {sql}"
205        )
206        # Truncated SQL alone rarely identifies a wide SELECT — the call site
207        # does, and two wide SELECTs can elide to the same string. Every
208        # listed statement names its call sites.
209        for source in query["sources"]:
210            click.echo(f"      → {_format_source(source)}")
211    if len(queries) > len(shown):
212        click.echo(f"    + {len(queries) - len(shown)} more — see --trace")
213
214    if exceptions := analysis["exceptions"]:
215        click.secho("  Exceptions:", fg="red", bold=True)
216        for exception in exceptions:
217            error_type = exception["error_type"] or "Exception"
218            click.secho(f"    ⚠ {error_type} in {exception['span']}", fg="red")
219            if message := exception["message"]:
220                click.secho(f"      {message}", fg="red")
221
222    if detailed:
223        click.echo("  Span tree:")
224        _render_span_tree(captured["spans"])
225
226
227def _render_traces(traces: list[CapturedTrace] | None, *, detailed: bool) -> None:
228    """Render the Trace section — one block per captured trace.
229
230    A followed redirect chain is several requests, so it gets several blocks
231    rather than one merged summary that would double-count anything the
232    framework does on every request.
233    """
234    if not traces:
235        click.secho("Trace:", fg="yellow", bold=True)
236        click.echo(f"  {_trace_note(traces)}")
237        return
238
239    for index, captured in enumerate(traces, start=1):
240        if index > 1:
241            click.echo()
242        label = (
243            "Trace:"
244            if len(traces) == 1
245            else f"Trace ({index}/{len(traces)}): {captured['name']}"
246        )
247        click.secho(label, fg="yellow", bold=True)
248        _render_trace(
249            captured=captured,
250            detailed=detailed,
251            show_hint=not detailed and index == 1,
252        )
253
254
255@register_cli("request")
256@click.command()
257@click.argument("path")
258@click.option(
259    "--method",
260    default="GET",
261    help="HTTP method (GET, POST, PUT, PATCH, DELETE, etc.)",
262)
263@click.option(
264    "--data",
265    help="Request body for POST/PUT/PATCH (form-encoded by default, e.g. 'key=val&key2=val2')",
266)
267@click.option(
268    "--user",
269    "user_id",
270    help="User ID or email to authenticate as (skips normal authentication)",
271)
272@click.option(
273    "--follow/--no-follow",
274    default=True,
275    help="Follow redirects (default: True)",
276)
277@click.option(
278    "--content-type",
279    help="Content-Type header for request data",
280)
281@click.option(
282    "--header",
283    "headers",
284    multiple=True,
285    help="Additional headers (format: 'Name: Value')",
286)
287@click.option(
288    "--no-headers",
289    is_flag=True,
290    help="Hide response headers from output",
291)
292@click.option(
293    "--no-body",
294    is_flag=True,
295    help="Hide response body from output",
296)
297@click.option(
298    "--status",
299    "assert_status",
300    type=int,
301    default=None,
302    help="Assert response status code equals this value",
303)
304@click.option(
305    "--contains",
306    "assert_contains",
307    multiple=True,
308    help="Assert response body contains this text (repeatable)",
309)
310@click.option(
311    "--not-contains",
312    "assert_not_contains",
313    multiple=True,
314    help="Assert response body does not contain this text (repeatable)",
315)
316@click.option(
317    "--trace",
318    "show_trace",
319    is_flag=True,
320    help=(
321        "Show the full trace in the text output — the complete query list and "
322        "the span tree. --json always includes it."
323    ),
324)
325@click.option(
326    "--json",
327    "output_json",
328    is_flag=True,
329    help="Output response metadata and the full trace as JSON (no body)",
330)
331def request(
332    path: str,
333    method: str,
334    data: str | None,
335    user_id: str | None,
336    follow: bool,
337    content_type: str | None,
338    headers: tuple[str, ...],
339    no_headers: bool,
340    no_body: bool,
341    assert_status: int | None,
342    assert_contains: tuple[str, ...],
343    assert_not_contains: tuple[str, ...],
344    show_trace: bool,
345    output_json: bool,
346) -> None:
347    """Make HTTP requests against the dev database"""
348
349    # Bound before the try so the failure handler can report a trace even
350    # when the request never got as far as capturing one.
351    traces: list[CapturedTrace] | None = None
352    traces_rendered = False
353
354    try:
355        # Only allow in DEBUG mode for security
356        if not settings.DEBUG:
357            click.secho("This command only works when DEBUG=True", fg="red", err=True)
358            raise SystemExit(1)
359
360        # Imported here rather than at the top: plain.dev loads this module
361        # to register the command every time `plain` starts, and the client
362        # is only worth its import time when a request is actually made.
363        from plain.testing import Client
364
365        client = Client(headers={"Host": "localhost"})
366
367        if user_id:
368            try:
369                from app.users.models import User
370            except ImportError:
371                raise click.UsageError(
372                    "app.users.models.User is required to use --user"
373                )
374
375            user = None
376            try:
377                # int() up front: get() takes the key's own type, and a
378                # non-numeric --user still raises ValueError, same as before.
379                user = User.query.get(int(user_id))
380            except User.DoesNotExist, ValueError:
381                pass
382
383            if user is None:
384                try:
385                    user = User.query.get(User.email.equals(user_id))
386                except User.DoesNotExist:
387                    pass
388
389            if user is None:
390                click.secho(f"User not found: {user_id}", fg="red", err=True)
391                raise SystemExit(1)
392
393            try:
394                from plain.auth.testing import login_client
395            except ImportError:
396                raise click.UsageError("plain.auth is required to use --user")
397
398            login_client(client, user)
399
400        # Parse additional headers (default Accept to text/html)
401        header_dict = {"Accept": "text/html"}
402        for header in headers:
403            if ":" in header:
404                key, value = header.split(":", 1)
405                header_dict[key.strip()] = value.strip()
406
407        # Auto-detect content type if not specified
408        if data and not content_type:
409            stripped = data.strip()
410            if stripped.startswith(("{", "[")):
411                content_type = "application/json"
412            else:
413                content_type = "application/x-www-form-urlencoded"
414
415        # Validate JSON data
416        if data and content_type and "json" in content_type.lower():
417            try:
418                json.loads(data)
419            except json.JSONDecodeError as e:
420                click.secho(f"Invalid JSON data: {e}", fg="red", err=True)
421                raise SystemExit(1)
422
423        method = method.upper()
424        if method not in _HTTP_METHODS:
425            click.secho(f"Unsupported HTTP method: {method}", fg="red", err=True)
426            raise SystemExit(1)
427
428        # Only these methods send the data, with its content type.
429        sends_data = method in ("POST", "PUT", "PATCH") and bool(data)
430
431        # The admin toolbar's preflight badge otherwise runs the full preflight
432        # suite on first render, landing those queries in the captured trace.
433        set_check_counts(errors=0, warnings=0)
434
435        # Make the request, capturing a trace unless the process has a
436        # tracer provider we can't capture from.
437        capture = capture_trace_spans() if capture_available() else nullcontext()
438        with capture as otel_exporter:
439            try:
440                response = client.request(
441                    method,
442                    path,
443                    body=data if sends_data else None,
444                    content_type=content_type if sends_data else None,
445                    headers=header_dict,
446                    follow_redirects=follow,
447                )
448            finally:
449                # Analyze in a `finally` so a view that raises still leaves
450                # a trace behind — that is the request you most want one
451                # for. Spans are exported as they end, so the ones that
452                # completed before the raise are already here.
453                if otel_exporter is not None:
454                    traces = analyze_traces(otel_exporter.get_finished_spans())
455
456        # The route that handled the request, by name. None when a
457        # middleware answered it, or nothing matched.
458        resolver_match = response.request.resolver_match
459        url_pattern = resolver_match.namespaced_url_name if resolver_match else None
460
461        # Whether the app streamed the body (an asset, an export).
462        streaming = response.returned_response.streaming
463
464        # Run assertions (shared by text and JSON output)
465        failed: list[str] = []
466
467        if assert_status is not None:
468            if response.status_code != assert_status:
469                failed.append(
470                    f"Expected status {assert_status}, got {response.status_code}"
471                )
472        elif response.status_code >= 500:
473            failed.append(f"Server error: {response.status_code}")
474
475        # The client reads a streaming body the way a server sends it,
476        # so a streamed body (e.g. an asset or export) is here to check too.
477        body_bytes = response.body
478        # A streamed body is only summarized below, so it's decoded just
479        # for assertions — a large binary download never is.
480        if streaming and not (assert_contains or assert_not_contains):
481            body_text = ""
482        else:
483            body_text = body_bytes.decode("utf-8", errors="replace")
484
485        for text in assert_contains:
486            if text not in body_text:
487                failed.append(f"Response body does not contain: {text}")
488
489        for text in assert_not_contains:
490            if text in body_text:
491                failed.append(f"Response body contains: {text}")
492
493        if output_json:
494            response_data: dict[str, Any] = {
495                "status": response.status_code,
496                "request_id": response.request.unique_id,
497            }
498            request_user = _get_request_user(response)
499            response_data["user"] = str(request_user) if request_user else None
500            redirects = response.redirect_chain
501            if redirects:
502                response_data["redirects"] = [
503                    {"url": url, "status": status} for url, status in redirects
504                ]
505            if url_pattern:
506                response_data["url_pattern"] = url_pattern
507            if response.headers:
508                response_data["headers"] = dict(response.headers)
509            json_output: dict[str, Any] = {
510                "response": response_data,
511                "traces": traces,
512            }
513            if note := _trace_note(traces):
514                json_output["trace_note"] = note
515            if failed:
516                json_output["assertion_failures"] = failed
517            click.echo(json.dumps(json_output, indent=2))
518            if failed:
519                raise SystemExit(1)
520            return
521
522        # Display response information
523        click.secho("Response:", fg="yellow", bold=True)
524
525        # Status code
526        click.echo(f"  Status: {response.status_code}")
527
528        # Request ID
529        click.echo(f"  Request ID: {response.request.unique_id}")
530
531        # Surface followed redirects — a 200 may not be the path you asked for.
532        redirects = response.redirect_chain
533        if redirects:
534            hops = " → ".join(
535                [path] + [f"{url} ({status})" for url, status in redirects]
536            )
537            click.secho(f"  Redirected: {hops}", fg="yellow")
538
539        if url_pattern:
540            click.echo(f"  URL pattern: {url_pattern}")
541
542        # Always show auth state — authed vs anonymous should never be ambiguous.
543        request_user = _get_request_user(response)
544        if request_user:
545            click.echo(f"  User: {request_user}")
546        else:
547            click.echo("  User: anonymous")
548
549        # Trace — its own section, paralleling the JSON `traces` key
550        click.echo()
551        # Set before rendering so a partial render isn't duplicated by the
552        # failure handler if `_render_traces` raises partway through.
553        traces_rendered = True
554        _render_traces(traces, detailed=show_trace)
555
556        click.echo()
557
558        # Show headers
559        if response.headers and not no_headers:
560            click.secho("Response Headers:", fg="yellow", bold=True)
561            for key, value in response.headers.items():
562                click.echo(f"  {key}: {value}")
563            click.echo()
564
565        # Show response content last
566        if no_body:
567            pass
568        elif streaming:
569            # Streaming/file responses (e.g. assets, exports): summarize
570            # instead of dumping what may be a large or binary body.
571            click.secho("Response Body:", fg="yellow", bold=True)
572            content_type = response.headers.get("Content-Type", "") or "unknown"
573            if body_bytes:
574                size = f"{len(body_bytes)} bytes"
575            elif length := response.headers.get("Content-Length"):
576                # A HEAD request: nothing was read, but the header says.
577                size = f"{length} bytes"
578            else:
579                size = "no body"
580            click.echo(f"  (streaming response: {content_type}, {size})")
581        elif body_text:
582            content_type = response.headers.get("Content-Type", "").lower()
583
584            # Default: print the decoded body under a generic header. JSON is
585            # pretty-printed; HTML and everything else print as-is.
586            header = "Response Body:"
587            output = body_text
588
589            if "json" in content_type:
590                try:
591                    output = json.dumps(response.json_data, indent=2)
592                    header = "Response Body (JSON):"
593                except Exception:
594                    pass  # fall back to the raw decoded body
595            elif "html" in content_type:
596                header = "Response Body (HTML):"
597
598            click.secho(header, fg="yellow", bold=True)
599            click.echo(output)
600        else:
601            click.secho("(No response body)", fg="yellow", dim=True)
602
603        # Report assertion failures
604        if failed:
605            click.echo()
606            click.secho("Assertions failed:", fg="red", bold=True)
607            for msg in failed:
608                click.secho(f"  ✗ {msg}", fg="red")
609            raise SystemExit(1)
610
611    except SystemExit:
612        raise
613    except BrokenPipeError:
614        # Downstream closed the pipe (`| head`) — not a failure. Point stdout
615        # at devnull so the interpreter's shutdown flush doesn't raise again.
616        devnull = os.open(os.devnull, os.O_WRONLY)
617        os.dup2(devnull, sys.stdout.fileno())
618        raise SystemExit(0)
619    except Exception as e:
620        click.secho(f"Request failed: {e}", fg="red", err=True)
621        # A failed request still captured a trace, and it is the one worth
622        # reading. Report it in whichever shape was asked for rather than
623        # exiting with nothing on stdout.
624        if output_json:
625            failure: dict[str, Any] = {"error": str(e), "traces": traces}
626            if note := _trace_note(traces):
627                failure["trace_note"] = note
628            click.echo(json.dumps(failure, indent=2))
629        elif traces is not None and not traces_rendered:
630            # Only when a request actually ran — a usage error has no trace to
631            # discuss, and a Trace section would be the whole of stdout.
632            click.echo()
633            _render_traces(traces, detailed=show_trace)
634        raise SystemExit(1)