Skip to content

Commit aeb205a

Browse files
sonquersonquer
committed
Add tracing, stream controls, and TLS EOF handling
Bump workspace version to 0.1.25 and update Cargo.lock. Add Readable.resume(), pause(), and isPaused() to the Node stream polyfill so buffered data is replayed and pause state can be queried. Add tracing instrumentation across the V8 ESM loader and ops bridge (HTTP, process, zlib) to improve observability and log lifecycle events and errors. Treat UnexpectedEof from TLS reads as a clean EOF with a debug log to avoid spurious warnings.
1 parent f4636b7 commit aeb205a

6 files changed

Lines changed: 143 additions & 7 deletions

File tree

‎Cargo.lock‎

Lines changed: 3 additions & 3 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎Cargo.toml‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@ members = [
77
]
88

99
[workspace.package]
10-
version = "0.1.24"
10+
version = "0.1.25"
1111
edition = "2024"
1212
license = "MIT OR Apache-2.0"
1313
publish = false

‎crates/nexide/runtime/polyfills/node/stream.js‎

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,28 @@ class Readable extends EventEmitter {
5656
if (this._buffer.length === 0) return null;
5757
return this._buffer.shift();
5858
}
59+
resume() {
60+
if (this._destroyed) return this;
61+
this._paused = false;
62+
if (this._buffer.length) {
63+
const replay = this._buffer.slice();
64+
this._buffer = [];
65+
queueMicrotask(() => {
66+
for (const chunk of replay) this.emit("data", chunk);
67+
if (this._ended) this.emit("end");
68+
});
69+
} else if (this._ended) {
70+
queueMicrotask(() => this.emit("end"));
71+
}
72+
return this;
73+
}
74+
pause() {
75+
this._paused = true;
76+
return this;
77+
}
78+
isPaused() {
79+
return this._paused === true;
80+
}
5981
pipe(dest) {
6082
if (this._buffer.length) {
6183
const replay = this._buffer.slice();

‎crates/nexide/src/engine/v8_engine/esm.rs‎

Lines changed: 53 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -114,7 +114,15 @@ fn load_and_evaluate_esm<'s>(
114114
scope: &mut v8::PinScope<'s, '_>,
115115
abs_path: &Path,
116116
) -> Result<v8::Local<'s, v8::Value>, String> {
117-
let module = load_esm_graph(scope, abs_path).map_err(|e| e.to_string())?;
117+
let module = load_esm_graph(scope, abs_path).map_err(|e| {
118+
tracing::warn!(
119+
target: LOG_TARGET,
120+
path = %abs_path.display(),
121+
error = %e,
122+
"esm graph load failed",
123+
);
124+
e.to_string()
125+
})?;
118126
let namespace_after_eval = |scope: &mut v8::PinScope<'s, '_>,
119127
module: v8::Local<'s, v8::Module>| {
120128
if matches!(module.get_status(), v8::ModuleStatus::Errored) {
@@ -128,10 +136,20 @@ fn load_and_evaluate_esm<'s>(
128136
module.get_status(),
129137
v8::ModuleStatus::Evaluated | v8::ModuleStatus::Errored
130138
) {
139+
tracing::trace!(
140+
target: LOG_TARGET,
141+
path = %abs_path.display(),
142+
"esm module already evaluated, returning namespace",
143+
);
131144
return namespace_after_eval(scope, module);
132145
}
133146

134147
if matches!(module.get_status(), v8::ModuleStatus::Uninstantiated) {
148+
tracing::debug!(
149+
target: LOG_TARGET,
150+
path = %abs_path.display(),
151+
"instantiating esm module",
152+
);
135153
v8::tc_scope!(let tc, scope);
136154
let ok = module
137155
.instantiate_module(tc, resolve_module_callback)
@@ -141,10 +159,21 @@ fn load_and_evaluate_esm<'s>(
141159
.exception()
142160
.map(|e| value_to_string(tc, e))
143161
.unwrap_or_else(|| format!("instantiate failed for {}", abs_path.display()));
162+
tracing::warn!(
163+
target: LOG_TARGET,
164+
path = %abs_path.display(),
165+
error = %exc,
166+
"esm module instantiate failed",
167+
);
144168
return Err(exc);
145169
}
146170
}
147171

