fix(library-db): name slow-write ops for macOS stall diagnosis (#1043)

* fix(library-db): name slow-write ops for macOS stall diagnosis (#1040)

Replace generic op=misc labels on production library-db write paths with
stable module.action names (sync_state.*, track.*, tombstone.*, cmd.*, …)
so SLOW write logs pinpoint the call site. Document the naming convention
on LibraryStore::with_conn.

Diagnostic step for #1040 — no behaviour change.

* docs: add CHANGELOG and credits for PR #1043

Library-db slow-write op naming diagnostic for issue #1040.
This commit is contained in:
cucadmuh
2026-06-09 11:03:22 +03:00
committed by GitHub
parent cfc9419de7
commit b2a5baa48d
11 changed files with 45 additions and 31 deletions
+8
View File
@@ -151,6 +151,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
## Fixed ## Fixed
### Library DB — named slow-write ops for stall diagnosis
**By [@cucadmuh](https://github.com/cucadmuh), PR [#1043](https://github.com/Psychotoxical/psysonic/pull/1043)**
* Production `library-db` write paths now log stable `module.action` op names instead of the generic `misc`, so the next `[library-db] SLOW write` line on macOS (or elsewhere) identifies the call site — diagnostic step for playback stalls under long write-lock holds ([#1040](https://github.com/Psychotoxical/psysonic/issues/1040)).
### Servers — complete border on the active server card ### Servers — complete border on the active server card
**By [@Psychotoxical](https://github.com/Psychotoxical), PR [#998](https://github.com/Psychotoxical/psysonic/pull/998)** **By [@Psychotoxical](https://github.com/Psychotoxical), PR [#998](https://github.com/Psychotoxical/psysonic/pull/998)**
@@ -34,7 +34,7 @@ pub(crate) fn reconcile_album_stars(
) -> Result<(), String> { ) -> Result<(), String> {
runtime runtime
.store .store
.with_conn("misc", |conn| { .with_conn("browse.reconcile_album_stars", |conn| {
if starred.is_empty() { if starred.is_empty() {
conn.execute( conn.execute(
"UPDATE album SET starred_at = NULL \ "UPDATE album SET starred_at = NULL \
@@ -81,7 +81,7 @@ pub fn link_all_tracks_for_server(
server_id: &str, server_id: &str,
now: i64, now: i64,
) -> Result<u32, String> { ) -> Result<u32, String> {
store.with_conn_mut("misc", |conn| { store.with_conn_mut("canonical.link_all_tracks", |conn| {
let tx = conn.transaction()?; let tx = conn.transaction()?;
let mut stmt = tx.prepare( let mut stmt = tx.prepare(
"SELECT id, isrc, mbid_recording FROM track \ "SELECT id, isrc, mbid_recording FROM track \
@@ -476,7 +476,7 @@ pub async fn library_get_offline_path(
) -> Result<OfflinePathDto, String> { ) -> Result<OfflinePathDto, String> {
let path = runtime let path = runtime
.store .store
.with_conn("misc", |conn| { .with_conn("cmd.get_offline_path", |conn| {
conn.query_row( conn.query_row(
"SELECT local_path FROM track_offline \ "SELECT local_path FROM track_offline \
WHERE server_id = ?1 AND track_id = ?2", WHERE server_id = ?1 AND track_id = ?2",
@@ -1028,7 +1028,7 @@ pub fn patch_content_hash(
} }
runtime runtime
.store .store
.with_conn("misc", |conn| { .with_conn("cmd.patch_content_hash", |conn| {
conn.execute( conn.execute(
"UPDATE track SET content_hash = ?3 \ "UPDATE track SET content_hash = ?3 \
WHERE server_id = ?1 AND id = ?2", WHERE server_id = ?1 AND id = ?2",
@@ -1075,7 +1075,7 @@ pub(crate) fn apply_track_patch(
runtime runtime
.store .store
.with_conn("misc", |conn| { .with_conn("cmd.patch_track", |conn| {
// One UPDATE per field present — keeps SQL simple and // One UPDATE per field present — keeps SQL simple and
// matches the spec's per-field patch semantics. // matches the spec's per-field patch semantics.
if let Some(v) = starred_at { if let Some(v) = starred_at {
@@ -1211,7 +1211,7 @@ pub fn library_purge_server(
let mut report = PurgeReportDto::default(); let mut report = PurgeReportDto::default();
runtime runtime
.store .store
.with_conn_mut("misc", |conn| { .with_conn_mut("cmd.purge_server", |conn| {
let tx = conn.transaction()?; let tx = conn.transaction()?;
let track_count: i64 = let track_count: i64 =
tx.query_row("SELECT COUNT(*) FROM track WHERE server_id = ?1", params![server_id], |r| r.get(0))?; tx.query_row("SELECT COUNT(*) FROM track WHERE server_id = ?1", params![server_id], |r| r.get(0))?;
@@ -29,7 +29,7 @@ impl<'a> SyncStateRepository<'a> {
/// if none exists. All non-PK columns fall back to their schema DEFAULTs /// if none exists. All non-PK columns fall back to their schema DEFAULTs
/// (`sync_phase='idle'`, `initial_sync_cursor_json='{}'`, …). /// (`sync_phase='idle'`, `initial_sync_cursor_json='{}'`, …).
pub fn ensure(&self, server_id: &str, library_scope: &str) -> Result<(), String> { pub fn ensure(&self, server_id: &str, library_scope: &str) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.ensure", |conn| {
conn.execute( conn.execute(
"INSERT OR IGNORE INTO sync_state (server_id, library_scope) VALUES (?1, ?2)", "INSERT OR IGNORE INTO sync_state (server_id, library_scope) VALUES (?1, ?2)",
params![server_id, library_scope], params![server_id, library_scope],
@@ -73,7 +73,7 @@ impl<'a> SyncStateRepository<'a> {
cursor: &Value, cursor: &Value,
) -> Result<(), String> { ) -> Result<(), String> {
let json = serde_json::to_string(cursor).map_err(|e| e.to_string())?; let json = serde_json::to_string(cursor).map_err(|e| e.to_string())?;
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_initial_sync_cursor", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, initial_sync_cursor_json) \ "INSERT INTO sync_state (server_id, library_scope, initial_sync_cursor_json) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -134,7 +134,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
flags: u32, flags: u32,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_capability_flags", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, capability_flags) \ "INSERT INTO sync_state (server_id, library_scope, capability_flags) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -192,7 +192,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
phase: &str, phase: &str,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_sync_phase", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, sync_phase) \ "INSERT INTO sync_state (server_id, library_scope, sync_phase) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -212,7 +212,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
last_scan_iso: Option<&str>, last_scan_iso: Option<&str>,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_server_last_scan_iso", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, server_last_scan_iso) \ "INSERT INTO sync_state (server_id, library_scope, server_last_scan_iso) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -232,7 +232,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
last_modified_ms: i64, last_modified_ms: i64,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_indexes_last_modified_ms", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, indexes_last_modified_ms) \ "INSERT INTO sync_state (server_id, library_scope, indexes_last_modified_ms) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -330,7 +330,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
epoch_ms: i64, epoch_ms: i64,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_next_poll_at", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, next_poll_at) \ "INSERT INTO sync_state (server_id, library_scope, next_poll_at) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -375,7 +375,7 @@ impl<'a> SyncStateRepository<'a> {
stats: &Value, stats: &Value,
) -> Result<(), String> { ) -> Result<(), String> {
let json = serde_json::to_string(stats).map_err(|e| e.to_string())?; let json = serde_json::to_string(stats).map_err(|e| e.to_string())?;
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_poll_stats_json", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, poll_stats_json) \ "INSERT INTO sync_state (server_id, library_scope, poll_stats_json) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -412,7 +412,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
count: i64, count: i64,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_local_track_count", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, local_track_count) \ "INSERT INTO sync_state (server_id, library_scope, local_track_count) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -447,7 +447,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
count: i64, count: i64,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_server_track_count", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, server_track_count) \ "INSERT INTO sync_state (server_id, library_scope, server_track_count) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -488,7 +488,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
unreliable: bool, unreliable: bool,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_n1_bulk_unreliable", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, n1_bulk_unreliable) \ "INSERT INTO sync_state (server_id, library_scope, n1_bulk_unreliable) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -508,7 +508,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
epoch_ms: i64, epoch_ms: i64,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_last_full_sync_at", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, last_full_sync_at) \ "INSERT INTO sync_state (server_id, library_scope, last_full_sync_at) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -528,7 +528,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
epoch_ms: i64, epoch_ms: i64,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_last_delta_sync_at", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, last_delta_sync_at) \ "INSERT INTO sync_state (server_id, library_scope, last_delta_sync_at) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -549,7 +549,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
last_modified_ms: i64, last_modified_ms: i64,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_artists_last_modified_ms", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, artists_last_modified_ms) \ "INSERT INTO sync_state (server_id, library_scope, artists_last_modified_ms) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -570,7 +570,7 @@ impl<'a> SyncStateRepository<'a> {
library_scope: &str, library_scope: &str,
tier: &str, tier: &str,
) -> Result<(), String> { ) -> Result<(), String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("sync_state.set_library_tier", |conn| {
conn.execute( conn.execute(
"INSERT INTO sync_state (server_id, library_scope, library_tier) \ "INSERT INTO sync_state (server_id, library_scope, library_tier) \
VALUES (?1, ?2, ?3) \ VALUES (?1, ?2, ?3) \
@@ -191,7 +191,7 @@ impl<'a> TrackRepository<'a> {
/// Next generation stamp for a full-resync orphan sweep on this server. /// Next generation stamp for a full-resync orphan sweep on this server.
pub fn next_resync_gen(&self, server_id: &str) -> Result<i64, String> { pub fn next_resync_gen(&self, server_id: &str) -> Result<i64, String> {
self.store.with_conn("misc", |c| { self.store.with_conn("track.next_resync_gen", |c| {
c.query_row( c.query_row(
"SELECT COALESCE(MAX(resync_gen), 0) + 1 FROM track WHERE server_id = ?1", "SELECT COALESCE(MAX(resync_gen), 0) + 1 FROM track WHERE server_id = ?1",
params![server_id], params![server_id],
@@ -203,7 +203,7 @@ impl<'a> TrackRepository<'a> {
/// IS-7 — soft-delete live rows not re-stamped during the active resync. /// IS-7 — soft-delete live rows not re-stamped during the active resync.
pub fn sweep_resync_orphans(&self, server_id: &str, resync_gen: i64) -> Result<u32, String> { pub fn sweep_resync_orphans(&self, server_id: &str, resync_gen: i64) -> Result<u32, String> {
let now = now_unix_ms(); let now = now_unix_ms();
let changed = self.store.with_conn_mut("misc", |c| { let changed = self.store.with_conn_mut("track.sweep_resync_orphans", |c| {
c.execute( c.execute(
"UPDATE track SET deleted = 1, synced_at = ?3 \ "UPDATE track SET deleted = 1, synced_at = ?3 \
WHERE server_id = ?1 AND deleted = 0 AND resync_gen != ?2", WHERE server_id = ?1 AND deleted = 0 AND resync_gen != ?2",
@@ -418,7 +418,7 @@ impl<'a> TrackRepository<'a> {
if rows.is_empty() { if rows.is_empty() {
return Ok(RemapStats::default()); return Ok(RemapStats::default());
} }
self.store.with_conn_mut("misc", |conn| { self.store.with_conn_mut("track.upsert_batch_remap", |conn| {
let tx = conn.transaction()?; let tx = conn.transaction()?;
let mut remapped: Vec<RemapEntry> = Vec::new(); let mut remapped: Vec<RemapEntry> = Vec::new();
let mut upsert = tx.prepare_cached(UPSERT_SQL)?; let mut upsert = tx.prepare_cached(UPSERT_SQL)?;
@@ -26,7 +26,7 @@ impl<'a> TrackIdHistoryRepository<'a> {
server_id: &str, server_id: &str,
old_id: &str, old_id: &str,
) -> Result<Option<String>, String> { ) -> Result<Option<String>, String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("track_id_history.lookup", |conn| {
conn.query_row( conn.query_row(
"SELECT new_id FROM track_id_history \ "SELECT new_id FROM track_id_history \
WHERE server_id = ?1 AND old_id = ?2", WHERE server_id = ?1 AND old_id = ?2",
@@ -40,7 +40,7 @@ impl<'a> TrackIdHistoryRepository<'a> {
/// Count the rows recorded for this server — used by tests and by /// Count the rows recorded for this server — used by tests and by
/// post-sync diagnostics (Settings „Library index" panel later). /// post-sync diagnostics (Settings „Library index" panel later).
pub fn count_for_server(&self, server_id: &str) -> Result<i64, String> { pub fn count_for_server(&self, server_id: &str) -> Result<i64, String> {
self.store.with_conn("misc", |conn| { self.store.with_conn("track_id_history.count", |conn| {
conn.query_row( conn.query_row(
"SELECT COUNT(*) FROM track_id_history WHERE server_id = ?1", "SELECT COUNT(*) FROM track_id_history WHERE server_id = ?1",
params![server_id], params![server_id],
@@ -103,6 +103,11 @@ impl LibraryStore {
} }
/// Writer connection — sync ingest, migrations, mutations. /// Writer connection — sync ingest, migrations, mutations.
///
/// `op` is logged on slow writes (`[library-db] SLOW write op=…`) — use a
/// stable `module.action` label (e.g. `sync_state.set_sync_phase`,
/// `track.upsert_batch_remap`), not the generic `"misc"`, so production
/// stalls can be attributed to a specific call site.
pub(crate) fn with_conn<R>( pub(crate) fn with_conn<R>(
&self, &self,
op: &'static str, op: &'static str,
@@ -284,7 +284,7 @@ impl<'a> DeltaSyncRunner<'a> {
fn local_track_updated_watermark(&self) -> Result<Option<i64>, SyncError> { fn local_track_updated_watermark(&self) -> Result<Option<i64>, SyncError> {
self.store self.store
.with_conn("misc", |c| { .with_conn("delta.local_track_watermark", |c| {
c.query_row( c.query_row(
"SELECT MAX(server_updated_at) FROM track \ "SELECT MAX(server_updated_at) FROM track \
WHERE server_id = ?1 AND deleted = 0", WHERE server_id = ?1 AND deleted = 0",
@@ -297,7 +297,7 @@ impl<'a> DeltaSyncRunner<'a> {
fn local_album_ids(&self) -> Result<HashSet<String>, SyncError> { fn local_album_ids(&self) -> Result<HashSet<String>, SyncError> {
self.store self.store
.with_conn("misc", |c| { .with_conn("delta.local_album_ids", |c| {
let mut stmt = c.prepare( let mut stmt = c.prepare(
"SELECT DISTINCT album_id FROM track \ "SELECT DISTINCT album_id FROM track \
WHERE server_id = ?1 AND deleted = 0 AND album_id IS NOT NULL", WHERE server_id = ?1 AND deleted = 0 AND album_id IS NOT NULL",
@@ -115,7 +115,7 @@ impl<'a> TombstoneReconciler<'a> {
fn next_candidates(&self, budget: u32) -> Result<Vec<String>, SyncError> { fn next_candidates(&self, budget: u32) -> Result<Vec<String>, SyncError> {
self.store self.store
.with_conn("misc", |c| { .with_conn("tombstone.next_candidates", |c| {
let mut stmt = c.prepare( let mut stmt = c.prepare(
"SELECT id FROM track \ "SELECT id FROM track \
WHERE server_id = ?1 AND deleted = 0 \ WHERE server_id = ?1 AND deleted = 0 \
@@ -133,7 +133,7 @@ impl<'a> TombstoneReconciler<'a> {
fn mark_deleted(&self, id: &str) -> Result<(), SyncError> { fn mark_deleted(&self, id: &str) -> Result<(), SyncError> {
self.store self.store
.with_conn("misc", |c| { .with_conn("tombstone.mark_deleted", |c| {
c.execute( c.execute(
"UPDATE track SET deleted = 1, synced_at = ?3 \ "UPDATE track SET deleted = 1, synced_at = ?3 \
WHERE server_id = ?1 AND id = ?2", WHERE server_id = ?1 AND id = ?2",
@@ -146,7 +146,7 @@ impl<'a> TombstoneReconciler<'a> {
fn mark_synced(&self, id: &str) -> Result<(), SyncError> { fn mark_synced(&self, id: &str) -> Result<(), SyncError> {
self.store self.store
.with_conn("misc", |c| { .with_conn("tombstone.mark_synced", |c| {
c.execute( c.execute(
"UPDATE track SET synced_at = ?3 \ "UPDATE track SET synced_at = ?3 \
WHERE server_id = ?1 AND id = ?2", WHERE server_id = ?1 AND id = ?2",
+1
View File
@@ -157,6 +157,7 @@ const CONTRIBUTOR_ENTRIES = [
'Themed startup splash before Vite loads — deferred window show, per-theme logo gradient (PR #1030)', 'Themed startup splash before Vite loads — deferred window show, per-theme logo gradient (PR #1030)',
'Artist page: Top Tracks play when album list is empty on the page (PR #1031)', 'Artist page: Top Tracks play when album list is empty on the page (PR #1031)',
'PsyLab Connections tab with server capability readout, Navidrome admin-role probe, and tab-bar layout fix; server-capability framework with AudioMuse detection via OpenSubsonic sonicSimilarity and sonic Instant Mix routing on Navidrome ≥0.62 (PR #1033)', 'PsyLab Connections tab with server capability readout, Navidrome admin-role probe, and tab-bar layout fix; server-capability framework with AudioMuse detection via OpenSubsonic sonicSimilarity and sonic Instant Mix routing on Navidrome ≥0.62 (PR #1033)',
'Library DB: named slow-write op labels for macOS playback-stall diagnosis (PR #1043)',
], ],
}, },
{ {