Skip to content

Commit 9a4751a

Browse files
fix(Mountain): improve extension loading, add BATCH-16 latency instrumentation
Key changes: - LocalhostPlugin: add MIME type override for JS/CSS/JSON/HTML/SVG assets to fix "not a valid JavaScript MIME type" errors in webview - ScanPathConfigure: remove debug_only gate on extension scan paths, enabling repo-layout fallback in release builds - AppLifecycle: extend fallback timers (2s→8s, 5s→15s) with logging when Sky hasn't advanced phases; skip if already advanced - TerminalProvider: capture and log PID + exit status code on terminal exit - DevLog: replace manual UTC timestamp with chrono::Local to match VS Code's session log directory convention - WindServiceHandlers: add diagnostic:log bridge, implement extensions:getInstalled for sidebar, add aux window stubs, use shared SessionTimestamp - CreateEffectForRequest: add BATCH-16 timestamps at dispatch-enter and body-start for tree.register latency analysis - MountainVinegRPCService: add grpc-recv timestamp for hot-path RPCs enabling 3-hop latency breakdown These changes improve extension loading reliability, add diagnostic visibility into RPC latency, and fix session log directory mismatch between Mountain.dev.log and VS Code output logs.
1 parent 22db075 commit 9a4751a

10 files changed

Lines changed: 486 additions & 117 deletions

File tree

Source/Binary/Build/LocalhostPlugin.rs

Lines changed: 42 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,36 @@ use tauri::plugin::TauriPlugin;
1515
/// this proxy forwards to the real collector via raw TCP. Zero CORS issues.
1616
const OTLP_HOST:&str = "127.0.0.1:4318";
1717

18+
/// Resolve the correct `Content-Type` for a request URL by its file extension.
19+
///
20+
/// The vendored `tauri-plugin-localhost` asset resolver sometimes reports
21+
/// `text/html` for disk-served `.js` / `.css` assets, which breaks module
22+
/// loading in the webview (the browser refuses JS with `'text/html' is not a
23+
/// valid JavaScript MIME type'`). By pre-setting `Content-Type` in
24+
/// `on_request`, we guarantee the right MIME for the extensions the workbench
25+
/// actually loads; the patched plugin keeps our value instead of overwriting.
26+
///
27+
/// Returns `None` for unknown extensions so the plugin's `asset.mime_type`
28+
/// fallback still applies (e.g. images, fonts, WASM — the asset resolver
29+
/// handles those correctly).
30+
fn MimeFromUrl(Url:&str) -> Option<&'static str> {
31+
// Strip query string / fragment before extension match.
32+
let Path = Url.split(['?', '#']).next().unwrap_or(Url);
33+
34+
let Extension = Path.rsplit('.').next()?.to_ascii_lowercase();
35+
36+
match Extension.as_str() {
37+
"js" | "mjs" | "cjs" => Some("application/javascript; charset=utf-8"),
38+
"css" => Some("text/css; charset=utf-8"),
39+
"json" | "map" => Some("application/json; charset=utf-8"),
40+
"html" | "htm" => Some("text/html; charset=utf-8"),
41+
"svg" => Some("image/svg+xml"),
42+
"wasm" => Some("application/wasm"),
43+
"txt" => Some("text/plain; charset=utf-8"),
44+
_ => None,
45+
}
46+
}
47+
1848
/// Forward a JSON body to the OTLP collector via raw HTTP/1.1 POST.
1949
/// Returns true if the collector accepted (2xx), false otherwise.
2050
fn ProxyToOTLP(Body:&[u8]) -> bool {
@@ -66,8 +96,9 @@ pub fn LocalhostPlugin<R:tauri::Runtime>(ServerPort:u16) -> TauriPlugin<R> {
6696
Response.add_header("Access-Control-Allow-Methods", "GET, POST, OPTIONS, HEAD");
6797
Response.add_header("Access-Control-Allow-Headers", "Content-Type, Authorization, Origin, Accept");
6898

69-
// OTLP proxy: forward /v1/traces to the local collector
7099
let Url = Request.url();
100+
101+
// OTLP proxy: forward /v1/traces to the local collector
71102
if Url.contains("/v1/traces") {
72103
Response.set_handled(true);
73104
let Body = Request.body();
@@ -79,6 +110,16 @@ pub fn LocalhostPlugin<R:tauri::Runtime>(ServerPort:u16) -> TauriPlugin<R> {
79110
// OTELBridge stops retrying after first failure.
80111
Response.set_status(204);
81112
}
113+
return;
114+
}
115+
116+
// Pre-set the correct `Content-Type` for known asset extensions.
117+
// The patched localhost plugin only falls back to asset.mime_type
118+
// when this header is absent, so setting it here makes our value
119+
// authoritative. Fixes module-loading errors of the form
120+
// `'text/html' is not a valid JavaScript MIME type`.
121+
if let Some(Mime) = MimeFromUrl(Url) {
122+
Response.add_header("Content-Type", Mime);
82123
}
83124
})
84125
.build()

