jdwp_client/eventloop.rs
1// JDWP Event Loop
2//
3// Handles concurrent reading of events and replies from JDWP socket
4
5use crate::events::{parse_event_packet, EventSet};
6use crate::protocol::{CommandPacket, JdwpError, JdwpResult, ReplyPacket, HEADER_SIZE, REPLY_FLAG};
7use std::collections::HashMap;
8use std::sync::Arc;
9use tokio::io::{AsyncReadExt, AsyncWriteExt};
10use tokio::net::tcp::{OwnedReadHalf, OwnedWriteHalf};
11use tokio::sync::{mpsc, oneshot};
12use tracing::{debug, error, info, warn};
13
14/// Maximum allowed JDWP packet size (10MB)
15/// This prevents memory exhaustion from malicious or buggy JVMs
16const MAX_PACKET_SIZE: usize = 10 * 1024 * 1024;
17
18/// Maximum time to wait for a command reply before considering it lost
19const REPLY_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(30);
20
21/// Request to send a command and get reply
22pub struct CommandRequest {
23 pub packet: CommandPacket,
24 pub reply_tx: oneshot::Sender<JdwpResult<ReplyPacket>>,
25}
26
27/// Handle to the event loop for sending commands and receiving events.
28///
29/// This handle can be cloned to send commands from multiple tasks, but only ONE clone
30/// should call `recv_event()` or `try_recv_event()` at a time. The event receiver is
31/// wrapped in an `Arc<Mutex<Receiver>>` which allows sharing, but concurrent event
32/// consumption from multiple tasks will lead to unpredictable behavior (events distributed
33/// round-robin across consumers).
34///
35/// # Thread Safety
36/// - Commands can be sent concurrently from multiple clones
37/// - Events should be consumed from a single task/clone
38///
39/// # Example
40/// ```no_run
41/// # use jdwp_client::EventLoopHandle;
42/// # use jdwp_client::protocol::CommandPacket;
43/// # async fn demo(event_loop: EventLoopHandle, cmd1: CommandPacket, cmd2: CommandPacket) {
44/// // Good: Single event consumer
45/// let handle1 = event_loop.clone();
46/// let handle2 = event_loop.clone();
47///
48/// // Both can send commands
49/// let _ = handle1.send_command(cmd1).await;
50/// let _ = handle2.send_command(cmd2).await;
51///
52/// // Only one should consume events
53/// while let Some(event) = handle1.recv_event().await {
54/// // Process event
55/// }
56/// # }
57/// ```
58#[derive(Clone, Debug)]
59pub struct EventLoopHandle {
60 command_tx: mpsc::Sender<CommandRequest>,
61 event_rx: Arc<tokio::sync::Mutex<mpsc::Receiver<EventSet>>>,
62 /// Why the loop stopped, written once by the loop as it exits and readable by every clone of this
63 /// handle — including the ones that arrive afterwards.
64 ///
65 /// Without it, a caller that shows up after the loop is gone can only be told *that* it is gone,
66 /// which is the same message a healthy-but-slow session would produce if anything ever went wrong
67 /// there. The loop knows the reason; this is how the reason outlives it.
68 shutdown: Arc<std::sync::OnceLock<String>>,
69}
70
71impl EventLoopHandle {
72 /// Send a command and wait for reply
73 ///
74 /// # Errors
75 /// Returns a [`JdwpError`] if the event loop has shut down or the reply is lost before it arrives.
76 /// Both cases name the reason the loop stopped when it recorded one.
77 pub async fn send_command(&self, packet: CommandPacket) -> JdwpResult<ReplyPacket> {
78 self.issue(packet).await?.reply().await
79 }
80
81 /// Hand a command to the loop and return as soon as it is queued — **without** waiting for its reply.
82 ///
83 /// This is the half of [`send_command`](Self::send_command) that PERF-1
84 /// ([#100](https://github.com/YgorPerez/java-debugging-mcp/issues/100)) needed, and adding it changes
85 /// nothing underneath: the loop already writes a command and returns without awaiting its answer, and
86 /// already correlates replies by packet id. The serialisation was in the *shape of the only way to
87 /// ask* — one call that issued and awaited — not in the transport. See [`InFlight`].
88 ///
89 /// # Errors
90 /// Returns a [`JdwpError`] if the event loop has shut down before the command could be queued. Note
91 /// what this does **not** promise: the command has been handed over, not written. It is written when
92 /// the loop next reaches `handle_outgoing_command`, and a write failure is reported to
93 /// [`InFlight::reply`] rather than here.
94 pub async fn issue(&self, packet: CommandPacket) -> JdwpResult<InFlight> {
95 let (reply_tx, reply_rx) = oneshot::channel();
96 let id = packet.id;
97
98 let request = CommandRequest { packet, reply_tx };
99
100 self.command_tx.send(request).await.map_err(|_| self.lost("the command was never sent"))?;
101
102 Ok(InFlight { id, reply_rx, shutdown: Arc::clone(&self.shutdown) })
103 }
104
105 /// See [`lost`].
106 fn lost(&self, what: &str) -> JdwpError {
107 lost(&self.shutdown, what)
108 }
109
110 /// Try to receive an event (non-blocking)
111 pub async fn try_recv_event(&self) -> Option<EventSet> {
112 let mut rx = self.event_rx.lock().await;
113 rx.try_recv().ok()
114 }
115
116 /// Wait for the next event (blocking)
117 pub async fn recv_event(&self) -> Option<EventSet> {
118 let mut rx = self.event_rx.lock().await;
119 rx.recv().await
120 }
121}
122
123/// A command that has been handed to the loop and not yet answered.
124///
125/// **Issue order is write order, and neither is completion order.** The loop dequeues commands FIFO and
126/// writes them in that order, so a command issued first reaches the JVM first. Nothing says the JVM
127/// answers in that order — JDWP's own words are that the protocol *"is asynchronous; multiple command
128/// packets may be sent before the first reply packet is received"*, matched by an id that *"must be
129/// unique among all outstanding commands sent from one source"*. So this type carries its [`id`](Self::id):
130/// correlation is the claim being made, and ADR-0038 asserts it rather than assuming it.
131///
132/// **Dropping one is safe, and that is a property of ADR-0018 rather than of this type.** Abandoning the
133/// wait does not abandon the command: the JVM still answers it, the reader task still consumes the whole
134/// packet, and `route_reply` finds the pending entry and discards the reply because nobody is listening.
135/// Framing cannot be lost that way, because framing does not live on this side of the channel. What
136/// dropping *does* cost is the work the JVM already did, which is why nothing here abandons a sibling on
137/// the strength of another's failure — see [`JdwpConnection::read_independently`](
138/// crate::JdwpConnection::read_independently).
139#[must_use = "an issued command is on its way to the debuggee; dropping this discards its reply"]
140pub struct InFlight {
141 id: u32,
142 reply_rx: oneshot::Receiver<JdwpResult<ReplyPacket>>,
143 /// A clone of the loop's shutdown cell, so a reply that never arrives can be explained by the same
144 /// mechanism [`EventLoopHandle::lost`] uses — including after the handle that issued it is gone.
145 shutdown: Arc<std::sync::OnceLock<String>>,
146}
147
148impl InFlight {
149 /// The packet id this command was sent with, and the id its reply must carry.
150 #[must_use]
151 pub const fn id(&self) -> u32 {
152 self.id
153 }
154
155 /// Wait for this command's reply.
156 ///
157 /// # Errors
158 /// Returns a [`JdwpError`] if the reply is lost before it arrives — a write failure, a lapsed
159 /// `REPLY_TIMEOUT`, or the loop shutting down — naming the reason the loop stopped when it
160 /// recorded one.
161 pub async fn reply(self) -> JdwpResult<ReplyPacket> {
162 let Self { reply_rx, shutdown, .. } = self;
163 reply_rx.await.map_err(|_| lost(&shutdown, "the command was sent and its reply was dropped"))?
164 }
165}
166
167/// The error for a command that will never be answered, naming the reason the loop stopped.
168///
169/// Both ways a command dies arrive here — one whose reply channel was dropped as the loop exited,
170/// and one sent after it had already gone — because both are the same fact about the debuggee and
171/// deserve the same words. `what` says how far this one got, since "sent" and "never sent" differ.
172///
173/// The `None` arm should be unreachable: `event_loop_task` records its cause before anything it owns
174/// can drop. It is worded as the anomaly it would be rather than as a plausible-looking default,
175/// because a reassuring message on an impossible branch is how the original defect read.
176fn lost(shutdown: &std::sync::OnceLock<String>, what: &str) -> JdwpError {
177 shutdown.get().map_or_else(
178 || JdwpError::Protocol(format!("the event loop stopped without recording a reason, and {what}")),
179 |cause| JdwpError::ConnectionClosed(cause.clone()),
180 )
181}
182
183/// Start the event loop task
184#[must_use]
185pub fn spawn_event_loop(reader: OwnedReadHalf, writer: OwnedWriteHalf) -> EventLoopHandle {
186 let (command_tx, command_rx) = mpsc::channel(32);
187 // Use larger buffer for events to avoid loss under load
188 // Events are critical (breakpoints, exceptions) and shouldn't be dropped
189 let (event_tx, event_rx) = mpsc::channel(256);
190 let shutdown = Arc::new(std::sync::OnceLock::new());
191
192 tokio::spawn(event_loop_task(reader, writer, command_rx, event_tx, Arc::clone(&shutdown)));
193
194 EventLoopHandle { command_tx, event_rx: Arc::new(tokio::sync::Mutex::new(event_rx)), shutdown }
195}
196
197/// Pending reply with timestamp for timeout tracking
198struct PendingReply {
199 sender: oneshot::Sender<JdwpResult<ReplyPacket>>,
200 sent_at: tokio::time::Instant,
201}
202
203/// How many whole packets the reader may run ahead of the loop (TEST-24, #65).
204///
205/// Small on purpose. Its job is to move the *read* out of `select!`, not to buffer traffic, and a packet
206/// may be up to `MAX_PACKET_SIZE` — so a generous channel is a generous memory bound for nothing. When it
207/// fills, the reader waits, which is the same serialisation the single-task version had and is not a
208/// deadlock: the loop returns to `select!` after every branch and keeps draining.
209const PACKET_CHANNEL_DEPTH: usize = 8;
210
211/// Own the socket's read half in a task of its own, forwarding whole packets over a channel.
212///
213/// **This exists because `read_exact` is not cancel safe, and the event loop is a `select!`.** tokio
214/// documents it: *"if the method is used as a branch in `tokio::select!` and another branch completes
215/// first, then some data may already have been read into buf"* — and that data is then gone. Reading a
216/// packet takes two `read_exact` calls, so any command sent, or any cleanup tick, while a packet was
217/// partly read **discarded the bytes already consumed**. JDWP has no frame delimiter, so the stream never
218/// recovers: the next read starts mid-payload and interprets whatever it finds as a header.
219///
220/// That is the whole of TEST-24 (#65). Its fingerprint was a length field of `1701737519`, which is the
221/// ASCII text `ent/` — a fragment of a package name, read from inside a class signature in the middle of
222/// an `AllClasses` reply. Those replies are the biggest this client ever receives, which is why
223/// `list_classes` is where it kept surfacing, and why it needed a busy session to reproduce: the payload
224/// read spans many polls, so the cancellation window is at its widest exactly there.
225///
226/// A dedicated task cannot be cancelled by another branch, and `Receiver::recv` — which replaces it in the
227/// `select!` — **is** cancel safe.
228fn spawn_packet_reader(mut reader: OwnedReadHalf) -> mpsc::Receiver<JdwpResult<(bool, u32, Vec<u8>)>> {
229 let (tx, rx) = mpsc::channel(PACKET_CHANNEL_DEPTH);
230 tokio::spawn(async move {
231 loop {
232 let result = read_packet(&mut reader).await;
233 let fatal = result.is_err();
234 // A closed channel means the loop is gone; there is nobody to read for.
235 if tx.send(result).await.is_err() {
236 break;
237 }
238 // One error ends the stream: alignment is lost or the socket is dead, and reading on would
239 // manufacture more garbage from the same broken stream.
240 if fatal {
241 break;
242 }
243 }
244 });
245 rx
246}
247
248/// Main event loop task
249async fn event_loop_task(
250 reader: OwnedReadHalf,
251 mut writer: OwnedWriteHalf,
252 mut command_rx: mpsc::Receiver<CommandRequest>,
253 event_tx: mpsc::Sender<EventSet>,
254 shutdown: Arc<std::sync::OnceLock<String>>,
255) {
256 info!("Event loop started");
257
258 let mut pending_replies: HashMap<u32, PendingReply> = HashMap::new();
259 let mut cleanup_interval = tokio::time::interval(tokio::time::Duration::from_secs(10));
260 // Reading happens in its own task so `select!` can never cancel it mid-packet (#65).
261 let mut packets = spawn_packet_reader(reader);
262
263 let cause = loop {
264 tokio::select! {
265 // Handle outgoing commands
266 Some(cmd) = command_rx.recv() => {
267 handle_outgoing_command(&mut writer, &mut pending_replies, cmd).await;
268 }
269
270 // Periodic cleanup of timed-out pending replies
271 _ = cleanup_interval.tick() => {
272 cleanup_pending_replies(&mut pending_replies);
273 }
274
275 // Handle incoming packets. `recv()` is cancel safe, which is the point of the reader task.
276 received = packets.recv() => {
277 match received {
278 Some(result) => {
279 if let Some(cause) = handle_incoming_packet(&mut pending_replies, &event_tx, result) {
280 break cause;
281 }
282 }
283 // The reader task ended without sending a final error, which it is written not to do.
284 // Reported as the anomaly it would be rather than as a plausible-looking default.
285 None => break "the packet reader stopped without reporting a reason".to_string(),
286 }
287 }
288 }
289 };
290
291 info!("Event loop shutting down: {}", cause);
292 // Recorded *before* `pending_replies` drops, which is what makes the drop legible. Dropping a
293 // `oneshot` sender wakes its caller with no payload — that is the whole of the old
294 // `Reply channel closed` — so the cause is published here and rendered by
295 // [`EventLoopHandle::lost`], which is also the only thing a caller arriving later can consult.
296 // One mechanism serves both, so there is no second notification pass to keep in step with it.
297 let _ = shutdown.set(cause);
298 drop(pending_replies);
299}
300
301/// Encode and write an outgoing command, then track it for reply routing.
302///
303/// On a write/flush error the waiting caller is notified and the command is dropped
304/// (equivalent to skipping this loop iteration); otherwise it is inserted into `pending_replies`.
305async fn handle_outgoing_command(
306 writer: &mut OwnedWriteHalf,
307 pending_replies: &mut HashMap<u32, PendingReply>,
308 cmd: CommandRequest,
309) {
310 let packet_id = cmd.packet.id;
311 debug!("Sending command id={}", packet_id);
312
313 let encoded = cmd.packet.encode();
314 if let Err(e) = writer.write_all(&encoded).await {
315 error!("Failed to write command: {}", e);
316 cmd.reply_tx.send(Err(JdwpError::Io(e))).ok();
317 return;
318 }
319
320 if let Err(e) = writer.flush().await {
321 error!("Failed to flush command: {}", e);
322 cmd.reply_tx.send(Err(JdwpError::Io(e))).ok();
323 return;
324 }
325
326 pending_replies
327 .insert(packet_id, PendingReply { sender: cmd.reply_tx, sent_at: tokio::time::Instant::now() });
328}
329
330/// Abandon any pending replies that have exceeded [`REPLY_TIMEOUT`], telling each one so.
331///
332/// This used to drop the sender and rely on that to wake the caller. It did wake them — with
333/// `Reply channel closed`, the same words a dead socket produced, which is how a JVM that simply never
334/// answered came to look like a transport failure. The connection is still open here, and
335/// [`JdwpError::ReplyTimeout`] says which of the two this is.
336fn cleanup_pending_replies(pending_replies: &mut HashMap<u32, PendingReply>) {
337 let now = tokio::time::Instant::now();
338 let before_count = pending_replies.len();
339
340 // Identified first, then removed — `retain` would drop each sender as it returned `false`, which is
341 // exactly the payload-less wake this function exists to stop doing.
342 let lapsed: Vec<(u32, tokio::time::Duration)> = pending_replies
343 .iter()
344 .map(|(id, pending)| (*id, now.duration_since(pending.sent_at)))
345 .filter(|(_, elapsed)| *elapsed > REPLY_TIMEOUT)
346 .collect();
347
348 for (packet_id, elapsed) in lapsed {
349 warn!("Command {} timed out after {:?}, removing from pending replies", packet_id, elapsed);
350 if let Some(pending) = pending_replies.remove(&packet_id) {
351 pending.sender.send(Err(JdwpError::ReplyTimeout(REPLY_TIMEOUT.as_secs()))).ok();
352 }
353 }
354
355 let removed = before_count - pending_replies.len();
356 if removed > 0 {
357 warn!("Cleaned up {} timed-out pending replies", removed);
358 }
359}
360
361/// Handle the result of reading a packet from the socket.
362///
363/// Returns `Some(cause)` when the event loop should stop — a fatal read error, or the event receiver
364/// having been dropped — and `None` to keep looping. The cause is a value rather than a log line
365/// because the callers waiting on this loop cannot read logs, and by default nothing enables them: the
366/// `error!` below is emitted by `jdwp_client`, which the server's filter only turns on at `warn` and a
367/// library consumer may not turn on at all.
368fn handle_incoming_packet(
369 pending_replies: &mut HashMap<u32, PendingReply>,
370 event_tx: &mpsc::Sender<EventSet>,
371 result: JdwpResult<(bool, u32, Vec<u8>)>,
372) -> Option<String> {
373 match result {
374 Ok((is_reply, packet_id, data)) => {
375 if is_reply {
376 route_reply(pending_replies, packet_id, &data);
377 None
378 } else {
379 handle_event_packet(event_tx, &data)
380 }
381 }
382 Err(e) => {
383 error!("Failed to read packet: {}", e);
384 // `e` is the diagnosis — an EOF means the debuggee went away, a reset means it was killed,
385 // and a size violation means the peer is not speaking JDWP. Discarding it here is what made
386 // the whole class of failure unattributable.
387 Some(format!("reading from the debuggee failed: {e}"))
388 }
389 }
390}
391
392/// Route a decoded reply to the command awaiting it, if any.
393fn route_reply(pending_replies: &mut HashMap<u32, PendingReply>, packet_id: u32, data: &[u8]) {
394 debug!("Received reply id={}", packet_id);
395
396 if let Some(pending) = pending_replies.remove(&packet_id) {
397 match ReplyPacket::decode(data) {
398 Ok(reply) => {
399 pending.sender.send(Ok(reply)).ok();
400 }
401 Err(e) => {
402 warn!("Failed to decode reply: {}", e);
403 pending.sender.send(Err(e)).ok();
404 }
405 }
406 } else {
407 warn!("Received reply for unknown command id={} (may have timed out)", packet_id);
408 }
409}
410
411/// Parse an event packet and broadcast it to the event consumer.
412///
413/// Uses non-blocking [`try_send`](mpsc::Sender::try_send) to avoid deadlocking against a
414/// consumer that is concurrently sending commands; a full channel drops the event.
415/// Returns `Some(cause)` when the event receiver has been dropped and the loop should stop.
416fn handle_event_packet(event_tx: &mpsc::Sender<EventSet>, data: &[u8]) -> Option<String> {
417 debug!("Received event packet, len={}", data.len());
418
419 // Event packets have command_set and command in header
420 // Data starts after the 11-byte header (read_packet guarantees the
421 // buffer is at least that long; fall back to empty if not).
422 let event_data = data.get(HEADER_SIZE..).unwrap_or(&[]);
423
424 match parse_event_packet(event_data) {
425 Ok(event_set) => {
426 info!(
427 "Parsed event set: {} events, suspend_policy={}",
428 event_set.events.len(),
429 event_set.suspend_policy
430 );
431
432 // Send event without blocking to avoid deadlock
433 // If consumer is sending commands while we're reading, blocking here would deadlock
434 match event_tx.try_send(event_set) {
435 Ok(()) => None,
436 Err(mpsc::error::TrySendError::Full(dropped_event)) => {
437 // Event channel is full - this is critical
438 error!("Event channel full ({} buffered), dropping event with {} events. Consumer not keeping up!",
439 event_tx.capacity(), dropped_event.events.len());
440 // TODO: Consider adding backpressure or alerting mechanism
441 None
442 }
443 Err(mpsc::error::TrySendError::Closed(_)) => {
444 info!("Event receiver dropped, shutting down event loop");
445 Some("the event consumer was dropped, so the session was torn down".to_string())
446 }
447 }
448 }
449 Err(e) => {
450 warn!("Failed to parse event: {}", e);
451 None
452 }
453 }
454}
455
456/// How many bytes of a non-JDWP stream to quote in the error (TEST-24, #65).
457///
458/// Four bytes cannot identify a speaker — `ent/` is a fragment of a package name, an HTTP header and a
459/// filesystem path alike — and the first sighting of this failure spent an entire investigation on exactly
460/// that ambiguity. Sixty-four is enough for an HTTP request line, a TLS `ClientHello` record header, or a
461/// recognisable run of a Java class signature, and still short enough to read in one line of log.
462const FOREIGN_BYTES_QUOTED: usize = 64;
463
464/// How long to spend collecting those bytes.
465///
466/// Deliberately short and deliberately best-effort. The connection is already unusable, so this is buying
467/// evidence, not function — and a peer that sent four bytes and stopped must not turn a clear error into a
468/// hang. Whatever has arrived by the deadline is what gets quoted, and the reply says how much that was.
469const FOREIGN_BYTES_DEADLINE: std::time::Duration = std::time::Duration::from_millis(250);
470
471/// Build the payload for [`JdwpError::NotJdwpFramed`]: what was wrong, and what was actually on the wire.
472///
473/// Reads a little further on purpose. The stream is finished either way — nothing downstream can resynchronise
474/// a JDWP connection once alignment is lost — so the only remaining value in the socket is the identity of
475/// whatever is talking, and that is worth 250ms to capture.
476async fn describe_foreign_bytes(reader: &mut OwnedReadHalf, header: &[u8], why: &str) -> String {
477 let mut seen = header.to_vec();
478 // Plain `read` rather than `read_exact`, and `read` is also the cancel-safe one — a short stream is
479 // the expected case here, not an error. Appending straight onto `seen` keeps every slice in bounds.
480 while seen.len() < FOREIGN_BYTES_QUOTED {
481 let mut chunk = [0u8; 32];
482 let want = (FOREIGN_BYTES_QUOTED - seen.len()).min(chunk.len());
483 let Some(into) = chunk.get_mut(..want) else { break };
484 match tokio::time::timeout(FOREIGN_BYTES_DEADLINE, reader.read(into)).await {
485 // Nothing more is coming, or nothing more arrived in time: quote what we have.
486 Ok(Ok(0) | Err(_)) | Err(_) => break,
487 Ok(Ok(n)) => seen.extend_from_slice(chunk.get(..n).unwrap_or_default()),
488 }
489 }
490
491 let hex = seen.iter().map(|b| format!("{b:02x}")).collect::<Vec<_>>().join(" ");
492 let text: String =
493 seen.iter().map(|&b| if (0x20..0x7f).contains(&b) { b as char } else { '.' }).collect();
494
495 // The decoded length field, when it is printable — the detail that turns "1701737519 bytes" into
496 // "the four bytes are the text `ent/`", which is what says foreign traffic rather than a huge reply.
497 let len_bytes = header.get(..4).unwrap_or_default();
498 let as_text = if len_bytes.iter().all(|&b| (0x20..0x7f).contains(&b)) {
499 format!(
500 " The length field's four bytes are the printable text {:?}, so this is text, not a size.",
501 String::from_utf8_lossy(len_bytes)
502 )
503 } else {
504 String::new()
505 };
506
507 format!(
508 "{why}.{as_text} {} byte(s) read at the header position: hex [{hex}] text \"{text}\". \
509 The connection cannot be resynchronised — JDWP has no frame delimiter to seek to — so the session \
510 ends here. If the text names a protocol or a path, something other than this JVM's JDWP agent is \
511 on that socket.",
512 seen.len()
513 )
514}
515
516/// Read a packet from the socket and determine if it's a reply or event
517async fn read_packet(reader: &mut OwnedReadHalf) -> JdwpResult<(bool, u32, Vec<u8>)> {
518 // Read header into a fixed-size buffer (constant-index access, no bounds risk).
519 let mut header = [0u8; HEADER_SIZE];
520
521 reader.read_exact(&mut header).await.map_err(JdwpError::Io)?;
522
523 // Parse header
524 let length = u32::from_be_bytes([header[0], header[1], header[2], header[3]]) as usize;
525 let packet_id = u32::from_be_bytes([header[4], header[5], header[6], header[7]]);
526 let flags = header[8];
527
528 // Validate the header on three INDEPENDENT grounds before trusting `length` (TEST-24, #65).
529 //
530 // The flags check is the one that was missing, and it is the cheapest of the three: JDWP defines
531 // exactly two values, `0` for a command and `0x80` for a reply. Any other byte means this is not a
532 // header, and it catches foreign traffic whose length field happens to land inside the 11..10MiB
533 // window — which the size checks alone never would.
534 let flags_are_jdwp = flags == 0 || flags == REPLY_FLAG;
535 let length_is_sane = (HEADER_SIZE..=MAX_PACKET_SIZE).contains(&length);
536 if !flags_are_jdwp || !length_is_sane {
537 let why = if !flags_are_jdwp {
538 format!("flags byte is {flags:#04x}, and JDWP defines only 0x00 (command) and 0x80 (reply)")
539 } else if length < HEADER_SIZE {
540 format!("length field is {length}, below the {HEADER_SIZE}-byte header it must include")
541 } else {
542 format!("length field is {length}, above the {MAX_PACKET_SIZE}-byte cap")
543 };
544 return Err(JdwpError::NotJdwpFramed(describe_foreign_bytes(reader, &header, &why).await));
545 }
546
547 // Read rest of packet
548 let data_len = length - HEADER_SIZE;
549 let mut full_packet = header.to_vec();
550
551 if data_len > 0 {
552 let mut data = vec![0u8; data_len];
553 reader.read_exact(&mut data).await.map_err(JdwpError::Io)?;
554 full_packet.extend_from_slice(&data);
555 }
556
557 let is_reply = flags == REPLY_FLAG;
558
559 Ok((is_reply, packet_id, full_packet))
560}
561
562#[cfg(test)]
563mod tests {
564 use super::*;
565 use crate::protocol::CommandPacket;
566
567 /// An event loop talking to a peer that reads commands, never answers them, and hangs up on cue.
568 ///
569 /// Needs no JVM and no handshake: [`spawn_event_loop`] is handed an already-handshaked socket by
570 /// [`crate::connection`], so a bare TCP peer reproduces the state exactly. What it manufactures is
571 /// the one condition CI hit and this box never did — a debuggee whose connection dies with a command
572 /// in flight.
573 struct HangingUpPeer {
574 handle: EventLoopHandle,
575 /// Fires once the peer has read a command it is never going to answer, so a test can hang up at
576 /// the one moment that exercises the in-flight path rather than racing it.
577 read: oneshot::Receiver<()>,
578 hangup: oneshot::Sender<()>,
579 }
580
581 async fn hanging_up_peer() -> HangingUpPeer {
582 let listener = tokio::net::TcpListener::bind("127.0.0.1:0").await.expect("bind a loopback port");
583 let addr = listener.local_addr().expect("read back the bound address");
584 let (read_tx, read) = oneshot::channel();
585 let (hangup, mut hangup_rx) = oneshot::channel();
586
587 tokio::spawn(async move {
588 let (mut socket, _) = listener.accept().await.expect("accept the event loop's connection");
589 let mut buf = vec![0u8; 1024];
590 let mut announced = Some(read_tx);
591 loop {
592 tokio::select! {
593 result = socket.read(&mut buf) => match result {
594 Ok(0) | Err(_) => break,
595 Ok(_) => if let Some(tx) = announced.take() { let _ = tx.send(()); },
596 },
597 _ = &mut hangup_rx => break,
598 }
599 }
600 // Dropping the socket is the hang-up: our side's `read_packet` sees EOF.
601 drop(socket);
602 });
603
604 let stream = tokio::net::TcpStream::connect(addr).await.expect("connect to the peer");
605 let (reader, writer) = stream.into_split();
606 HangingUpPeer { handle: spawn_event_loop(reader, writer), read, hangup }
607 }
608
609 /// The regression behind an unattributable CI flake: a command in flight when the debuggee's
610 /// connection died reported `Reply channel closed`, which said nothing about the debuggee at all.
611 ///
612 /// The assertion is on the *cause*, not on "it returned an error" — the old code also returned an
613 /// error, and that is precisely why nobody could tell a dead JVM from a bug in this crate.
614 #[tokio::test]
615 async fn a_command_in_flight_when_the_debuggee_hangs_up_is_told_why() {
616 let peer = hanging_up_peer().await;
617 let handle = peer.handle.clone();
618 let in_flight = tokio::spawn(async move { handle.send_command(CommandPacket::new(1, 1, 1)).await });
619
620 // Hang up only once the command is provably registered as pending, so this test cannot pass by
621 // way of the "arrived after the loop was gone" path, which is a different branch.
622 peer.read.await.expect("the peer should have read the command");
623 peer.hangup.send(()).expect("the peer should still be listening for the hang-up");
624
625 let err = in_flight.await.expect("the command task should not panic").expect_err(
626 "a command whose connection died cannot succeed — the peer never sent a reply packet",
627 );
628 let JdwpError::ConnectionClosed(cause) = &err else {
629 panic!("expected ConnectionClosed carrying the reason, got {err:?}");
630 };
631 assert!(
632 cause.contains("reading from the debuggee failed"),
633 "the cause must name what happened to the connection, not just that it ended: {cause}"
634 );
635 }
636
637 /// A peer that sends `bytes` and then stays connected — foreign traffic on a JDWP socket.
638 ///
639 /// Stays connected on purpose: hanging up would make EOF the explanation and hide the framing failure
640 /// behind a plausible one, which is the substitution this whole class of bug keeps making.
641 async fn garbage_peer(bytes: &'static [u8]) -> EventLoopHandle {
642 let listener = tokio::net::TcpListener::bind("127.0.0.1:0").await.expect("bind a loopback port");
643 let addr = listener.local_addr().expect("read back the bound address");
644 tokio::spawn(async move {
645 let (mut socket, _) = listener.accept().await.expect("accept the event loop's connection");
646 let _ = socket.write_all(bytes).await;
647 let _ = socket.flush().await;
648 // Hold the socket open so the failure cannot be read as a hang-up.
649 tokio::time::sleep(std::time::Duration::from_secs(30)).await;
650 });
651 let stream = tokio::net::TcpStream::connect(addr).await.expect("connect to the peer");
652 let (reader, writer) = stream.into_split();
653 spawn_event_loop(reader, writer)
654 }
655
656 /// TEST-24 (#65): the exact CI fingerprint — a length field that is really ASCII text — must be
657 /// reported as text on the wire, not as an enormous packet.
658 ///
659 /// The bytes are the ones the release gate actually produced: `0x656e742f`, announced at the time as
660 /// `Packet too large: 1701737519 bytes`. That sentence sent the reader looking for a 1.7GB reply. The
661 /// four bytes are `ent/` — a fragment of a package name, an HTTP path, or a header — and *that* is the
662 /// fact worth printing.
663 #[tokio::test]
664 async fn a_length_field_that_is_really_text_says_so_instead_of_claiming_a_huge_packet() {
665 let handle = garbage_peer(b"ent/management/RuntimeMXBean;junk padding to fill the quote").await;
666 let err = handle
667 .send_command(CommandPacket::new(1, 1, 1))
668 .await
669 .expect_err("a stream that is not JDWP-framed cannot answer a command");
670 let JdwpError::ConnectionClosed(cause) = &err else {
671 panic!("expected ConnectionClosed carrying the reason, got {err:?}");
672 };
673 assert!(
674 cause.contains("not JDWP-framed"),
675 "the failure must name the framing, which is what is actually wrong: {cause}"
676 );
677 assert!(
678 cause.contains("printable text") && cause.contains("ent/"),
679 "the decoded length field is the whole insight — 1701737519 tells nobody anything: {cause}"
680 );
681 assert!(
682 !cause.contains("Packet too large"),
683 "reporting this as a large packet is the misdiagnosis being fixed: {cause}"
684 );
685 // The bytes themselves, so the *speaker* can be identified rather than guessed at.
686 assert!(cause.contains("hex ["), "the raw bytes must be quoted: {cause}");
687 assert!(
688 cause.contains("management/"),
689 "quoting only 4 bytes is what made the first sighting ambiguous; the run has to be long \
690 enough to recognise: {cause}"
691 );
692 }
693
694 /// TEST-24 (#65): the check that did not exist — a flags byte JDWP never uses.
695 ///
696 /// This is the case the two size checks can never catch: a length field that lands inside
697 /// `11..=10MiB` looks perfectly plausible, so foreign traffic passes both and is then parsed as a
698 /// packet. JDWP defines exactly two flag values, which makes this the cheapest possible detector.
699 #[tokio::test]
700 async fn a_flags_byte_jdwp_never_uses_is_caught_even_when_the_length_looks_plausible() {
701 // length = 32 (plausible), id = 1, flags = 'A' — neither 0x00 nor 0x80.
702 let bytes: &'static [u8] = b"\x00\x00\x00\x20\x00\x00\x00\x01AGET / HTTP/1.1\r\nHost: x\r\n\r\n";
703 let handle = garbage_peer(bytes).await;
704 let err = handle
705 .send_command(CommandPacket::new(1, 1, 1))
706 .await
707 .expect_err("a stream whose flags byte is not JDWP cannot answer a command");
708 let JdwpError::ConnectionClosed(cause) = &err else {
709 panic!("expected ConnectionClosed carrying the reason, got {err:?}");
710 };
711 assert!(
712 cause.contains("flags byte is 0x41"),
713 "the flags value is the finding here, and it must be named: {cause}"
714 );
715 assert!(
716 cause.contains("0x00 (command)") && cause.contains("0x80 (reply)"),
717 "say what JDWP does allow, so the reader can tell foreign traffic from a version skew: {cause}"
718 );
719 }
720
721 // Probe: same peer, but give the loop time to read BEFORE any command is sent.
722 /// A peer that answers one command with a reply delivered in **two chunks**, so the payload read is
723 /// provably in flight during the gap.
724 ///
725 /// The gap is the experiment: it is when a second command gets sent, and under the old single-task
726 /// `select!` that command cancelled the half-finished `read_exact` and threw away everything already
727 /// consumed.
728 async fn chunked_reply_peer(payload: Vec<u8>) -> (EventLoopHandle, oneshot::Sender<()>) {
729 let listener = tokio::net::TcpListener::bind("127.0.0.1:0").await.expect("bind a loopback port");
730 let addr = listener.local_addr().expect("read back the bound address");
731 let (finish, finish_rx) = oneshot::channel();
732 tokio::spawn(async move {
733 let (mut socket, _) = listener.accept().await.expect("accept the event loop's connection");
734 let mut cmd = [0u8; HEADER_SIZE];
735 socket.read_exact(&mut cmd).await.expect("read the first command's header");
736 let id = u32::from_be_bytes([cmd[4], cmd[5], cmd[6], cmd[7]]);
737
738 // Reply header + error code, then only the first byte of the payload.
739 // The 2-byte error code lives INSIDE JDWP's 11-byte header, so it must not be counted twice.
740 let total = u32::try_from(HEADER_SIZE + payload.len()).expect("reply fits in u32");
741 let mut head = Vec::new();
742 head.extend_from_slice(&total.to_be_bytes());
743 head.extend_from_slice(&id.to_be_bytes());
744 head.push(REPLY_FLAG);
745 head.extend_from_slice(&0u16.to_be_bytes());
746 head.extend_from_slice(&payload[..1]);
747 socket.write_all(&head).await.expect("write the first chunk");
748 socket.flush().await.expect("flush the first chunk");
749
750 // Hold the rest back until the test has sent the second command.
751 let _ = finish_rx.await;
752 socket.write_all(&payload[1..]).await.expect("write the second chunk");
753 socket.flush().await.expect("flush the second chunk");
754 tokio::time::sleep(std::time::Duration::from_secs(10)).await;
755 });
756 let stream = tokio::net::TcpStream::connect(addr).await.expect("connect to the peer");
757 let (reader, writer) = stream.into_split();
758 (spawn_event_loop(reader, writer), finish)
759 }
760
761 /// TEST-24 (#65), the root cause: a command sent while a packet is half-read must not eat the bytes
762 /// already consumed.
763 ///
764 /// `read_exact` is **not cancel safe** — tokio says so — and `read_packet` calls it twice. While it was
765 /// a `select!` branch, any command or cleanup tick arriving mid-packet dropped the future and discarded
766 /// everything it had read. JDWP has no frame delimiter, so the stream never realigns: the next read
767 /// starts inside the old payload and reads whatever it finds there as a header. That is where #65's
768 /// `1701737519` came from — ASCII `ent/`, a fragment of a package name inside an `AllClasses` reply,
769 /// which is both the largest reply this client receives and the one that kept failing.
770 ///
771 /// The payload is padded well past one read so the cancellation window is real rather than notional.
772 #[tokio::test]
773 async fn a_command_sent_mid_packet_does_not_desynchronise_the_stream() {
774 let payload: Vec<u8> = (0..8192u32).map(|i| u8::try_from(i % 251).unwrap_or(0)).collect();
775 let (handle, finish) = chunked_reply_peer(payload.clone()).await;
776
777 let first = tokio::spawn({
778 let h = handle.clone();
779 async move { h.send_command(CommandPacket::new(1, 1, 1)).await }
780 });
781
782 // Let the first command go out and its reply start arriving, so the read is genuinely in flight.
783 tokio::time::sleep(std::time::Duration::from_millis(150)).await;
784
785 // THE cancellation trigger. Under the old code this dropped the in-flight `read_exact`.
786 let second = tokio::spawn({
787 let h = handle.clone();
788 async move { h.send_command(CommandPacket::new(2, 1, 1)).await }
789 });
790 tokio::time::sleep(std::time::Duration::from_millis(150)).await;
791 finish.send(()).expect("the peer should still be waiting to send the rest");
792
793 let reply = first
794 .await
795 .expect("the first command's task should not panic")
796 .expect("the first reply must arrive intact — a cancelled read would have desynchronised here");
797 assert_eq!(
798 reply.data(),
799 &payload[..],
800 "the reply payload must be byte-identical; a short or shifted payload is the desync this test exists for"
801 );
802
803 second.abort();
804 }
805
806 /// The second half: the reason has to outlive the loop that discovered it.
807 ///
808 /// A session does not stop being asked questions the moment its debuggee dies — the MCP layer has a
809 /// queue of them. Each used to get `Event loop shut down`, which reads as an internal fault rather
810 /// than as the debuggee having gone away.
811 #[tokio::test]
812 async fn a_question_asked_after_the_debuggee_hung_up_still_names_the_cause() {
813 let peer = hanging_up_peer().await;
814 let handle = peer.handle.clone();
815 let in_flight = tokio::spawn(async move { handle.send_command(CommandPacket::new(1, 1, 1)).await });
816 peer.read.await.expect("the peer should have read the command");
817 peer.hangup.send(()).expect("the peer should still be listening for the hang-up");
818 let _ = in_flight.await.expect("the command task should not panic");
819
820 // The loop has now recorded its cause and exited. Ask again.
821 let err = peer
822 .handle
823 .send_command(CommandPacket::new(2, 1, 1))
824 .await
825 .expect_err("the connection is gone; nothing can answer this");
826 let JdwpError::ConnectionClosed(cause) = &err else {
827 panic!("expected ConnectionClosed carrying the reason, got {err:?}");
828 };
829 assert!(
830 cause.contains("reading from the debuggee failed"),
831 "a later caller must get the same diagnosis as the first: {cause}"
832 );
833 }
834
835 /// A JVM that stays connected and simply never answers is a different fault from one that hung up,
836 /// and used to be reported with the same words.
837 ///
838 /// Time is paused rather than waited out: the real budget is [`REPLY_TIMEOUT`] (30s), which is worth
839 /// asserting on and not worth spending. `cleanup_pending_replies` is called directly because it is
840 /// the whole mechanism — the loop's only other job here is to tick it.
841 #[tokio::test(start_paused = true)]
842 async fn a_reply_that_never_arrives_is_reported_as_a_lapsed_reply_not_a_dead_connection() {
843 let mut pending = HashMap::new();
844 let (sender, receiver) = oneshot::channel();
845 pending.insert(7, PendingReply { sender, sent_at: tokio::time::Instant::now() });
846
847 // Not yet due: a cleanup pass before the budget must leave the command alone, or a slow-but-fine
848 // debuggee would be abandoned mid-question. Halved rather than "budget minus a second" because
849 // subtracting from a `Duration` is the underflow this repo already got bitten by once.
850 tokio::time::advance(REPLY_TIMEOUT / 2).await;
851 cleanup_pending_replies(&mut pending);
852 assert_eq!(pending.len(), 1, "abandoned a command that still had time left");
853
854 tokio::time::advance(REPLY_TIMEOUT).await;
855 cleanup_pending_replies(&mut pending);
856 assert!(pending.is_empty(), "a lapsed command must be dropped from the pending map");
857
858 let err = receiver
859 .await
860 .expect("the lapsed command must be told, not left to a dropped sender")
861 .expect_err("a lapsed reply is not a success");
862 assert!(
863 matches!(err, JdwpError::ReplyTimeout(secs) if secs == REPLY_TIMEOUT.as_secs()),
864 "expected ReplyTimeout naming the budget, got {err:?}"
865 );
866 }
867}