diff --git a/packages/app-lib/src/state/process.rs b/packages/app-lib/src/state/process.rs index 8c6f2bb..86056b8 100644 --- a/packages/app-lib/src/state/process.rs +++ b/packages/app-lib/src/state/process.rs @@ -616,220 +616,62 @@ impl Process { let mut buf_reader = BufReader::new(reader); if xml_logging { - let mut reader = Reader::from_reader(buf_reader); - reader.config_mut().enable_all_checks(false); - - let mut buf = Vec::new(); - let mut current_event = Log4jEvent::default(); - let mut in_event = false; - let mut in_message = false; - let mut in_throwable = false; - let mut current_content = String::new(); + // NOTE: we deliberately do NOT use quick-xml's streaming async reader + // here. Its parser marks itself `ParseState::Done` permanently after + // any I/O/parse error or a transient `Eof` (see quick-xml #513), so a + // single split XML frame on the live pipe would silently kill all + // further log forwarding — which is exactly the "logs stop after the + // client finished starting" bug. + // + // Instead we accumulate raw bytes into a buffer and cut out complete + // `…` frames, parsing each frame in one + // synchronous pass. Malformed or partial frames are skipped without + // poisoning the stream, so forwarding always continues. + let mut pending = String::new(); + let mut chunk = [0u8; 8192]; loop { - match reader.read_event_into_async(&mut buf).await { + let read = match tokio::io::AsyncReadExt::read(&mut buf_reader, &mut chunk).await { + Ok(0) => break, + Ok(n) => n, Err(e) => { - tracing::error!( - "Error at position {}: {:?}", - reader.buffer_position(), - e - ); + tracing::warn!("Live log read error: {e}"); break; } - // exits the loop when reaching end of file - Ok(Event::Eof) => break, + }; - Ok(Event::Start(e)) => { - match e.name().as_ref() { - b"log4j:Event" => { - // Reset for new event - current_event = Log4jEvent::default(); - in_event = true; + pending.push_str(&String::from_utf8_lossy(&chunk[..read])); - // Extract attributes - for attr in e.attributes().flatten() { - let key = String::from_utf8_lossy( - attr.key.into_inner(), - ) - .to_string(); - let value = - String::from_utf8_lossy(&attr.value) - .to_string(); - - match key.as_str() { - "logger" => { - current_event.logger_name = - Some(value) - } - "level" => { - current_event.level = Some(value) - } - "thread" => { - current_event.thread_name = - Some(value) - } - "timestamp" => { - current_event.timestamp_millis = - value.parse::().ok() - } - _ => {} - } - } - } - b"log4j:Message" => { - in_message = true; - current_content = String::new(); - } - b"log4j:Throwable" => { - in_throwable = true; - current_content = String::new(); - } - _ => {} - } - } - Ok(Event::End(e)) => { - match e.name().as_ref() { - b"log4j:Message" => { - in_message = false; - current_event.message = - Some(current_content.clone()); - } - b"log4j:Throwable" => { - in_throwable = false; - current_event.throwable = - if current_content.is_empty() { - None - } else { - Some(current_content.clone()) - }; - - // Write log entry + throwable to file - if let Some(formatted_log) = - Self::format_log4j_entry(¤t_event) - { - if let Err(e) = Process::append_to_log_file( - &log_path, - &formatted_log, - ) { - tracing::error!( - "Failed to write to log file: {}", - e - ); - } - - if let Some(ref throwable) = - current_event.throwable - && let Err(e) = - Process::append_to_log_file( - &log_path, throwable, - ) - { - tracing::error!( - "Failed to write throwable to log file: {}", - e - ); - } - } - - Self::emit_log4j_event( - instance_id, - ¤t_event, - ); - } - b"log4j:Event" => { - in_event = false; - // If no throwable was present, write the log entry at the end of the event - if current_event.message.is_some() - && current_event.throwable.is_none() - { - if let Some(formatted_log) = - Self::format_log4j_entry(¤t_event) - && let Err(e) = - Process::append_to_log_file( - &log_path, - &formatted_log, - ) - { - tracing::error!( - "Failed to write to log file: {}", - e - ); - } - - if let Some(timestamp_millis) = - current_event.timestamp_millis - { - let timestamp = - timestamp_millis.to_string(); - let message = current_event - .message - .as_deref() - .unwrap_or("") - .trim(); - crate::api::multiplayer::observe_minecraft_log( - instance_id, - instance_name, - process_id, - message, - ) - .await; - if let Err(e) = Self::maybe_handle_server_join_logging( - instance_id, - ×tamp, - message, - ).await { - tracing::error!("Failed to handle server join logging: {e}"); - } - } - - Self::emit_log4j_event( - instance_id, - ¤t_event, - ); - } - } - _ => {} - } - } - Ok(Event::Text(mut e)) => { - if in_message || in_throwable { - if let Ok(text) = e.xml_content() { - append_bounded_log4j_content( - &mut current_content, - &text, - ); - } - } else if !in_event - && !e.inplace_trim_end() - && !e.inplace_trim_start() - && let Ok(text) = e.xml_content() - { - if let Err(e) = Process::append_to_log_file( - &log_path, - &format!("{text}\n"), - ) { - tracing::error!( - "Failed to write to log file: {}", - e - ); - } - Self::emit_legacy_log(instance_id, &text); - } - } - Ok(Event::CData(e)) => { - if (in_message || in_throwable) - && let Ok(text) = e.xml_content() - { - append_bounded_log4j_content( - &mut current_content, - &text, - ); - } - } - _ => (), + // Drain every complete frame currently buffered. + while let Some(frame) = take_next_log4j_frame(&mut pending) { + Self::handle_log4j_frame( + instance_id, + instance_name, + process_id, + &log_path, + &frame, + ) + .await; } - buf.clear(); + // Guard against a runaway buffer if no frame delimiters ever + // appear (e.g. raw non-XML output on a logging-configured + // instance). Flush it as legacy text so it is not lost. + if pending.len() > MAX_PERSISTED_LOG_LINE_BYTES { + let text = std::mem::take(&mut pending); + if let Err(e) = Self::append_to_log_file(&log_path, &text) { + tracing::warn!("Failed to write to log file: {e}"); + } + Self::emit_legacy_log(instance_id, text.trim_end()); + } + } + + // Flush any trailing partial content on stream end. + if !pending.trim().is_empty() { + if let Err(e) = Self::append_to_log_file(&log_path, &pending) { + tracing::warn!("Failed to write to log file: {e}"); + } + Self::emit_legacy_log(instance_id, pending.trim_end()); } } else { while let Ok(Some(line)) = @@ -862,6 +704,164 @@ impl Process { } } + /// Parses one complete `…` frame and forwards + /// its content to the log file / frontend. A frame that fails to parse is + /// logged and dropped; it never stops the reader loop. + async fn handle_log4j_frame( + instance_id: &str, + instance_name: &str, + process_id: &str, + log_path: &Path, + frame: &str, + ) { + let mut reader = Reader::from_str(frame); + reader.config_mut().enable_all_checks(false); + + let mut current_event = Log4jEvent::default(); + let mut in_message = false; + let mut in_throwable = false; + let mut current_content = String::new(); + + let mut buf = Vec::new(); + loop { + match reader.read_event_into(&mut buf) { + Err(e) => { + tracing::warn!("Malformed live log frame: {e}"); + break; + } + Ok(Event::Eof) => break, + Ok(Event::Start(e)) => match e.name().as_ref() { + b"log4j:Event" => { + current_event = Log4jEvent::default(); + for attr in e.attributes().flatten() { + let key = + String::from_utf8_lossy(attr.key.into_inner()) + .to_string(); + let value = String::from_utf8_lossy(&attr.value) + .to_string(); + match key.as_str() { + "logger" => { + current_event.logger_name = Some(value) + } + "level" => current_event.level = Some(value), + "thread" => { + current_event.thread_name = Some(value) + } + "timestamp" => { + current_event.timestamp_millis = + value.parse::().ok() + } + _ => {} + } + } + } + b"log4j:Message" => { + in_message = true; + current_content = String::new(); + } + b"log4j:Throwable" => { + in_throwable = true; + current_content = String::new(); + } + _ => {} + }, + Ok(Event::End(e)) => match e.name().as_ref() { + b"log4j:Message" => { + in_message = false; + current_event.message = Some(current_content.clone()); + } + b"log4j:Throwable" => { + in_throwable = false; + current_event.throwable = + if current_content.is_empty() { + None + } else { + Some(current_content.clone()) + }; + } + b"log4j:Event" => { + if let Some(formatted) = + Self::format_log4j_entry(¤t_event) + { + if let Err(e) = + Self::append_to_log_file(log_path, &formatted) + { + tracing::error!( + "Failed to write to log file: {e}" + ); + } + if let Some(ref throwable) = current_event.throwable + && let Err(e) = Self::append_to_log_file( + log_path, + throwable, + ) + { + tracing::error!( + "Failed to write throwable to log file: {e}" + ); + } + + if let Some(timestamp_millis) = + current_event.timestamp_millis + { + let timestamp = timestamp_millis.to_string(); + let message = current_event + .message + .as_deref() + .unwrap_or("") + .trim(); + crate::api::multiplayer::observe_minecraft_log( + instance_id, + instance_name, + process_id, + message, + ) + .await; + if let Err(e) = + Self::maybe_handle_server_join_logging( + instance_id, + ×tamp, + message, + ) + .await + { + tracing::error!( + "Failed to handle server join logging: {e}" + ); + } + } + + Self::emit_log4j_event(instance_id, ¤t_event); + } + } + _ => {} + }, + Ok(Event::Text(e)) => { + if (in_message || in_throwable) + && let Ok(text) = e.xml_content() + { + append_bounded_log4j_content( + &mut current_content, + &text, + ); + } + } + Ok(Event::CData(e)) => { + if (in_message || in_throwable) + && let Ok(text) = e.xml_content() + { + append_bounded_log4j_content( + &mut current_content, + &text, + ); + } + } + _ => (), + } + buf.clear(); + } + } + fn format_timestamp(timestamp_millis: Option) -> String { if let Some(timestamp_val) = timestamp_millis { let datetime_utc = if timestamp_val > i32::MAX as i64 { @@ -1267,7 +1267,28 @@ impl Process { Ok(()) } } +/// Cuts the next complete `…` frame out of the +/// live buffer and returns it as an owned string, leaving any trailing partial +/// frame in place. +/// +/// Returns `None` when the buffer does not yet contain a full frame. This is a +/// plain string operation on purpose: it never poisons any parser state, so a +/// split or malformed frame on the live pipe cannot stop log forwarding. +fn take_next_log4j_frame(buffer: &mut String) -> Option { + const OPEN: &str = " 0 { + buffer.drain(..start); + } + let close = buffer.find(CLOSE)?; + let end = close + CLOSE.len(); + let frame = buffer[..end].to_string(); + buffer.drain(..end); + Some(frame) +} #[cfg(test)] mod post_upgrade_tests { use super::*; diff --git a/packages/ui/src/layouts/shared/console/components/LogViewport.vue b/packages/ui/src/layouts/shared/console/components/LogViewport.vue index 1728ebf..37df96a 100644 --- a/packages/ui/src/layouts/shared/console/components/LogViewport.vue +++ b/packages/ui/src/layouts/shared/console/components/LogViewport.vue @@ -19,32 +19,30 @@ /> -
+ +
-
{{ item.originalIndex + 1 }} - {{ item.originalIndex + 1 }} - -
+
@@ -99,114 +97,21 @@ const props = withDefaults( ) const viewportRef = ref(null) -const scrollTop = ref(0) -const viewportHeight = ref(0) const stickToBottom = ref(true) -// 行高：单行 = 字号 × 1.4（与等宽字体匹配），wrap 时按估算折行数放大 -const lineHeightPx = computed(() => Math.round(props.fontSize * 1.4)) -// wrap 折行估算：0.6em 为等宽字符平均宽，乘 0.9 留保守余量（行高宁高勿矮，避免内容溢出重叠） -const charsPerLine = computed(() => { - const vp = viewportRef.value - if (!vp) return 120 - return Math.max(20, Math.floor((vp.clientWidth / (props.fontSize * 0.6)) * 0.9)) +// Placeholder row height for `contain-intrinsic-size`. Native +// `content-visibility: auto` replaces this with the real measured height once a +// line enters the viewport, so it only needs to be a reasonable estimate to +// keep the scrollbar from jumping. Wrapped lines can be taller, so bias higher. +const intrinsicLineHeight = computed(() => { + const single = Math.round(props.fontSize * 1.4) + return props.wrap ? single * 2 : single }) -function estimateHeight(item: ViewportLine): number { - if (!props.wrap) return lineHeightPx.value - const lines = Math.max(1, Math.ceil(item.line.text.length / charsPerLine.value)) - return lines * lineHeightPx.value -} - -// 高度前缀和缓存：lines/wrap/fontSize 变化时重建（O(n)），滚动时二分查找（O(log n)） -// 总高度必须是响应式的：普通变量 + 无依赖 computed 会缓存过期值， -// 清空控制台后模板不再读取它，重启后 spacer 会以旧高度渲染（底部空白）。 -let heightPrefix: number[] | null = null -const heightTotal = ref(0) - -function rebuildHeights() { - const n = props.lines.length - if (!props.wrap) { - heightPrefix = null - heightTotal.value = n * lineHeightPx.value - return - } - const prefix = new Array(n) - let acc = 0 - for (let i = 0; i < n; i++) { - prefix[i] = acc - acc += estimateHeight(props.lines[i]!) - } - heightPrefix = prefix - heightTotal.value = acc -} - -watch( - () => [props.lines, props.wrap, props.fontSize] as const, - ([lines], previous) => { - rebuildHeights() - // A fresh stream after an empty console (clear, restart, initial - // hydration) always resumes bottom-following. - if (previous && previous[0].length === 0 && lines.length > 0) { - stickToBottom.value = true - } - if (lines.length === 0) { - // Reset the virtual window state along with the DOM scroll position; - // browsers may clamp silently without firing a scroll event. - scrollTop.value = 0 - if (viewportRef.value) viewportRef.value.scrollTop = 0 - } - if (stickToBottom.value) { - nextTick(scrollToBottom) - } - }, - { immediate: true }, -) - -const totalHeight = computed(() => heightTotal.value) - -// 虚拟窗口：可见行 + 上下缓冲 -const WINDOW_BUFFER = 15 - -function computeWindow(): { items: ViewportLine[]; startIndex: number } { - const n = props.lines.length - if (n === 0) return { items: [], startIndex: 0 } - - let start = 0 - let end = n - 1 - - if (n > WINDOW_BUFFER * 2) { - if (props.wrap && heightPrefix) { - let lo = 0 - let hi = n - 1 - while (lo < hi) { - const mid = (lo + hi + 1) >> 1 - if (heightPrefix[mid]! <= scrollTop.value) lo = mid - else hi = mid - 1 - } - start = Math.max(0, lo - WINDOW_BUFFER) - } else { - const first = Math.floor(scrollTop.value / lineHeightPx.value) - start = Math.max(0, first - WINDOW_BUFFER) - } - end = Math.min( - n - 1, - start + Math.ceil(viewportHeight.value / lineHeightPx.value) + WINDOW_BUFFER * 2, - ) - } - - return { items: props.lines.slice(start, end + 1), startIndex: start } -} - -const windowState = computed(computeWindow) -const windowItems = computed(() => windowState.value.items) - -const topOffset = computed(() => { - const { startIndex } = windowState.value - if (startIndex === 0) return 0 - if (props.wrap && heightPrefix) return heightPrefix[startIndex]! - return startIndex * lineHeightPx.value -}) +const lineStyle = computed(() => ({ + 'content-visibility': 'auto', + 'contain-intrinsic-size': `auto ${intrinsicLineHeight.value}px`, +})) function entryClass(line: LogLine): string { if (line.level === 'error') return 'entry-error' @@ -235,43 +140,47 @@ function renderLine(item: ViewportLine): string { function handleScroll() { const vp = viewportRef.value if (!vp) return - scrollTop.value = vp.scrollTop - viewportHeight.value = vp.clientHeight - stickToBottom.value = vp.scrollTop + vp.clientHeight >= vp.scrollHeight - lineHeightPx.value * 2 + stickToBottom.value = vp.scrollTop + vp.clientHeight >= vp.scrollHeight - 32 } function scrollToBottom() { const vp = viewportRef.value if (!vp) return vp.scrollTop = vp.scrollHeight - scrollTop.value = vp.scrollTop stickToBottom.value = true } -function syncViewportSize() { - const vp = viewportRef.value - if (!vp) return - viewportHeight.value = vp.clientHeight - // 窗口宽度影响 wrap 折行估算，resize 时重建高度缓存 - if (props.wrap) rebuildHeights() -} - let resizeObserver: ResizeObserver | null = null onMounted(() => { - syncViewportSize() if (stickToBottom.value) nextTick(scrollToBottom) - resizeObserver = new ResizeObserver(syncViewportSize) + resizeObserver = new ResizeObserver(() => { + if (stickToBottom.value) scrollToBottom() + }) if (viewportRef.value) resizeObserver.observe(viewportRef.value) - window.addEventListener('resize', syncViewportSize) }) onBeforeUnmount(() => { resizeObserver?.disconnect() resizeObserver = null - window.removeEventListener('resize', syncViewportSize) }) +// Follow the tail while new lines stream in, but only when the user has not +// scrolled up. A fresh stream after an empty console (clear, restart, initial +// hydration) always resumes bottom-following. +watch( + () => props.lines, + (lines, previous) => { + if (previous && previous.length === 0 && lines.length > 0) { + stickToBottom.value = true + } + if (stickToBottom.value) { + nextTick(scrollToBottom) + } + }, + { immediate: true }, +) + defineExpose({ scrollToBottom, })