Source/Binary/Extension/ScanPathConfigure.rs

Lines changed: 31 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -64,35 +64,38 @@ pub fn ScanPathConfigure(AppState:&std::sync::Arc<ApplicationState>) -> Result<V
6464
dev_log!("extensions", "[Extensions] [ScanPaths] + {}", LocalPath.display());
6565
ScanPathsGuard.push(LocalPath);
6666

67-
// Dev-only fallback paths: the monorepo layout
68-
// (Element/Mountain/Target/debug/) is not present in shipped
69-
// bundles. In production, the ../Resources/extensions path above
70-
// is authoritative. Gate with cfg to keep release builds lean.
71-
#[cfg(debug_assertions)]
72-
{
73-
// Sky Target path: where CopyVSCodeAssets copies built-in
74-
// extensions during the build.
75-
let SkyTargetPath = Parent.join("../../../Sky/Target/Static/Application/extensions");
76-
if SkyTargetPath.exists() {
77-
dev_log!(
78-
"extensions",
79-
"[Extensions] [ScanPaths] + {} (Sky Target, dev)",
80-
SkyTargetPath.display()
81-
);
82-
ScanPathsGuard.push(SkyTargetPath);
83-
}
67+
// Monorepo-layout fallback paths: resolved relative to
68+
// `Element/Mountain/Target/{debug,release}/`, so they only
69+
// materialise when the binary runs from inside the repo.
70+
// Shipped `.app`s launched from `/Applications/` hit the
71+
// `.exists()` guard and silently skip — no need for a
72+
// `cfg(debug_assertions)` gate. Keeping these live in release
73+
// lets a raw `Target/release/<name>` launch find the same 98
74+
// built-in extensions a debug build does.
75+
//
76+
// Sky Target path: where CopyVSCodeAssets copies built-in
77+
// extensions during the Sky build.
78+
let SkyTargetPath = Parent.join("../../../Sky/Target/Static/Application/extensions");
79+
if SkyTargetPath.exists() {
80+
dev_log!(
81+
"extensions",
82+
"[Extensions] [ScanPaths] + {} (Sky Target, repo-layout)",
83+
SkyTargetPath.display()
84+
);
85+
ScanPathsGuard.push(SkyTargetPath);
86+
}
8487

85-
// VS Code dependency path: built-in extensions from the VS
86-
// Code source checkout — avoids requiring a copy step in dev.
87-
let DependencyPath = Parent.join("../../../../Dependency/Microsoft/Dependency/Editor/extensions");
88-
if DependencyPath.exists() {
89-
dev_log!(
90-
"extensions",
91-
"[Extensions] [ScanPaths] + {} (VS Code Dependency, dev)",
92-
DependencyPath.display()
93-
);
94-
ScanPathsGuard.push(DependencyPath);
95-
}
88+
// VS Code dependency path: built-in extensions from the VS
89+
// Code source checkout — avoids requiring a copy step.
90+
let DependencyPath =
91+
Parent.join("../../../../Dependency/Microsoft/Dependency/Editor/extensions");
92+
if DependencyPath.exists() {
93+
dev_log!(
94+
"extensions",
95+
"[Extensions] [ScanPaths] + {} (VS Code Dependency, repo-layout)",
96+
DependencyPath.display()
97+
);
98+
ScanPathsGuard.push(DependencyPath);
9699
}
97100
}
98101
}

Source/Binary/Main/AppLifecycle.rs

