itsscb/rust-analyzer
1
0
Fork 0
mirror of https://github.com/rust-lang/rust-analyzer.git synced 2025-09-28 11:20:54 +00:00
Code Issues Packages Projects Releases Wiki Activity

Downgrade salsa log levels

Browse Source
This commit is contained in:
Lukas Wirth 2024-12-28 15:08:26 +01:00
parent bfc223e857
commit c800485555
8 changed files with 86 additions and 68 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
crates/ra-salsa/ra-salsa-macros/src/query_group.rs
View File

@ -242,7 +242,7 @@ pub(crate) fn query_group(args: TokenStream, input: TokenStream) -> TokenStream
let tracing = if let QueryStorage::Memoized | QueryStorage::LruMemoized = query.storage {
let s = format!("{trait_name}::{fn_name}");
Some(quote! {
let _p = tracing::debug_span!(#s, #(#key_names = tracing::field::debug(&#key_names)),*).entered();
let _p = tracing::trace_span!(#s, #(#key_names = tracing::field::debug(&#key_names)),*).entered();
})
} else {
None

45
crates/ra-salsa/src/derived/slot.rs
View File

@ -13,7 +13,7 @@ use crate::{Database, DatabaseKeyIndex, Event, EventKind, QueryDb};
use parking_lot::{RawRwLock, RwLock};
use std::ops::Deref;
use std::sync::atomic::{AtomicBool, Ordering};
use tracing::{debug, info};
use tracing::trace;
pub(super) struct Slot<Q>
where
@ -126,7 +126,7 @@ where
// doing any `set` invocations while the query function runs.
let revision_now = runtime.current_revision();
info!("{:?}: invoked at {:?}", self, revision_now,);
trace!("{:?}: invoked at {:?}", self, revision_now,);
// First, do a check with a read-lock.
loop {
@ -152,7 +152,7 @@ where
) -> StampedValue<Q::Value> {
let runtime = db.salsa_runtime();
debug!("{:?}: read_upgrade(revision_now={:?})", self, revision_now,);
trace!("{:?}: read_upgrade(revision_now={:?})", self, revision_now,);
// Check with an upgradable read to see if there is a value
// already. (This permits other readers but prevents anyone
@ -184,7 +184,7 @@ where
// inputs and check whether they are out of date.
if let Some(memo) = &mut old_memo {
if let Some(value) = memo.verify_value(db.ops_database(), revision_now, &active_query) {
info!("{:?}: validated old memoized value", self,);
trace!("{:?}: validated old memoized value", self,);
db.salsa_event(Event {
runtime_id: runtime.id(),
@ -212,7 +212,7 @@ where
old_memo: Option<Memo<Q::Value>>,
key: &Q::Key,
) -> StampedValue<Q::Value> {
tracing::info!("{:?}: executing query", self.database_key_index().debug(db));
tracing::trace!("{:?}: executing query", self.database_key_index().debug(db));
db.salsa_event(Event {
runtime_id: db.salsa_runtime().id(),
@ -224,7 +224,7 @@ where
let value = match Cycle::catch(|| Q::execute(db, key.clone())) {
Ok(v) => v,
Err(cycle) => {
tracing::debug!(
tracing::trace!(
"{:?}: caught cycle {:?}, have strategy {:?}",
self.database_key_index().debug(db),
cycle,
@ -272,9 +272,10 @@ where
// consumers must be aware of. Becoming *more* durable
// is not. See the test `constant_to_non_constant`.
if revisions.durability >= old_memo.revisions.durability && old_memo.value == value {
debug!(
trace!(
"read_upgrade({:?}): value is equal, back-dating to {:?}",
self, old_memo.revisions.changed_at,
self,
old_memo.revisions.changed_at,
);
assert!(old_memo.revisions.changed_at <= revisions.changed_at);
@ -290,7 +291,7 @@ where
let memo_value = new_value.value.clone();
debug!("read_upgrade({:?}): result.revisions = {:#?}", self, revisions,);
trace!("read_upgrade({:?}): result.revisions = {:#?}", self, revisions,);
panic_guard.proceed(Some(Memo { value: memo_value, verified_at: revision_now, revisions }));
@ -339,9 +340,11 @@ where
}
QueryState::Memoized(memo) => {
debug!(
trace!(
"{:?}: found memoized value, verified_at={:?}, changed_at={:?}",
self, memo.verified_at, memo.revisions.changed_at,
self,
memo.verified_at,
memo.revisions.changed_at,
);
if memo.verified_at < revision_now {
@ -355,7 +358,7 @@ where
value: value.clone(),
};
info!("{:?}: returning memoized value changed at {:?}", self, value.changed_at);
trace!("{:?}: returning memoized value changed at {:?}", self, value.changed_at);
ProbeState::UpToDate(value)
}
@ -387,7 +390,7 @@ where
}
pub(super) fn invalidate(&self, new_revision: Revision) -> Option<Durability> {
tracing::debug!("Slot::invalidate(new_revision = {:?})", new_revision);
tracing::trace!("Slot::invalidate(new_revision = {:?})", new_revision);
match &mut *self.state.write() {
QueryState::Memoized(memo) => {
memo.revisions.untracked = true;
@ -411,9 +414,11 @@ where
db.unwind_if_cancelled();
debug!(
trace!(
"maybe_changed_after({:?}) called with revision={:?}, revision_now={:?}",
self, revision, revision_now,
self,
revision,
revision_now,
);
// Do an initial probe with just the read-lock.
@ -680,9 +685,11 @@ where
assert!(self.verified_at != revision_now);
let verified_at = self.verified_at;
debug!(
trace!(
"verify_revisions: verified_at={:?}, revision_now={:?}, inputs={:#?}",
verified_at, revision_now, self.revisions.inputs
verified_at,
revision_now,
self.revisions.inputs
);
if self.check_durability(db.salsa_runtime()) {
@ -708,7 +715,7 @@ where
let changed_input =
inputs.slice.iter().find(|&&input| db.maybe_changed_after(input, verified_at));
if let Some(input) = changed_input {
debug!("validate_memoized_value: `{:?}` may have changed", input);
trace!("validate_memoized_value: `{:?}` may have changed", input);
return false;
}
@ -721,7 +728,7 @@ where
/// True if this memo is known not to have changed based on its durability.
fn check_durability(&self, runtime: &Runtime) -> bool {
let last_changed = runtime.last_changed_revision(self.revisions.durability);
debug!(
trace!(
"check_durability(last_changed={:?} <= verified_at={:?}) = {:?}",
last_changed,
self.verified_at,

49
crates/ra-salsa/src/derived_lru/slot.rs
View File

@ -17,7 +17,7 @@ use parking_lot::{RawRwLock, RwLock};
use std::marker::PhantomData;
use std::ops::Deref;
use std::sync::atomic::{AtomicBool, Ordering};
use tracing::{debug, info};
use tracing::trace;
pub(super) struct Slot<Q, MP>
where
@ -140,7 +140,7 @@ where
// doing any `set` invocations while the query function runs.
let revision_now = runtime.current_revision();
info!("{:?}: invoked at {:?}", self, revision_now,);
trace!("{:?}: invoked at {:?}", self, revision_now,);
// First, do a check with a read-lock.
loop {
@ -168,7 +168,7 @@ where
) -> StampedValue<Q::Value> {
let runtime = db.salsa_runtime();
debug!("{:?}: read_upgrade(revision_now={:?})", self, revision_now,);
trace!("{:?}: read_upgrade(revision_now={:?})", self, revision_now,);
// Check with an upgradable read to see if there is a value
// already. (This permits other readers but prevents anyone
@ -202,7 +202,7 @@ where
// inputs and check whether they are out of date.
if let Some(memo) = &mut old_memo {
if let Some(value) = memo.verify_value(db.ops_database(), revision_now, &active_query) {
info!("{:?}: validated old memoized value", self,);
trace!("{:?}: validated old memoized value", self,);
db.salsa_event(Event {
runtime_id: runtime.id(),
@ -230,7 +230,7 @@ where
old_memo: Option<Memo<Q::Value>>,
key: &Q::Key,
) -> StampedValue<Q::Value> {
tracing::info!("{:?}: executing query", self.database_key_index().debug(db));
tracing::trace!("{:?}: executing query", self.database_key_index().debug(db));
db.salsa_event(Event {
runtime_id: db.salsa_runtime().id(),
@ -242,7 +242,7 @@ where
let value = match Cycle::catch(|| Q::execute(db, key.clone())) {
Ok(v) => v,
Err(cycle) => {
tracing::debug!(
tracing::trace!(
"{:?}: caught cycle {:?}, have strategy {:?}",
self.database_key_index().debug(db),
cycle,
@ -293,9 +293,10 @@ where
if revisions.durability >= old_memo.revisions.durability
&& MP::memoized_value_eq(old_value, &value)
{
debug!(
trace!(
"read_upgrade({:?}): value is equal, back-dating to {:?}",
self, old_memo.revisions.changed_at,
self,
old_memo.revisions.changed_at,
);
assert!(old_memo.revisions.changed_at <= revisions.changed_at);
@ -313,7 +314,7 @@ where
let memo_value =
if self.should_memoize_value(key) { Some(new_value.value.clone()) } else { None };
debug!("read_upgrade({:?}): result.revisions = {:#?}", self, revisions,);
trace!("read_upgrade({:?}): result.revisions = {:#?}", self, revisions,);
panic_guard.proceed(Some(Memo { value: memo_value, verified_at: revision_now, revisions }));
@ -362,9 +363,11 @@ where
}
QueryState::Memoized(memo) => {
debug!(
trace!(
"{:?}: found memoized value, verified_at={:?}, changed_at={:?}",
self, memo.verified_at, memo.revisions.changed_at,
self,
memo.verified_at,
memo.revisions.changed_at,
);
if memo.verified_at < revision_now {
@ -378,7 +381,11 @@ where
value: value.clone(),
};
info!("{:?}: returning memoized value changed at {:?}", self, value.changed_at);
trace!(
"{:?}: returning memoized value changed at {:?}",
self,
value.changed_at
);
ProbeState::UpToDate(value)
} else {
@ -426,7 +433,7 @@ where
}
pub(super) fn invalidate(&self, new_revision: Revision) -> Option<Durability> {
tracing::debug!("Slot::invalidate(new_revision = {:?})", new_revision);
tracing::trace!("Slot::invalidate(new_revision = {:?})", new_revision);
match &mut *self.state.write() {
QueryState::Memoized(memo) => {
memo.revisions.untracked = true;
@ -450,9 +457,11 @@ where
db.unwind_if_cancelled();
debug!(
trace!(
"maybe_changed_after({:?}) called with revision={:?}, revision_now={:?}",
self, revision, revision_now,
self,
revision,
revision_now,
);
// Do an initial probe with just the read-lock.
@ -734,9 +743,11 @@ where
assert!(self.verified_at != revision_now);
let verified_at = self.verified_at;
debug!(
trace!(
"verify_revisions: verified_at={:?}, revision_now={:?}, inputs={:#?}",
verified_at, revision_now, self.revisions.inputs
verified_at,
revision_now,
self.revisions.inputs
);
if self.check_durability(db.salsa_runtime()) {
@ -762,7 +773,7 @@ where
let changed_input =
inputs.slice.iter().find(|&&input| db.maybe_changed_after(input, verified_at));
if let Some(input) = changed_input {
debug!("validate_memoized_value: `{:?}` may have changed", input);
trace!("validate_memoized_value: `{:?}` may have changed", input);
return false;
}
@ -775,7 +786,7 @@ where
/// True if this memo is known not to have changed based on its durability.
fn check_durability(&self, runtime: &Runtime) -> bool {
let last_changed = runtime.last_changed_revision(self.revisions.durability);
debug!(
trace!(
"check_durability(last_changed={:?} <= verified_at={:?}) = {:?}",
last_changed,
self.verified_at,

14
crates/ra-salsa/src/input.rs
View File

@ -14,7 +14,7 @@ use crate::{DatabaseKeyIndex, QueryDb};
use indexmap::map::Entry;
use parking_lot::RwLock;
use std::iter;
use tracing::debug;
use tracing::trace;
/// Input queries store the result plus a list of the other queries
/// that they invoked. This means we can avoid recomputing them when
@ -73,11 +73,11 @@ where
return true;
};
debug!("maybe_changed_after(slot={:?}, revision={:?})", Q::default(), revision,);
trace!("maybe_changed_after(slot={:?}, revision={:?})", Q::default(), revision,);
let changed_at = slot.stamped_value.read().changed_at;
debug!("maybe_changed_after: changed_at = {:?}", changed_at);
trace!("maybe_changed_after: changed_at = {:?}", changed_at);
changed_at > revision
}
@ -140,7 +140,7 @@ where
Q: Query,
{
fn set(&self, runtime: &mut Runtime, key: &Q::Key, value: Q::Value, durability: Durability) {
tracing::debug!("{:?}({:?}) = {:?} ({:?})", Q::default(), key, value, durability);
tracing::trace!("{:?}({:?}) = {:?} ({:?})", Q::default(), key, value, durability);
// The value is changing, so we need a new revision (*). We also
// need to update the 'last changed' revision by invoking
@ -234,14 +234,14 @@ where
) -> bool {
debug_assert!(revision < db.salsa_runtime().current_revision());
debug!("maybe_changed_after(slot={:?}, revision={:?})", Q::default(), revision,);
trace!("maybe_changed_after(slot={:?}, revision={:?})", Q::default(), revision,);
let Some(value) = &*self.slot.stamped_value.read() else {
return true;
};
let changed_at = value.changed_at;
debug!("maybe_changed_after: changed_at = {:?}", changed_at);
trace!("maybe_changed_after: changed_at = {:?}", changed_at);
changed_at > revision
}
@ -298,7 +298,7 @@ where
Q: Query<Key = ()>,
{
fn set(&self, runtime: &mut Runtime, (): &Q::Key, value: Q::Value, durability: Durability) {
tracing::debug!("{:?} = {:?} ({:?})", Q::default(), value, durability);
tracing::trace!("{:?} = {:?} ({:?})", Q::default(), value, durability);
// The value is changing, so we need a new revision (*). We also
// need to update the 'last changed' revision by invoking

4
crates/ra-salsa/src/lib.rs
View File

@ -79,7 +79,7 @@ pub trait Database: plumbing::DatabaseOps {
let current_revision = runtime.current_revision();
let pending_revision = runtime.pending_revision();
tracing::debug!(
tracing::trace!(
"unwind_if_cancelled: current_revision={:?}, pending_revision={:?}",
current_revision,
pending_revision
@ -684,7 +684,7 @@ impl Cycle {
}
pub(crate) fn throw(self) -> ! {
tracing::debug!("throwing cycle {:?}", self);
tracing::trace!("throwing cycle {:?}", self);
std::panic::resume_unwind(Box::new(self))
}

24
crates/ra-salsa/src/lru.rs
View File

@ -103,11 +103,11 @@ where
/// Records that `node` was used. This may displace an old node (if the LRU limits are
pub(crate) fn record_use(&self, node: &Arc<Node>) -> Option<Arc<Node>> {
tracing::debug!("record_use(node={:?})", node);
tracing::trace!("record_use(node={:?})", node);
// Load green zone length and check if the LRU cache is even enabled.
let green_zone = self.green_zone.load(Ordering::Acquire);
tracing::debug!("record_use: green_zone={}", green_zone);
tracing::trace!("record_use: green_zone={}", green_zone);
if green_zone == 0 {
return None;
}
@ -115,7 +115,7 @@ where
// Find current index of list (if any) and the current length
// of our green zone.
let index = node.lru_index().load();
tracing::debug!("record_use: index={}", index);
tracing::trace!("record_use: index={}", index);
// Already a member of the list, and in the green zone -- nothing to do!
if index < green_zone {
@ -162,9 +162,9 @@ where
let entries =
std::mem::replace(&mut self.entries, Vec::with_capacity(self.end_red_zone as usize));
tracing::debug!("green_zone = {:?}", self.green_zone());
tracing::debug!("yellow_zone = {:?}", self.yellow_zone());
tracing::debug!("red_zone = {:?}", self.red_zone());
tracing::trace!("green_zone = {:?}", self.green_zone());
tracing::trace!("yellow_zone = {:?}", self.yellow_zone());
tracing::trace!("red_zone = {:?}", self.red_zone());
// We expect to resize when the LRU cache is basically empty.
// So just forget all the old LRU indices to start.
@ -180,7 +180,7 @@ where
/// list may displace an old member of the red zone, in which case
/// that is returned.
fn record_use(&mut self, node: &Arc<Node>) -> Option<Arc<Node>> {
tracing::debug!("record_use(node={:?})", node);
tracing::trace!("record_use(node={:?})", node);
// NB: When this is invoked, we have typically already loaded
// the LRU index (to check if it is in green zone). But that
@ -212,7 +212,7 @@ where
if len < self.end_red_zone {
self.entries.push(node.clone());
node.lru_index().store(len);
tracing::debug!("inserted node {:?} at {}", node, len);
tracing::trace!("inserted node {:?} at {}", node, len);
return self.record_use(node);
}
@ -220,7 +220,7 @@ where
// zone and then promoting.
let victim_index = self.pick_index(self.red_zone());
let victim_node = std::mem::replace(&mut self.entries[victim_index as usize], node.clone());
tracing::debug!("evicting red node {:?} from {}", victim_node, victim_index);
tracing::trace!("evicting red node {:?} from {}", victim_node, victim_index);
victim_node.lru_index().clear();
self.promote_red_to_green(node, victim_index);
Some(victim_node)
@ -241,7 +241,7 @@ where
// going to invoke `self.promote_yellow` next, and it will get
// updated then.
let yellow_index = self.pick_index(self.yellow_zone());
tracing::debug!(
tracing::trace!(
"demoting yellow node {:?} from {} to red at {}",
self.entries[yellow_index as usize],
yellow_index,
@ -265,7 +265,7 @@ where
// Pick a yellow at random and switch places with it.
let green_index = self.pick_index(self.green_zone());
tracing::debug!(
tracing::trace!(
"demoting green node {:?} from {} to yellow at {}",
self.entries[green_index as usize],
green_index,
@ -275,7 +275,7 @@ where
self.entries[yellow_index as usize].lru_index().store(yellow_index);
node.lru_index().store(green_index);
tracing::debug!("promoted {:?} to green index {}", node, green_index);
tracing::trace!("promoted {:?} to green index {}", node, green_index);
}
fn pick_index(&mut self, zone: std::ops::Range<u16>) -> u16 {

12
crates/ra-salsa/src/runtime.rs
View File

@ -9,7 +9,7 @@ use parking_lot::{Mutex, RwLock};
use std::hash::Hash;
use std::panic::panic_any;
use std::sync::atomic::{AtomicU32, Ordering};
use tracing::debug;
use tracing::trace;
use triomphe::{Arc, ThinArc};
mod dependency_graph;
@ -177,7 +177,7 @@ impl Runtime {
where
F: FnOnce(Revision) -> Option<Durability>,
{
tracing::debug!("increment_revision()");
tracing::trace!("increment_revision()");
if !self.permits_increment() {
panic!("increment_revision invoked during a query computation");
@ -196,7 +196,7 @@ impl Runtime {
let new_revision = current_revision.next();
debug!("increment_revision: incremented to {:?}", new_revision);
trace!("increment_revision: incremented to {:?}", new_revision);
if let Some(d) = op(new_revision) {
for rev in &self.shared_state.revisions[1..=d.index()] {
@ -267,7 +267,7 @@ impl Runtime {
database_key_index: DatabaseKeyIndex,
to_id: RuntimeId,
) {
debug!("unblock_cycle_and_maybe_throw(database_key={:?})", database_key_index);
trace!("unblock_cycle_and_maybe_throw(database_key={:?})", database_key_index);
let mut from_stack = self.local_state.take_query_stack();
let from_id = self.id();
@ -305,7 +305,7 @@ impl Runtime {
Cycle::new(Arc::new(v))
};
debug!("cycle {:?}, cycle_query {:#?}", cycle.debug(db), cycle_query,);
trace!("cycle {:?}, cycle_query {:#?}", cycle.debug(db), cycle_query,);
// We can remove the cycle participants from the list of dependencies;
// they are a strongly connected component (SCC) and we only care about
@ -323,7 +323,7 @@ impl Runtime {
CycleRecoveryStrategy::Fallback => false,
})
.for_each(|aq| {
debug!("marking {:?} for fallback", aq.database_key_index.debug(db));
trace!("marking {:?} for fallback", aq.database_key_index.debug(db));
aq.take_inputs_from(&cycle_query);
assert!(aq.cycle.is_none());
aq.cycle = Some(cycle.clone());

4
crates/ra-salsa/src/runtime/local_state.rs
View File

@ -1,4 +1,4 @@
use tracing::debug;
use tracing::trace;
use triomphe::ThinArc;
use crate::durability::Durability;
@ -78,7 +78,7 @@ impl LocalState {
durability: Durability,
changed_at: Revision,
) {
debug!(
trace!(
"report_query_read_and_unwind_if_cycle_resulted(input={:?}, durability={:?}, changed_at={:?})",
input, durability, changed_at
);