perf(logging): batch UI updates and gate native log copies

This commit is contained in:
zarzet committed 2026-10-04 01:41:38 +07:00
1 parent 37a1db274a
commit 7f7e9c0e39
3 files changed
+133 -25

No files matched your search

+18 -3
View File
@@ -142,8 +142,21 @@ class LogBuffer extends ChangeNotifier {
int get length => _entries.length;
void add(LogEntry entry) {
if (_append(entry)) notifyListeners();
}
/// A native poll is one UI update, even when it contains hundreds of logs.
void addAll(Iterable<LogEntry> entries) {
var changed = false;
for (final entry in entries) {
changed = _append(entry) || changed;
}
if (changed) notifyListeners();
}
bool _append(LogEntry entry) {
if (!_loggingEnabled && entry.level != 'ERROR' && entry.level != 'FATAL') {
return;
return false;
}
final sanitizedMessage = _truncateLogText(
@@ -172,7 +185,7 @@ class LogBuffer extends ChangeNotifier {
_entries.removeFirst();
}
_entries.add(sanitizedEntry);
notifyListeners();
return true;
}
void startGoLogPolling() {
@@ -200,6 +213,7 @@ class LogBuffer extends ChangeNotifier {
final logs = result['logs'] as List<dynamic>? ?? [];
final nextIndex = result['next_index'] as int? ?? _lastGoLogIndex;
final keepNonErrorLogs = _loggingEnabled;
final entries = <LogEntry>[];
for (final log in logs.whereType<Map<Object?, Object?>>()) {
final logMap = Map<String, dynamic>.from(log);
@@ -231,7 +245,7 @@ class LogBuffer extends ChangeNotifier {
} catch (_) {}
}
add(
entries.add(
LogEntry(
timestamp: parsedTime,
level: level,
@@ -242,6 +256,7 @@ class LogBuffer extends ChangeNotifier {
);
}
addAll(entries);
_lastGoLogIndex = nextIndex;
} catch (e) {
if (kDebugMode) {
+85 -22
View File
@@ -26,7 +26,7 @@ struct State {
}
#[derive(Default)]
pub struct LogBuffer(Mutex<State>);
pub struct LogBuffer(Mutex<State>, Mutex<()>);
#[derive(Clone, Copy, Debug, PartialEq, Eq, thiserror::Error)]
#[error("log buffer closed")]
@@ -53,16 +53,31 @@ impl LogBuffer {
}
pub fn add(&self, level: &str, tag: &str, message: &str) -> Result<(), LogClosed> {
self.add_bytes(level, tag, message.as_bytes().to_vec())
self.add_message(level, tag, || message.as_bytes().to_vec(), false)
}
fn add_bytes(&self, level: &str, tag: &str, message: Vec<u8>) -> Result<(), LogClosed> {
fn add_message(
&self,
level: &str,
tag: &str,
message: impl FnOnce() -> Vec<u8>,
sanitized: bool,
) -> Result<(), LogClosed> {
// Serialize append/output order without holding the state lock during
// stderr IO. Snapshot readers and shutdown can still access the buffer.
let _output = self.1.lock().expect("log output lock");
let mut state = self.0.lock().expect("log buffer lock");
state.check()?;
if !state.enabled && level != "ERROR" && level != "FATAL" {
return Ok(());
}
let message = decode_go_utf8(&truncate(sanitize_bytes(message)));
let message = message();
let message = if sanitized {
message
} else {
sanitize_bytes(message)
};
let message = decode_go_utf8(&truncate(message));
let entry = LogEntry {
timestamp: chrono::Local::now().format("%H:%M:%S%.3f").to_string(),
level: level.into(),
@@ -72,25 +87,22 @@ impl LogBuffer {
if state.entries.len() == CAPACITY {
state.entries.pop_front();
}
use std::io::Write;
let _ = writeln!(
std::io::stderr().lock(),
"[{}] {}",
entry.tag,
entry.message
);
let line = format!("[{}] {}", entry.tag, entry.message);
state.entries.push_back(entry);
state.next_index = state.next_index.wrapping_add(1);
drop(state);
use std::io::Write;
let _ = writeln!(std::io::stderr().lock(), "{line}");
Ok(())
}
pub fn backend(&self, message: &str) -> Result<(), LogClosed> {
self.backend_bytes(message.as_bytes().to_vec())
self.backend_bytes(message.as_bytes(), false)
}
fn backend_bytes(&self, mut message: Vec<u8>) -> Result<(), LogClosed> {
fn backend_bytes(&self, mut message: &[u8], sanitized: bool) -> Result<(), LogClosed> {
if message.last() == Some(&b'\n') {
message.pop();
message = &message[..message.len() - 1];
}
let mut tag = "Rust".to_owned();
if message.first() == Some(&b'[')
@@ -102,7 +114,7 @@ impl LogBuffer {
tag = decode_go_utf8(&message[1..end]);
message = trim_bytes(&message[end + 1..]);
}
let lowercase = spotiflac_core::matching::lowercase(&decode_go_utf8(&message));
let lowercase = spotiflac_core::matching::lowercase(&decode_go_utf8(message));
let level = if lowercase.contains("error") || lowercase.contains("failed") {
"ERROR"
} else if lowercase.contains("warning") || lowercase.contains("warn") {
@@ -117,7 +129,7 @@ impl LogBuffer {
} else {
"INFO"
};
self.add_bytes(level, &tag, message)
self.add_message(level, &tag, || message.to_vec(), sanitized)
}
pub(crate) fn extension(&self, id: &str, level: &str, arguments: Vec<String>, total: usize) {
@@ -147,7 +159,7 @@ impl LogBuffer {
.into_bytes();
line.extend(formatted);
line.push(b'\n');
let _ = self.backend_bytes(line);
let _ = self.backend_bytes(&line, true);
}
pub fn all(&self) -> Result<String, LogClosed> {
@@ -206,15 +218,66 @@ fn truncate(mut message: Vec<u8>) -> Vec<u8> {
message
}
fn trim_bytes(bytes: &[u8]) -> Vec<u8> {
fn trim_bytes(bytes: &[u8]) -> &[u8] {
// Invalid bytes are non-whitespace in Go and are retained until JSON export.
let decoded = decode_go_utf8(bytes);
let left = decoded.len() - decoded.trim_start().len();
let right = decoded.len() - decoded.trim_end().len();
let end = bytes.len().saturating_sub(right);
if left >= end {
Vec::new()
} else {
bytes[left..end].to_vec()
if left >= end { &[] } else { &bytes[left..end] }
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn disabled_messages_skip_conversion_but_errors_and_closed_state_are_preserved() {
let logs = LogBuffer::default();
logs.add_message(
"DEBUG",
"Example",
|| panic!("disabled message copied"),
false,
)
.unwrap();
for level in ["ERROR", "FATAL"] {
logs.add(level, "Example", "password=fixture-secret;")
.unwrap();
}
let values: serde_json::Value = serde_json::from_str(&logs.all().unwrap()).unwrap();
assert_eq!(values[0]["message"], "password=[REDACTED];");
assert_eq!(values[1]["level"], "FATAL");
logs.shutdown();
assert_eq!(logs.add("DEBUG", "Example", "ignored"), Err(LogClosed));
}
#[test]
fn extension_redaction_precedes_level_inference_and_preserves_raw_byte_truncation() {
let logs = LogBuffer::default();
logs.set_enabled(true).unwrap();
logs.extension(
"example",
"WARN",
vec!["password=failed-secret;".into(), "é".repeat(257)],
2,
);
let values: serde_json::Value = serde_json::from_str(&logs.all().unwrap()).unwrap();
assert_eq!(values[0]["level"], "INFO");
assert_eq!(values[0]["tag"], "Extension:example:WARN");
assert_eq!(
values[0]["message"],
format!("password=[REDACTED]; {}...[truncated]", "é".repeat(256))
);
logs.extension(
"example",
"",
vec!["failure: failed password=fixture-secret;".into()],
1,
);
assert_eq!(logs.count().unwrap(), 2);
let values: serde_json::Value = serde_json::from_str(&logs.all().unwrap()).unwrap();
assert_eq!(values[1]["level"], "ERROR");
assert!(!logs.all().unwrap().contains("fixture-secret"));
}
}
+30
View File
@@ -6,6 +6,36 @@ import 'package:spotiflac_android/screens/settings/log_screen.dart';
import 'package:spotiflac_android/utils/logger.dart';
void main() {
test(
'native log batches notify once and preserve redaction and capacity',
() {
final buffer = LogBuffer()..clear();
var updates = 0;
void listener() => updates++;
buffer.addListener(listener);
addTearDown(() {
buffer.removeListener(listener);
buffer.clear();
});
buffer.addAll([
for (var index = 0; index < 600; index++)
LogEntry(
timestamp: DateTime(2026),
level: 'ERROR',
tag: 'Native',
message: '$index -decryption_key secret-value',
),
]);
expect(updates, 1);
expect(buffer.length, LogBuffer.maxEntries);
expect(buffer.entries.first.message, startsWith('100 '));
expect(buffer.entries.last.message, startsWith('599 '));
expect(formatLogEntries(buffer.entries), isNot(contains('secret-value')));
buffer.addAll(const []);
expect(updates, 1);
},
);
test('selected log export keeps chronological lines only', () {
final entries = [
LogEntry(