run --local: attach a file log subscriber so application logs are captured

.claude/skills/fix-issue.md

@@ -174,6 +174,7 @@ to the symptom table below, so the next similar issue costs fewer reads.
 | `retrieve … where [Seq = $Game/MoveSeq + 1]` fails with a bare `mismatched input '+' expecting ']'` — no hint that Mendix XPath can't compute values (this is a Mendix limitation, not an mxcli bug) | Mendix XPath constraints take a literal/token/variable/path on the value side, never an arithmetic expression; the parse error named the token but not the cause | `mdl/visitor/visitor.go` (`enhanceErrorMessage`, `looksLikeXPathArithmetic`/`xpathArithmeticRe`) | Do NOT add grammar support (mxbuild would still reject the XPath). Add an error hint keyed on `mismatched input '<+|*|div|mod>' expecting ']'` (`expecting ']'` only occurs inside a `[…]` constraint) explaining the limitation and the workaround: compute into a variable first, then compare. Also documented in `xpath-constraints.md`. Bug-test `mdl-examples/bug-tests/f8-xpath-arithmetic.fail.mdl`. Findings #8 |
 | Design properties are written free-form: a `ColorPicker`/`ToggleButtonGroup` value serializes as a plain option (wrong `$Type` for Studio Pro's Appearance tab), and a typo'd key/value (they're case-sensitive) passes `mxcli check`. Also `show design properties <widget>` reports "No design properties found for widget type container" for a valid widget | Root bug: `resolveDesignPropsKey` upper-cased the MDL keyword but the lookup map is **lowercase-keyed**, so `container`→`DivContainer` never resolved — leaving `resolveDesignPropertyValueType` dead code and the theme registry unused on the write/validate paths | `mdl/executor/theme_reader.go` (`resolveDesignPropsKey` case fix) + `mdl/executor/cmd_pages_builder_v3.go` (`astDesignPropToValue` takes theme props) + `mdl/executor/validate_design_properties.go` (new, MDL-WIDGET11/12) wired from `cmd/mxcli/cmd_check.go` + `cmd/mxcli/lsp_diagnostics.go` (cached `themeRegistry`) | Fix `resolveDesignPropsKey` to lower-case the lookup. On write, resolve each flat value's type from the registry (`ColorPicker`/`ToggleButtonGroup`→custom). On check (`-p` only, when themesource defines properties), walk page/snippet/alter-page widget trees and warn: **MDL-WIDGET11** unknown key (case-sensitivity hint / valid-key list), **MDL-WIDGET12** invalid value (lists allowed values). Warnings, not errors — a newer theme may add keys/values (forward-compat, per `page-styling-support.md:402`). Skip compound (registry doesn't model sub-props) and widgets with no type-specific metadata (pluggable). Bug-test `mdl-examples/bug-tests/typed-design-properties.mdl` |
 | `mxcli run --local`: when a page action throws, the browser shows the generic Mendix error dialog and there is nothing to correlate it against — the runtime's own stdout/stderr (server stack trace, microflow `LOG` output) is swallowed, so a server-side bug can't be told apart from a client one | The runtime JVM was spawned with `cmd.Stdout=log; cmd.Stderr=log` where `log` is an in-memory `syncBuffer` surfaced only on a *startup* failure; during normal operation it goes nowhere on disk | `cmd/mxcli/docker/localboot.go` (`spawnAndConfigure`, `openRuntimeLog`, `LocalRuntime.logFile`, `LocalRuntimeOptions.RuntimeLogPath`) + `cmd/mxcli/docker/runlocal.go` (default `<projectDir>/.mxcli/runtime.log`) + `cmd/mxcli/cmd_run.go` (`--runtime-log`) | Tee the JVM's stdout+stderr to `<projectDir>/.mxcli/runtime.log` via `io.MultiWriter(log, file)` (the in-memory buffer still backs startup-error reporting). Append across restarts with a `=== runtime start … ===` marker; close the handle on Stop/reopen. Default on; `--runtime-log <path>` relocates, `-` disables. Print the path at boot. Test `TestOpenRuntimeLog`. Findings #25 |
+| Follow-up to the above (#25 re-test): `run --local` writes `runtime.log` but it stays **nearly empty** — the JVM tee captures startup/JVM output only; **application** logs (microflow `LOG`, server-side exception stack traces) never reach stdout, so a page-action error still can't be diagnosed | A standalone runtime (launched via `runtimelauncher.jar`) attaches **no log subscriber** by default — unlike a Studio Pro / m2ee run, which calls `create_log_subscriber` **after** start. Mendix application logs flow to log *subscribers*, not stdout, so with none attached they go nowhere | `cmd/mxcli/docker/runtime_controller.go` (`RuntimeController.LogSubscriberFile`/`Stdout`, `attachFileLogSubscriber`, called at the end of `Start`) + `cmd/mxcli/docker/localboot.go` (`StartLocalRuntime` sets `ctrl.LogSubscriberFile` to the abs runtime-log path) | After a successful `start` (and on every restart's `Start`, since each fresh JVM has no subscriber), call the `create_log_subscriber` admin action with `{type:"file", name:"mxcli-run-local", autosubscribe:"INFO", filename:<abs runtime.log>, max_size:1GiB, max_rotate:0}`. **`max_rotate:0` is load-bearing**: the JVM stdout tee holds an fd on the same file, and a rotate-rename would detach it. Best-effort (a logging failure must not fail an up runtime — warn to Stdout instead). Pass an **absolute** path (the runtime's cwd is `<install>/runtime`, not mxcli's). Tests `TestStart_AttachesLogSubscriber`, `TestStart_NoLogSubscriberWhenUnset`, `TestStart_LogSubscriberFailureNonFatal`. Findings #25 (round 2) |
 
 ---
 

.claude/skills/mendix/run-local.md

@@ -116,7 +116,7 @@ Launch `run --local` as the **sole** command in its invocation (don't chain a tr
 | `--screenshot` | off | Playwright PNG after boot + each change |
 | `--screenshot-path` / `--screenshot-url` | `.mxcli/run-local.png` / app root | Screenshot output / page (URL or `/path`) |
 | `--screenshot-user` / `--screenshot-password` | — | Log in once, reuse session (pages behind login) |
-| `--runtime-log` | `.mxcli/runtime.log` | Tee the Mendix runtime's stdout+stderr to a file for debugging (`-` disables) |
+| `--runtime-log` | `.mxcli/runtime.log` | Runtime log file: JVM stdout/stderr **and** the application log (microflow `LOG` output + server stack traces, via an attached file log subscriber). `-` disables. |
 | `--app-port` / `--admin-port` / `--serve-port` | 8080 / 8090 / 6543 | Ports |
 | `--db-host` / `--db-name` / `--db-user` / `--db-password` | 127.0.0.1:5432 / derived / mendix / mendix | Database |
 
@@ -153,12 +153,23 @@ mxcli run --local -p app.mpr --watch --screenshot
 ## Debugging a server-side error
 
 When a page action throws, the browser shows the generic Mendix error dialog with no
-detail. The runtime's own log — server stack traces and your microflow `LOG ERROR`/
-`LOG INFO` output — is tee'd to `<projectDir>/.mxcli/runtime.log` (the path is printed
+detail. The runtime log — server stack traces and your microflow `LOG ERROR`/
+`LOG INFO` output — is written to `<projectDir>/.mxcli/runtime.log` (the path is printed
 at boot). `tail -f .mxcli/runtime.log` while you reproduce the action to see the stack
-and correlate it. The file is appended across restarts (each boot writes a
-`=== runtime start … ===` marker). Override the path with `--runtime-log <path>`, or
-pass `--runtime-log -` to disable the file.
+and correlate it.
+
+Two things feed that file, because a standalone runtime attaches **no** log subscriber
+by default (a Studio Pro / m2ee run does):
+
+- mxcli tees the runtime **JVM's** stdout/stderr to it (startup output, JVM-level crashes).
+- After start, mxcli attaches a Mendix **file log subscriber** so the **application** log
+  — microflow `LOG` output and server-side exception stack traces — lands there too.
+  Without this, application logs go nowhere and the file is nearly empty.
+
+The file is appended across restarts (each boot writes a `=== runtime start … ===`
+marker); the subscriber is re-attached on every restart and never rotates the file (so
+the JVM tee's handle stays valid). Override the path with `--runtime-log <path>`, or
+pass `--runtime-log -` to disable the file (and the subscriber) entirely.
 
 ## External browser preview (`--hub`)
 

cmd/mxcli/cmd_run.go

@@ -38,10 +38,13 @@ mxcli tunnel-hub, without leaving this machine: a chisel client reverse-tunnels
 the local app out over 443, and the runtime boots with ApplicationRootUrl set to
 the hub URL so the app works under that origin. --hub implies --local.
 
-The Mendix runtime's own stdout/stderr (server stack traces, microflow LOG
-output) is tee'd to <projectDir>/.mxcli/runtime.log so a server-side error is
-debuggable — the path is printed at boot. Override with --runtime-log <path>,
-or "-" to disable.
+The Mendix runtime log — server-side stack traces and your microflow LOG
+output — is written to <projectDir>/.mxcli/runtime.log so a server-side error
+is debuggable (the browser only shows a generic dialog). mxcli both tees the
+runtime JVM's stdout/stderr to the file and attaches a Mendix file log
+subscriber after start, so the application log lands there too (a standalone
+runtime attaches no subscriber by default). The path is printed at boot;
+override with --runtime-log <path>, or "-" to disable.
 
 Examples:
   mxcli run --local -p app.mpr
@@ -159,6 +162,6 @@ func init() {
 	runCmd.Flags().StringArray("screenshot-url", nil, "Page to screenshot: a full URL or a path relative to the app root, e.g. /p/customers (default the app root). Repeat for a multi-page set.")
 	runCmd.Flags().String("screenshot-user", "", "Log in with this user before screenshotting (for pages behind login)")
 	runCmd.Flags().String("screenshot-password", "", "Password for --screenshot-user")
-	runCmd.Flags().String("runtime-log", "", "Tee the Mendix runtime's stdout+stderr to this file for debugging (default <projectDir>/.mxcli/runtime.log; \"-\" to disable)")
+	runCmd.Flags().String("runtime-log", "", "Write the Mendix runtime log (server stack traces + microflow LOG output) to this file for debugging (default <projectDir>/.mxcli/runtime.log; \"-\" to disable)")
 	rootCmd.AddCommand(runCmd)
 }

cmd/mxcli/docker/localboot.go

@@ -250,6 +250,18 @@ func StartLocalRuntime(opts LocalRuntimeOptions) (*LocalRuntime, error) {
 		},
 	}
 	rt.ctrl = NewRuntimeController(rt.m2ee)
+	// Attach a file log subscriber (post-start, inside Start) so the runtime's
+	// application log lands in the same file the JVM stdout/stderr is tee'd to.
+	// An absolute path keeps the runtime (cwd = <install>/runtime) and the JVM
+	// tee (cwd = mxcli's) pointed at one file. Findings #25.
+	if opts.RuntimeLogPath != "" {
+		logPath := opts.RuntimeLogPath
+		if abs, err := filepath.Abs(logPath); err == nil {
+			logPath = abs
+		}
+		rt.ctrl.LogSubscriberFile = logPath
+		rt.ctrl.Stdout = opts.Stdout
+	}
 
 	if err := rt.spawnAndConfigure(); err != nil {
 		return nil, err

cmd/mxcli/docker/runtime_controller.go

@@ -4,6 +4,7 @@ package docker
 
 import (
 	"fmt"
+	"io"
 	"strings"
 )
 
@@ -15,8 +16,30 @@ import (
 // docs/11-proposals/PROPOSAL_mxcli_dev_warm_loop.md § Hot-reload scope).
 type RuntimeController struct {
 	opts M2EEOptions
+	// LogSubscriberFile, when non-empty, makes Start attach a Mendix "file" log
+	// subscriber writing the application log (microflow LOG output, server-side
+	// stack traces) to this file after a successful start. A standalone runtime
+	// attaches no log subscriber by default — unlike a Studio Pro / m2ee run,
+	// which configures one after start — so without this the application log is
+	// never written anywhere and a page-action error shows only the generic
+	// Mendix dialog (findings #25). The runtime is told never to rotate the file
+	// (max_rotate 0) because run --local also tees the JVM's own stdout/stderr to
+	// this same path, and a rotate-rename would detach that handle.
+	LogSubscriberFile string
+	// Stdout receives a non-fatal warning if the log subscriber cannot be
+	// attached (the app is already up at that point). nil is silent.
+	Stdout io.Writer
 }
 
+// logSubscriberName identifies the file log subscriber run --local attaches. A
+// stable name means a restart's re-attach replaces rather than duplicates it.
+const logSubscriberName = "mxcli-run-local"
+
+// maxRuntimeLogSize bounds the file subscriber. With max_rotate 0 the runtime
+// never rotates, so keep this generous — it is a per-session dev log, not a
+// production sink.
+const maxRuntimeLogSize = 1 << 30 // 1 GiB
+
 // NewRuntimeController returns a controller for the given admin API connection.
 func NewRuntimeController(opts M2EEOptions) *RuntimeController {
 	return &RuntimeController{opts: opts}
@@ -87,9 +110,41 @@ func (c *RuntimeController) Start() (*M2EEResponse, error) {
 	if msg := resp.M2EEError(); msg != "" {
 		return resp, fmt.Errorf("start failed: %s", msg)
 	}
+	// The runtime is up; wire the application log to a file (best-effort — a
+	// logging hiccup must not fail an otherwise-good start). Re-run on every
+	// Start so a restart's fresh JVM re-attaches the subscriber (findings #25).
+	if err := c.attachFileLogSubscriber(); err != nil && c.Stdout != nil {
+		fmt.Fprintf(c.Stdout, "  (runtime application log not attached: %v)\n", err)
+	}
 	return resp, nil
 }
 
+// attachFileLogSubscriber wires the runtime's application log to
+// LogSubscriberFile via the create_log_subscriber admin action (a no-op when the
+// field is empty). It mirrors what m2ee-tools does after start: register a
+// "file" subscriber that autosubscribes to every log node at INFO or above.
+func (c *RuntimeController) attachFileLogSubscriber() error {
+	if c.LogSubscriberFile == "" {
+		return nil
+	}
+	params := map[string]any{
+		"type":          "file",
+		"name":          logSubscriberName,
+		"autosubscribe": "INFO",
+		"filename":      c.LogSubscriberFile,
+		"max_size":      maxRuntimeLogSize,
+		"max_rotate":    0,
+	}
+	resp, err := CallM2EE(c.opts, "create_log_subscriber", params)
+	if err != nil {
+		return err
+	}
+	if msg := resp.M2EEError(); msg != "" {
+		return fmt.Errorf("create_log_subscriber: %s", msg)
+	}
+	return nil
+}
+
 // RuntimeStatus returns the runtime status string (e.g. "running", "starting").
 func (c *RuntimeController) RuntimeStatus() (string, error) {
 	resp, err := CallM2EE(c.opts, "runtime_status", nil)

cmd/mxcli/docker/runtime_controller_test.go

@@ -3,12 +3,14 @@
 package docker
 
 import (
+	"bytes"
 	"encoding/json"
 	"net"
 	"net/http"
 	"net/http/httptest"
 	"net/url"
 	"strconv"
+	"strings"
 	"testing"
 )
 
@@ -103,6 +105,93 @@ func TestStart_CleanDatabase(t *testing.T) {
 	}
 }
 
+func TestStart_AttachesLogSubscriber(t *testing.T) {
+	// Capture the create_log_subscriber params so we can assert the file
+	// subscriber is wired correctly (findings #25).
+	var subParams map[string]any
+	var actions []string
+	ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		var req struct {
+			Action string         `json:"action"`
+			Params map[string]any `json:"params"`
+		}
+		_ = json.NewDecoder(r.Body).Decode(&req)
+		actions = append(actions, req.Action)
+		if req.Action == "create_log_subscriber" {
+			subParams = req.Params
+		}
+		_ = json.NewEncoder(w).Encode(M2EEResponse{})
+	}))
+	t.Cleanup(ts.Close)
+	host, port := parseTestServerAddr(t, ts.URL)
+
+	c := NewRuntimeController(M2EEOptions{Host: host, Port: port, Token: "test", Direct: true})
+	c.LogSubscriberFile = "/tmp/x/runtime.log"
+	if _, err := c.Start(); err != nil {
+		t.Fatalf("Start: %v", err)
+	}
+
+	// The subscriber is attached after a successful start.
+	if len(actions) != 2 || actions[0] != "start" || actions[1] != "create_log_subscriber" {
+		t.Fatalf("actions = %v, want [start create_log_subscriber]", actions)
+	}
+	if subParams == nil {
+		t.Fatal("create_log_subscriber received no params")
+	}
+	if subParams["type"] != "file" {
+		t.Errorf("type = %v, want file", subParams["type"])
+	}
+	if subParams["filename"] != "/tmp/x/runtime.log" {
+		t.Errorf("filename = %v, want /tmp/x/runtime.log", subParams["filename"])
+	}
+	if subParams["autosubscribe"] != "INFO" {
+		t.Errorf("autosubscribe = %v, want INFO", subParams["autosubscribe"])
+	}
+	if subParams["name"] != logSubscriberName {
+		t.Errorf("name = %v, want %v", subParams["name"], logSubscriberName)
+	}
+	// max_rotate 0 = never rename the file (the JVM tee holds an fd on it). JSON
+	// numbers decode to float64.
+	if mr, ok := subParams["max_rotate"].(float64); !ok || mr != 0 {
+		t.Errorf("max_rotate = %v, want 0", subParams["max_rotate"])
+	}
+}
+
+func TestStart_NoLogSubscriberWhenUnset(t *testing.T) {
+	// Without LogSubscriberFile, Start must not attach a subscriber.
+	m, opts := newMockAdmin(t, map[string]func(int) M2EEResponse{"start": ok})
+	if _, err := NewRuntimeController(opts).Start(); err != nil {
+		t.Fatalf("Start: %v", err)
+	}
+	for _, a := range m.calls {
+		if a == "create_log_subscriber" {
+			t.Fatalf("create_log_subscriber was called with no LogSubscriberFile set (calls=%v)", m.calls)
+		}
+	}
+}
+
+func TestStart_LogSubscriberFailureNonFatal(t *testing.T) {
+	// A failing create_log_subscriber must not fail an otherwise-good start; the
+	// app is already up. The failure is reported to Stdout instead.
+	m, opts := newMockAdmin(t, map[string]func(int) M2EEResponse{
+		"start":                 ok,
+		"create_log_subscriber": func(int) M2EEResponse { return M2EEResponse{Result: 1, Message: "no disk"} },
+	})
+	var stdout bytes.Buffer
+	c := NewRuntimeController(opts)
+	c.LogSubscriberFile = "/tmp/x/runtime.log"
+	c.Stdout = &stdout
+	if _, err := c.Start(); err != nil {
+		t.Fatalf("Start should not fail when the log subscriber fails: %v", err)
+	}
+	if len(m.calls) != 2 || m.calls[1] != "create_log_subscriber" {
+		t.Errorf("calls = %v, want [start create_log_subscriber]", m.calls)
+	}
+	if !strings.Contains(stdout.String(), "application log not attached") {
+		t.Errorf("expected a non-fatal warning on stdout, got %q", stdout.String())
+	}
+}
+
 func TestStart_OutOfDateDatabase(t *testing.T) {
 	// First start reports the schema must change (result 3); after DDL, start succeeds.
 	m, opts := newMockAdmin(t, map[string]func(int) M2EEResponse{

docs-site/src/tools/run-local.md

@@ -77,16 +77,22 @@ so structural changes need a restart; behavioural changes do not.
 | `--screenshot-path` | `<projectDir>/.mxcli/run-local.png` | Screenshot output PNG |
 | `--screenshot-url` | app root | Page to shoot: full URL, or a path relative to the app root (e.g. `/p/customers`). Repeat for a multi-page set. |
 | `--screenshot-user` / `--screenshot-password` | — | Log in once (Mendix form auth) and reuse the session, so pages behind login render authenticated |
-| `--runtime-log` | `<projectDir>/.mxcli/runtime.log` | Tee the Mendix runtime's stdout+stderr (server stack traces, microflow `LOG` output) to a file; `-` disables |
+| `--runtime-log` | `<projectDir>/.mxcli/runtime.log` | Runtime log file — JVM stdout/stderr **and** the application log (server stack traces + microflow `LOG` output); `-` disables |
 
 ## Debugging a server-side error
 
 When a page action throws, the browser shows the generic Mendix error dialog with no
-detail. The runtime's own log is tee'd to `<projectDir>/.mxcli/runtime.log` (the path is
+detail. The runtime log is written to `<projectDir>/.mxcli/runtime.log` (the path is
 printed at boot) — `tail -f .mxcli/runtime.log` while you reproduce the action to see the
-server stack trace and your microflow `LOG` output. The file is appended across restarts,
-each marked with `=== runtime start … ===`. Use `--runtime-log <path>` to relocate it or
-`--runtime-log -` to turn it off.
+server stack trace and your microflow `LOG` output.
+
+A standalone runtime attaches **no** log subscriber by default (a Studio Pro / m2ee run
+does), so mxcli wires two sources into that file: it tees the runtime JVM's stdout/stderr,
+and after start it attaches a Mendix **file log subscriber** so the application log
+(microflow `LOG` output and server-side stack traces) lands there too — otherwise the file
+would be nearly empty. The file is appended across restarts, each marked with
+`=== runtime start … ===`; the subscriber is re-attached on each restart and never rotates
+the file. Use `--runtime-log <path>` to relocate it or `--runtime-log -` to turn it off.
 
 ## External browser preview (`--hub`)