Lines changed: 38 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -376,19 +376,47 @@ pub fn AppLifecycleSetup(
376376
.Lifecycle
377377
.AdvanceAndBroadcast(2, &PostSetupAppHandle);
378378

379-
// Schedule a background transition to Restored (3) after a short
380-
// settle delay — matches VS Code's behaviour of deferring non-
381-
// critical UI restoration (workbench layout, webview panels,
382-
// recent-files list) until the main editor is interactive. A
383-
// second transition to Eventually (4) follows so late-binding
384-
// extensions know to stop blocking on "ready".
379+
// Schedule a background transition to Restored (3), then Eventually
380+
// (4). Sky/Wind are the authoritative signal — they call
381+
// `lifecycle:advancePhase` over Tauri IPC when the workbench is
382+
// truly interactive (`Restored`) and when late-binding extensions
383+
// should stop blocking (`Eventually`). `AdvanceAndBroadcast`
384+
// rejects backwards/same-phase advances (LifecyclePhaseState.rs:53),
385+
// so the timers below are pure fallbacks: if Sky has already driven
386+
// the phase, these become no-ops and log nothing visible.
387+
//
388+
// The windows are deliberately generous — a debug-electron cold
389+
// boot with 98 extensions has been observed to finish its
390+
// `$activateByEvent("*")` burst at ~3.5 s on an M4 mini and
391+
// noticeably later on older hardware. The previous 2 s / 5 s
392+
// timings ran the risk of flipping Restored while the burst was
393+
// still in flight, which prematurely unblocked services gated on
394+
// "the editor is interactive". 8 s / 15 s keeps a safety margin
395+
// without visibly delaying late-binding extensions that legitimately
396+
// need Eventually to fire.
385397
let LifecycleStateClone = AppStateForSetup.Feature.Lifecycle.clone();
386398
let AppHandleForPhase = PostSetupAppHandle.clone();
387399
tauri::async_runtime::spawn(async move {
388-
tokio::time::sleep(tokio::time::Duration::from_millis(2_000)).await;
389-
LifecycleStateClone.AdvanceAndBroadcast(3, &AppHandleForPhase);
390-
tokio::time::sleep(tokio::time::Duration::from_millis(5_000)).await;
391-
LifecycleStateClone.AdvanceAndBroadcast(4, &AppHandleForPhase);
400+
tokio::time::sleep(tokio::time::Duration::from_millis(8_000)).await;
401+
if LifecycleStateClone.GetPhase() < 3 {
402+
dev_log!(
403+
"lifecycle",
404+
"[Lifecycle] [Fallback] Sky did not advance to Restored within 8s; Mountain \
405+
auto-advancing (current phase={})",
406+
LifecycleStateClone.GetPhase()
407+
);
408+
LifecycleStateClone.AdvanceAndBroadcast(3, &AppHandleForPhase);
409+
}
410+
tokio::time::sleep(tokio::time::Duration::from_millis(15_000)).await;
411+
if LifecycleStateClone.GetPhase() < 4 {
412+
dev_log!(
413+
"lifecycle",
414+
"[Lifecycle] [Fallback] Sky did not advance to Eventually within 23s total; \
415+
Mountain auto-advancing (current phase={})",
416+
LifecycleStateClone.GetPhase()
417+
);
418+
LifecycleStateClone.AdvanceAndBroadcast(4, &AppHandleForPhase);
419+
}
392420
});
393421

394422
crate::otel_span!("lifecycle:postsetup:complete", PostSetupStart);

Source/Environment/TerminalProvider.rs

Lines changed: 24 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -277,15 +277,36 @@ impl TerminalProvider for MountainEnvironment {
277277

278278
let TermIDForExit = TerminalIdentifier;
279279

280+
// BATCH-19 Part B: capture the PID before `ChildProcess` is moved into
281+
// the exit-watcher task so the exit log line can correlate with the
282+
// spawn log (`[TerminalProvider] localPty:spawn OK id=N pid=M`). Also
283+
// surface the actual exit status code — previously discarded via
284+
// `let _exit_status = …`, which meant the log could only say "has
285+
// exited" without distinguishing a clean `exit 0`, `echo hi; exit`
286+
// flow from a crash. That distinction is what the BATCH-19 smoke test
287+
// needs to confirm the shell really ran and returned.
288+
let PidForExit = ChildProcess.process_id();
289+
280290
let EnvironmentClone = self.clone();
281291

282292
tokio::spawn(async move {
283-
let _exit_status = ChildProcess.wait();
293+
let ExitStatus = ChildProcess.wait();
294+
295+
// portable-pty's `Child::wait()` returns `io::Result<ExitStatus>`.
296+
// `{:?}` on ExitStatus shows `success` and any captured code
297+
// without needing to commit to a specific accessor name (the
298+
// crate's exit-status API has varied across versions).
299+
let StatusSummary = match &ExitStatus {
300+
Ok(Code) => format!("exited {:?}", Code),
301+
Err(Error) => format!("wait failed: {}", Error),
302+
};
284303

285304
dev_log!(
286305
"terminal",
287-
"[TerminalProvider] Process for terminal ID {} has exited.",
288-
TermIDForExit
306+
"[TerminalProvider] Process for terminal ID {} pid={:?} {}",
307+
TermIDForExit,
308+
PidForExit,
309+
StatusSummary
289310
);
290311

291312
let IPCProvider:Arc<dyn IPCProvider> = EnvironmentClone.Require();

Source/IPC/DevLog.rs

Lines changed: 78 additions & 62 deletions
Original file line numberDiff line numberDiff line change
@@ -140,63 +140,35 @@ fn ResolveLogDirectory() -> PathBuf {
140140
Base.join(Stamp)
141141
}
142142

143-
fn FormatTimestamp() -> String {
143+
/// Session timestamp in local time, cached once per process. MUST match
144+
/// whatever `WindServiceHandlers.rs::"nativeHost:getEnvironmentPaths"`
145+
/// builds, because VS Code's file service writes `window1/output/*.log`
146+
/// into the directory that handler returns — if DevLog and VS Code use
147+
/// different timezones, `Mountain.dev.log` and the `window1/` subtree
148+
/// land in two sibling directories 2–3 hours apart, which makes every
149+
/// post-mortem investigation start with "which folder has the real
150+
/// log?". Picking `chrono::Local::now()` matches the VS Code convention
151+
/// (Tauri's tauri-plugin-log also writes local-time `YYYYMMDDTHHMMSS`).
152+
///
153+
/// The format string is deliberately identical to the handler's
154+
/// `"%Y%m%dT%H%M%S"`, and both sides pull from the same OnceLock via
155+
/// `SessionTimestamp()` so re-entrant calls from anywhere in the
156+
/// codebase produce the same string.
157+
pub fn SessionTimestamp() -> String {
144158
static STAMP:OnceLock<String> = OnceLock::new();
145159
STAMP
146-
.get_or_init(|| {
147-
let Duration = SystemTime::now().duration_since(std::time::UNIX_EPOCH).unwrap_or_default();
148-
let Secs = Duration.as_secs() as i64;
149-
// Minimal UTC breakdown without pulling chrono into DevLog: the
150-
// Tauri plugin format is `YYYYMMDDTHHMMSS`, which is easy to build
151-
// manually from the epoch.
152-
let Days = Secs / 86_400;
153-
let SecondsOfDay = (Secs % 86_400) as u32;
154-
let Hour = SecondsOfDay / 3_600;
155-
let Minute = (SecondsOfDay % 3_600) / 60;
156-
let Second = SecondsOfDay % 60;
157-
let (Year, Month, Day) = DaysToYMD(Days);
158-
format!("{:04}{:02}{:02}T{:02}{:02}{:02}", Year, Month, Day, Hour, Minute, Second)
159-
})
160+
.get_or_init(|| chrono::Local::now().format("%Y%m%dT%H%M%S").to_string())
160161
.clone()
161162
}
162163

163-
/// Convert days-since-epoch to (year, month, day). Vendored here to avoid
164-
/// dragging chrono into the dev-log hot path.
165-
fn DaysToYMD(Days:i64) -> (i64, u32, u32) {
166-
let mut Year = 1970_i64;
167-
let mut Remaining = Days;
168-
loop {
169-
let YearLen = if IsLeap(Year) { 366 } else { 365 };
170-
if Remaining < YearLen as i64 {
171-
break;
172-
}
173-
Remaining -= YearLen as i64;
174-
Year += 1;
175-
}
176-
let MonthLengths = [
177-
31u32,
178-
if IsLeap(Year) { 29 } else { 28 },
179-
31,
180-
30,
181-
31,
182-
30,
183-
31,
184-
31,
185-
30,
186-
31,
187-
30,
188-
31,
189-
];
190-
let mut Month = 0_usize;
191-
let mut Day = Remaining as u32;
192-
while Month < 12 && Day >= MonthLengths[Month] {
193-
Day -= MonthLengths[Month];
194-
Month += 1;
195-
}
196-
(Year, (Month as u32) + 1, Day + 1)
197-
}
164+
fn FormatTimestamp() -> String { SessionTimestamp() }
198165

199-
fn IsLeap(Year:i64) -> bool { (Year % 4 == 0 && Year % 100 != 0) || Year % 400 == 0 }
166+
// `DaysToYMD` + `IsLeap` were previously used to build a UTC timestamp
167+
// string without pulling chrono into DevLog. Replaced by
168+
// `chrono::Local::now()` in `SessionTimestamp()` so this file agrees
169+
// with `WindServiceHandlers.rs::"nativeHost:getEnvironmentPaths"` on
170+
// the session-log directory. chrono is already a Mountain dependency,
171+
// so the vendored date math is dead weight now.
200172

201173
/// Initialise the file sink on first call. Silently falls through to a
202174
/// disabled sink if the directory or file can't be created — the caller
@@ -258,21 +230,65 @@ pub fn WriteToFile(Line:&str) {
258230
// The app-data directory name is absurdly long. In short mode, alias it.
259231
static APP_DATA_PREFIX:OnceLock<Option<String>> = OnceLock::new();
260232

233+
/// Produce an identity signature for THIS running binary derived from
234+
/// `CARGO_PKG_NAME` (which Maintain sets to the long PascalCase product
235+
/// name before `cargo build`). Each profile produces a distinct signature
236+
/// — `_Debug_Mountain` → `.debug.mountain`, `_Compile_Mountain` →
237+
/// `.compile.mountain`, `_Bundle_Clean_Debug_ElectronProfile_Mountain`
238+
/// → `.debug.electron.profile.mountain` — so a candidate directory in
239+
/// `~/Library/Application Support/` can be disambiguated against every
240+
/// other `land.editor.*.mountain` leftover from prior runs.
241+
///
242+
/// Only the last three underscore-delimited segments are used: the
243+
/// leading `DevelopmentNodeEnvironment_MicrosoftVSCodeDependency_
244+
/// 22NodeVersion_Bundle_Clean` prefix is identical across profiles and
245+
/// doesn't help disambiguate, while the tail (`Debug_Mountain` vs
246+
/// `Compile_Mountain` vs `Debug_ElectronProfile_Mountain`) is where the
247+
/// per-profile identity lives.
248+
fn BinarySignature() -> String {
249+
let PackageName = env!("CARGO_PKG_NAME");
250+
let Segments:Vec<&str> = PackageName.split('_').collect();
251+
let Take = Segments.len().min(4);
252+
let Start = Segments.len().saturating_sub(Take);
253+
let Tail = Segments[Start..].join("_");
254+
// Lowercase + `_` → `.` gives the same segment order the Tauri
255+
// identifier uses (identifiers are dot-delimited lowercase). We
256+
// don't split PascalCase into words here — the substring match
257+
// below doesn't need exact equality, just a unique tail.
258+
Tail.to_ascii_lowercase().replace('_', ".")
259+
}
260+
261261
fn DetectAppDataPrefix() -> Option<String> {
262-
// Match the bundle identifier pattern used by Mountain
263-
if let Ok(Home) = std::env::var("HOME") {
264-
let Base = format!("{}/Library/Application Support", Home);
265-
if let Ok(Entries) = std::fs::read_dir(&Base) {
266-
for Entry in Entries.flatten() {
267-
let Name = Entry.file_name();
268-
let Name = Name.to_string_lossy();
269-
if Name.starts_with("land.editor.") && Name.contains("mountain") {
270-
return Some(format!("{}/{}", Base, Name));
271-
}
262+
let Home = std::env::var("HOME").ok()?;
263+
let Base = format!("{}/Library/Application Support", Home);
264+
let Signature = BinarySignature();
265+
266+
// Prefer a directory whose name ends with this binary's unique tail
267+
// signature: that's the app-data directory Tauri created for THIS
268+
// profile. Without this check, a user who has ever launched another
269+
// profile (debug-electron, release-electron, …) will see DevLog
270+
// writing into that stale directory while userdata still goes into
271+
// the current one, producing an "empty logs folder" mystery.
272+
let mut FirstMatchingMountain:Option<String> = None;
273+
if let Ok(Entries) = std::fs::read_dir(&Base) {
274+
for Entry in Entries.flatten() {
275+
let Name = Entry.file_name();
276+
let Name = Name.to_string_lossy().into_owned();
277+
if !Name.starts_with("land.editor.") || !Name.contains("mountain") {
278+
continue;
279+
}
280+
// Strict match: binary signature tail is a suffix of the dir name.
281+
if Name.ends_with(&Signature) {
282+
return Some(format!("{}/{}", Base, Name));
283+
}
284+
// Lossy match: some segment of the binary signature is contained
285+
// in the dir name. Used only if no strict match exists.
286+
if FirstMatchingMountain.is_none() {
287+
FirstMatchingMountain = Some(format!("{}/{}", Base, Name));
272288
}
273289
}
274290
}
275-
None
291+
FirstMatchingMountain
276292
}
277293

278294
/// Get the app-data path prefix for aliasing (cached).

0 commit comments

Comments
 (0)