172+
tracing::debug!(
173+
target: LOG_TARGET,
174+
path = %abs_path.display(),
175+
"evaluating esm module",
176+
);
148177
let eval_value = {
149178
v8::tc_scope!(let tc, scope);
150179
match module.evaluate(tc) {
@@ -156,18 +185,39 @@ fn load_and_evaluate_esm<'s>(
156185
.unwrap_or_else(|| {
157186
format!("evaluate returned none for {}", abs_path.display())
158187
});
188+
tracing::warn!(
189+
target: LOG_TARGET,
190+
path = %abs_path.display(),
191+
error = %exc,
192+
"esm module evaluate threw synchronously",
193+
);
159194
return Err(exc);
160195
}
161196
}
162197
};
163198

164199
if matches!(module.get_status(), v8::ModuleStatus::Errored) {
165200
let exc = module.get_exception();
166-
return Err(value_to_string(scope, exc));
201+
let msg = value_to_string(scope, exc);
202+
tracing::warn!(
203+
target: LOG_TARGET,
204+
path = %abs_path.display(),
205+
error = %msg,
206+
"esm module entered errored state after evaluate",
207+
);
208+
return Err(msg);
167209
}
168210

169211
let namespace = module.get_module_namespace();
170-
chain_namespace_after(scope, eval_value, namespace).map_err(|e| e.to_string())
212+
chain_namespace_after(scope, eval_value, namespace).map_err(|e| {
213+
tracing::warn!(
214+
target: LOG_TARGET,
215+
path = %abs_path.display(),
216+
error = %e,
217+
"esm namespace chaining failed",
218+
);
219+
e.to_string()
220+
})
171221
}
172222

173223
/// Calls `globalThis.__nexideEsm.chain(evalPromise, namespace)` to

‎crates/nexide/src/engine/v8_engine/ops_bridge.rs‎

Lines changed: 56 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3222,6 +3222,8 @@ fn op_tls_close<'s>(
32223222

32233223
use crate::ops::{HttpHeader, HttpRequest, http_request};
32243224

3225+
const HTTP_BRIDGE_TARGET: &str = "nexide::engine::bridge::http";
3226+
32253227
/// Reads `{ method, url, headers: [[name, value], ...], body: Uint8Array? }`
32263228
/// from the JS argument, fires the request asynchronously, and resolves
32273229
/// with `{ status, statusText, headers: [[name, value], ...], bodyId }`.
@@ -3259,6 +3261,13 @@ fn op_http_request<'s>(
32593261
let status = response.status;
32603262
let status_text = response.status_text;
32613263
let headers = response.headers;
3264+
tracing::debug!(
3265+
target: HTTP_BRIDGE_TARGET,
3266+
body_id = id,
3267+
status,
3268+
headers = headers.len(),
3269+
"http response slot allocated",
3270+
);
32623271
Box::new(move |scope, resolver| {
32633272
let obj = v8::Object::new(scope);
32643273
let status_key = v8::String::new(scope, "status").unwrap();
@@ -3335,6 +3344,13 @@ fn op_http_response_close<'s>(
33353344
let body_id = args.get(0).uint32_value(scope).unwrap_or(0);
33363345
let handle = from_isolate(scope);
33373346
let removed = handle.0.borrow().http_responses.remove(body_id);
3347+
if removed {
3348+
tracing::debug!(
3349+
target: HTTP_BRIDGE_TARGET,
3350+
body_id,
3351+
"http response slot released",
3352+
);
3353+
}
33383354
let result = v8::Boolean::new(scope, removed);
33393355
rv.set(result.into());
33403356
}
@@ -3462,6 +3478,8 @@ fn bytes_to_uint8_array<'s>(
34623478
// ──────────────────────────────────────────────────────────────────────
34633479

34643480
use super::bridge::ChildSlot;
3481+
3482+
const PROC_BRIDGE_TARGET: &str = "nexide::engine::bridge::process";
34653483
use crate::ops::{
34663484
ExitInfo, SpawnRequest, StdioMode, proc_kill, proc_read_pipe, proc_spawn, proc_wait,
34673485
proc_write_pipe,
@@ -3513,6 +3531,15 @@ fn op_proc_spawn<'s>(
35133531
let has_stdout = slot.stdout.try_lock().is_ok_and(|g| g.is_some());
35143532
let has_stderr = slot.stderr.try_lock().is_ok_and(|g| g.is_some());
35153533
let id = table.insert(slot);
3534+
tracing::debug!(
3535+
target: PROC_BRIDGE_TARGET,
3536+
child_id = id,
3537+
pid = child_handle.pid,
3538+
stdin = has_stdin,
3539+
stdout = has_stdout,
3540+
stderr = has_stderr,
3541+
"child process slot allocated",
3542+
);
35163543
let obj = v8::Object::new(scope);
35173544
let id_key = v8::String::new(scope, "id").unwrap();
35183545
let id_val = v8::Number::new(scope, f64::from(id));
@@ -3745,6 +3772,13 @@ fn op_proc_close<'s>(
37453772
let id = args.get(0).uint32_value(scope).unwrap_or(0);
37463773
let handle = from_isolate(scope);
37473774
let removed = handle.0.borrow().child_processes.remove(id);
3775+
if removed {
3776+
tracing::debug!(
3777+
target: PROC_BRIDGE_TARGET,
3778+
child_id = id,
3779+
"child process slot released",
3780+
);
3781+
}
37483782
rv.set(v8::Boolean::new(scope, removed).into());
37493783
}
37503784

@@ -3924,6 +3958,8 @@ fn set_bool_field<'s>(
39243958

39253959
use crate::ops::{ZlibStream, parse_zlib_kind};
39263960

3961+
const ZLIB_BRIDGE_TARGET: &str = "nexide::engine::bridge::zlib";
3962+
39273963
/// Creates a streaming zlib state machine. `kind` is the kebab-case
39283964
/// identifier (`"deflate"`, `"gunzip"`, …) and `level` is the zlib
39293965
/// compression level (0..=9, ignored for decoders).
@@ -3940,9 +3976,22 @@ fn op_zlib_create<'s>(
39403976
let handle = from_isolate(scope);
39413977
let table = handle.0.borrow().zlib_streams.clone();
39423978
let id = table.insert(std::rc::Rc::new(std::cell::RefCell::new(Some(stream))));
3979+
tracing::debug!(
3980+
target: ZLIB_BRIDGE_TARGET,
3981+
stream_id = id,
3982+
kind = %kind_str,
3983+
level,
3984+
"zlib stream slot allocated",
3985+
);
39433986
rv.set(v8::Number::new(scope, f64::from(id)).into());
39443987
}
39453988
Err(err) => {
3989+
tracing::warn!(
3990+
target: ZLIB_BRIDGE_TARGET,
3991+
kind = %kind_str,
3992+
code = err.code,
3993+
"zlib stream create rejected",
3994+
);
39463995
let exc = make_node_error(scope, &err);
39473996
scope.throw_exception(exc);
39483997
}
@@ -4030,6 +4079,13 @@ fn op_zlib_close<'s>(
40304079
let id = args.get(0).uint32_value(scope).unwrap_or(0);
40314080
let handle = from_isolate(scope);
40324081
let removed = handle.0.borrow().zlib_streams.remove(id);
4082+
if removed {
4083+
tracing::debug!(
4084+
target: ZLIB_BRIDGE_TARGET,
4085+
stream_id = id,
4086+
"zlib stream slot released",
4087+
);
4088+
}
40334089
rv.set(v8::Boolean::new(scope, removed).into());
40344090
}
40354091

‎crates/nexide/src/ops/tls.rs‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -150,6 +150,14 @@ pub async fn read_chunk(
150150
}
151151
Ok(buf)
152152
}
153+
Err(e) if e.kind() == io::ErrorKind::UnexpectedEof => {
154+
tracing::debug!(
155+
target: LOG_TARGET,
156+
error = %e,
157+
"tls peer closed without close_notify; treating as clean eof",
158+
);
159+
Ok(Vec::new())
160+
}
153161
Err(e) => {
154162
let mapped = tls_error(&e);
155163
tracing::warn!(

0 commit comments

Comments
 (0)