noth/surrealpatch
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Improve debug experience on debug builds ()

Browse source
This commit is contained in:
Przemyslaw Hugh Kaznowski 2024-03-12 09:27:28 +00:00 committed by GitHub
parent 0e3fb7b365
commit b62011bfec
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
5 changed files with 125 additions and 61 deletions

10
core/src/key/debug.rs
View file

@ -1,12 +1,16 @@
/// Debug purposes only. It may be used in logs. Not for key handling in implementation code.
use crate::kvs::Key;
/// Helpers for debugging keys
/// sprint_key converts a key to an escaped string.
/// This is used for logging and debugging tests and should not be used in implementation code.
pub fn sprint_key(key: &Key) -> String {
key.iter()
#[doc(hidden)]
pub fn sprint_key<T>(key: &T) -> String
where
T: AsRef<[u8]>,
{
key.as_ref()
.iter()
.flat_map(|&byte| std::ascii::escape_default(byte))
.map(|byte| byte as char)
.collect::<String>()

64
core/src/kvs/tx.rs
View file

@ -29,6 +29,7 @@ use crate::dbs::node::ClusterMembership;
use crate::dbs::node::Timestamp;
use crate::err::Error;
use crate::idg::u32::U32;
use crate::key::debug::sprint_key;
use crate::key::error::KeyCategory;
use crate::key::key_req::KeyRequirements;
use crate::kvs::cache::Cache;
@ -358,8 +359,9 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
let key = key.into();
#[cfg(debug_assertions)]
trace!("Del {:?}", key);
trace!("Del {:?}", sprint_key(&key));
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -405,10 +407,10 @@ impl Transaction {
#[allow(unused_variables)]
pub async fn exi<K>(&mut self, key: K) -> Result<bool, Error>
where
K: Into<Key> + Debug,
K: Into<Key> + Debug + AsRef<[u8]>,
{
#[cfg(debug_assertions)]
trace!("Exi {:?}", key);
trace!("Exi {:?}", sprint_key(&key));
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -456,8 +458,9 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
let key = key.into();
#[cfg(debug_assertions)]
trace!("Get {:?}", key);
trace!("Get {:?}", sprint_key(&key));
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -506,8 +509,9 @@ impl Transaction {
K: Into<Key> + Debug,
V: Into<Val> + Debug,
{
let key = key.into();
#[cfg(debug_assertions)]
trace!("Set {:?} => {:?}", key, val);
trace!("Set {:?} => {:?}", sprint_key(&key), val);
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -559,8 +563,10 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
// We convert to byte slice as its easier at this level
let key = key.into();
#[cfg(debug_assertions)]
trace!("Get Timestamp {:?}", key);
trace!("Get Timestamp {:?}", sprint_key(&key));
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -638,8 +644,6 @@ impl Transaction {
K: Into<Key> + Debug,
V: Into<Val> + Debug,
{
#[cfg(debug_assertions)]
trace!("Set {:?} <ts> {:?} => {:?}", prefix, suffix, val);
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -755,8 +759,12 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
let rng = Range {
start: rng.start.into(),
end: rng.end.into(),
};
#[cfg(debug_assertions)]
trace!("Scan {:?} - {:?}", rng.start, rng.end);
trace!("Scan {:?} - {:?}", sprint_key(&rng.start), sprint_key(&rng.end));
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -808,10 +816,10 @@ impl Transaction {
batch_limit: u32,
) -> Result<ScanResult<K>, Error>
where
K: Into<Key> + From<Vec<u8>> + Debug + Clone,
K: Into<Key> + From<Vec<u8>> + AsRef<[u8]> + Debug + Clone,
{
#[cfg(debug_assertions)]
trace!("Scan {:?} - {:?}", page.range.start, page.range.end);
trace!("Scan {:?} - {:?}", sprint_key(&page.range.start), sprint_key(&page.range.end));
let range = page.range.clone();
let res = match self {
#[cfg(feature = "kv-mem")]
@ -883,8 +891,9 @@ impl Transaction {
K: Into<Key> + Debug,
V: Into<Val> + Debug,
{
let key = key.into();
#[cfg(debug_assertions)]
trace!("Putc {:?} if {:?} => {:?}", key, chk, val);
trace!("Putc {:?} if {:?} => {:?}", sprint_key(&key), chk, val);
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -933,8 +942,9 @@ impl Transaction {
K: Into<Key> + Debug,
V: Into<Val> + Debug,
{
let key = key.into();
#[cfg(debug_assertions)]
trace!("Delc {:?} if {:?}", key, chk);
trace!("Delc {:?} if {:?}", sprint_key(&key), chk);
match self {
#[cfg(feature = "kv-mem")]
Transaction {
@ -987,10 +997,10 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
#[cfg(debug_assertions)]
trace!("Getr {:?}..{:?} (limit: {limit})", rng.start, rng.end);
let beg: Key = rng.start.into();
let end: Key = rng.end.into();
#[cfg(debug_assertions)]
trace!("Getr {:?}..{:?} (limit: {limit})", sprint_key(&beg), sprint_key(&end));
let mut out: Vec<(Key, Val)> = vec![];
let mut next_page = Some(ScanPage {
range: beg..end,
@ -1021,8 +1031,12 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
let rng = Range {
start: rng.start.into(),
end: rng.end.into(),
};
#[cfg(debug_assertions)]
trace!("Delr {:?}..{:?} (limit: {limit})", rng.start, rng.end);
trace!("Delr {:?}..{:?} (limit: {limit})", sprint_key(&rng.start), sprint_key(&rng.end));
match self {
#[cfg(feature = "kv-tikv")]
Transaction {
@ -1077,10 +1091,10 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
#[cfg(debug_assertions)]
trace!("Getp {:?} (limit: {limit})", key);
let beg: Key = key.into();
let end: Key = beg.clone().add(0xff);
#[cfg(debug_assertions)]
trace!("Getp {:?}-{:?} (limit: {limit})", sprint_key(&beg), sprint_key(&end));
let mut out: Vec<(Key, Val)> = vec![];
// Start processing
let mut next_page = Some(ScanPage {
@ -1111,10 +1125,10 @@ impl Transaction {
where
K: Into<Key> + Debug,
{
#[cfg(debug_assertions)]
trace!("Delp {:?} (limit: {limit})", key);
let beg: Key = key.into();
let end: Key = beg.clone().add(0xff);
#[cfg(debug_assertions)]
trace!("Delp {:?}-{:?} (limit: {limit})", sprint_key(&beg), sprint_key(&end));
let min = beg.clone();
let max = end.clone();
self.delr(min..max, limit).await?;
@ -1342,7 +1356,7 @@ impl Transaction {
let key = crate::key::table::lq::new(ns, db, tb, live_stm.id.0);
let key_enc = crate::key::table::lq::Lq::encode(&key)?;
#[cfg(debug_assertions)]
trace!("putc_tblq ({:?}): key={:?}", &live_stm.id, crate::key::debug::sprint_key(&key_enc));
trace!("putc_tblq ({:?}): key={:?}", &live_stm.id, sprint_key(&key_enc));
self.putc(key_enc, live_stm, expected).await
}
@ -2006,7 +2020,7 @@ impl Transaction {
) -> Result<LiveStatement, Error> {
let key = crate::key::table::lq::new(ns, db, tb, *lv);
let key_enc = crate::key::table::lq::Lq::encode(&key)?;
trace!("Getting lv ({:?}) {:?}", lv, crate::key::debug::sprint_key(&key_enc));
trace!("Getting lv ({:?}) {:?}", lv, sprint_key(&key_enc));
let val = self.get(key_enc).await?.ok_or(Error::LvNotFound {
value: lv.to_string(),
})?;
@ -2024,7 +2038,7 @@ impl Transaction {
) -> Result<DefineEventStatement, Error> {
let key = crate::key::table::ev::new(ns, db, tb, ev);
let key_enc = crate::key::table::ev::Ev::encode(&key)?;
trace!("Getting ev ({:?}) {:?}", ev, crate::key::debug::sprint_key(&key_enc));
trace!("Getting ev ({:?}) {:?}", ev, sprint_key(&key_enc));
let val = self.get(key_enc).await?.ok_or(Error::EvNotFound {
value: ev.to_string(),
})?;
@ -2042,7 +2056,7 @@ impl Transaction {
) -> Result<DefineFieldStatement, Error> {
let key = crate::key::table::fd::new(ns, db, tb, fd);
let key_enc = crate::key::table::fd::Fd::encode(&key)?;
trace!("Getting fd ({:?}) {:?}", fd, crate::key::debug::sprint_key(&key_enc));
trace!("Getting fd ({:?}) {:?}", fd, sprint_key(&key_enc));
let val = self.get(key_enc).await?.ok_or(Error::FdNotFound {
value: fd.to_string(),
})?;
@ -2060,7 +2074,7 @@ impl Transaction {
) -> Result<DefineIndexStatement, Error> {
let key = crate::key::table::ix::new(ns, db, tb, ix);
let key_enc = crate::key::table::ix::Ix::encode(&key)?;
trace!("Getting ix ({:?}) {:?}", ix, crate::key::debug::sprint_key(&key_enc));
trace!("Getting ix ({:?}) {:?}", ix, sprint_key(&key_enc));
let val = self.get(key_enc).await?.ok_or(Error::IxNotFound {
value: ix.to_string(),
})?;

6
src/cli/mod.rs
View file

@ -15,7 +15,7 @@ mod version;
mod version_client;
use crate::cli::version_client::VersionClient;
use crate::cnf::{LOGO, PKG_VERSION};
use crate::cnf::{DEBUG_BUILD_WARNING, LOGO, PKG_VERSION};
use crate::env::RELEASE;
use clap::{Parser, Subcommand};
pub use config::CF;
@ -99,6 +99,10 @@ pub async fn init() -> ExitCode {
.unwrap();
// Parse the CLI arguments
let args = Cli::parse();
#[cfg(debug_assertions)]
println!("{DEBUG_BUILD_WARNING}");
// After parsing arguments, we check the version online
if args.online_version_check {
let client = version_client::new(Some(Duration::from_millis(500))).unwrap();

8
src/cnf/mod.rs
View file

@ -13,6 +13,14 @@ Y88b d88P Y88b 888 888 888 Y8b. 888 888 888 888 .d88P 888 d88P
";
pub const DEBUG_BUILD_WARNING: &str = "\
┌─────────────────────────────────────────────────────────────────────────────┐
│ !!! THIS IS A DEBUG BUILD !!! │
│ Debug builds are not intended for production use and include │
│ tooling and features that we would not recommend people run on │
│ live data. │
└─────────────────────────────────────────────────────────────────────────────┘";
/// The publicly visible name of the server
pub const PKG_NAME: &str = "surrealdb";

98
tests/cli_integration.rs
View file

@ -2,6 +2,7 @@
mod common;
mod cli_integration {
use crate::remove_debug_info;
use assert_fs::prelude::{FileTouch, FileWriteStr, PathChild};
use common::Format;
use common::Socket;
@ -59,6 +60,14 @@ mod cli_integration {
assert!(common::run("version --turbo").output().is_err());
}
fn debug_builds_contain_debug_message(addr: &str, creds: &str, ns: &Ulid, db: &Ulid) {
info!("* Debug builds contain debug message");
let args =
format!("sql --conn http://{addr} {creds} --ns {ns} --db {db} --multi --hide-welcome");
let res = common::run(&args).input("CREATE not_a_table:not_a_record;\n").output().unwrap();
assert!(res.contains("Debug builds are not intended for production use"));
}
#[test(tokio::test)]
async fn all_commands() {
// Commands without credentials when auth is disabled, should succeed
@ -73,16 +82,16 @@ mod cli_integration {
let ns = Ulid::new();
let db = Ulid::new();
#[cfg(debug_assertions)]
debug_builds_contain_debug_message(&addr, creds, &ns, &db);
info!("* Create a record");
{
let args = format!(
"sql --conn http://{addr} {creds} --ns {ns} --db {db} --multi --hide-welcome"
);
assert_eq!(
common::run(&args).input("CREATE thing:one;\n").output(),
Ok("[[{ id: thing:one }]]\n\n".to_owned()),
"failed to send sql: {args}"
);
let output = common::run(&args).input("CREATE thing:one;\n").output().unwrap();
assert!(output.contains("[[{ id: thing:one }]]\n\n"), "failed to send sql: {args}");
}
info!("* Export to stdout");
@ -117,8 +126,9 @@ mod cli_integration {
"sql --conn http://{addr} {creds} --ns {ns} --db {db2} --pretty --hide-welcome"
);
let output = common::run(&args).input("SELECT * FROM thing;\n").output().unwrap();
let output = remove_debug_info(output);
let (line1, rest) = output.split_once('\n').expect("response to have multiple lines");
assert!(line1.starts_with("-- Query 1"));
assert!(line1.starts_with("-- Query 1"), "Expected on {line1}, and rest was {rest}");
assert!(line1.contains("execution time"));
assert_eq!(rest, "[\n\t{\n\t\tid: thing:one\n\t}\n]\n\n", "failed to send sql: {args}");
}
@ -482,8 +492,9 @@ mod cli_integration {
// Commands with credentials for different auth levels
let (addr, server) = common::start_server_with_defaults().await.unwrap();
let creds = format!("--user {USER} --pass {PASS}");
let ns = Ulid::new();
let db = Ulid::new();
// Prefix with 'a' so that we don't start with a number and cause a parsing error
let ns = format!("a{}", Ulid::new());
let db = format!("a{}", Ulid::new());
info!("* Create users with identical credentials at ROOT, NS and DB levels");
{
@ -621,11 +632,10 @@ mod cli_integration {
let args = format!(
"sql --conn http://{addr} {creds} --ns {ns} --db {db} --multi --hide-welcome"
);
assert_eq!(
common::run(&args).input("DEFINE TABLE thing CHANGEFEED 1s;\n").output(),
Ok("[NONE]\n\n".to_owned()),
"failed to send sql: {args}"
);
let output =
common::run(&args).input("DEFINE TABLE thing CHANGEFEED 1s;\n").output().unwrap();
let output = remove_debug_info(output);
assert_eq!(output, "[NONE]\n\n".to_owned(), "failed to send sql: {args}");
}
info!("* Create a record");
@ -633,9 +643,14 @@ mod cli_integration {
let args = format!(
"sql --conn http://{addr} {creds} --ns {ns} --db {db} --multi --hide-welcome"
);
let output = common::run(&args)
.input("BEGIN TRANSACTION; CREATE thing:one; COMMIT;\n")
.output()
.unwrap();
let output = remove_debug_info(output);
assert_eq!(
common::run(&args).input("BEGIN TRANSACTION; CREATE thing:one; COMMIT;\n").output(),
Ok("[[{ id: thing:one }]]\n\n".to_owned()),
output,
"[[{ id: thing:one }]]\n\n".to_owned(),
"failed to send sql: {args}"
);
}
@ -646,20 +661,26 @@ mod cli_integration {
"sql --conn http://{addr} {creds} --ns {ns} --db {db} --multi --hide-welcome"
);
if FFLAGS.change_feed_live_queries.enabled() {
let output = common::run(&args)
.input("SHOW CHANGES FOR TABLE thing SINCE 0 LIMIT 10;\n")
.output()
.unwrap();
let output = remove_debug_info(output);
assert_eq!(
common::run(&args)
.input("SHOW CHANGES FOR TABLE thing SINCE 0 LIMIT 10;\n")
.output(),
Ok("[[{ changes: [{ define_table: { name: 'thing' } }], versionstamp: 65536 }, { changes: [{ create: { id: thing:one } }], versionstamp: 131072 }]]\n\n"
.to_owned()),
output,
"[[{ changes: [{ define_table: { name: 'thing' } }], versionstamp: 65536 }, { changes: [{ create: { id: thing:one } }], versionstamp: 131072 }]]\n\n"
.to_owned(),
"failed to send sql: {args}");
} else {
let output = common::run(&args)
.input("SHOW CHANGES FOR TABLE thing SINCE 0 LIMIT 10;\n")
.output()
.unwrap();
let output = remove_debug_info(output);
assert_eq!(
common::run(&args)
.input("SHOW CHANGES FOR TABLE thing SINCE 0 LIMIT 10;\n")
.output(),
Ok("[[{ changes: [{ define_table: { name: 'thing' } }], versionstamp: 65536 }, { changes: [{ update: { id: thing:one } }], versionstamp: 131072 }]]\n\n"
.to_owned()),
output,
"[[{ changes: [{ define_table: { name: 'thing' } }], versionstamp: 65536 }, { changes: [{ update: { id: thing:one } }], versionstamp: 131072 }]]\n\n"
.to_owned(),
"failed to send sql: {args}" );
}
};
@ -671,13 +692,12 @@ mod cli_integration {
let args = format!(
"sql --conn http://{addr} {creds} --ns {ns} --db {db} --multi --hide-welcome"
);
assert_eq!(
common::run(&args)
.input("SHOW CHANGES FOR TABLE thing SINCE 0 LIMIT 10;\n")
.output(),
Ok("[[]]\n\n".to_owned()),
"failed to send sql: {args}"
);
let output = common::run(&args)
.input("SHOW CHANGES FOR TABLE thing SINCE 0 LIMIT 10;\n")
.output()
.unwrap();
let output = remove_debug_info(output);
assert_eq!(output, "[[]]\n\n".to_owned(), "failed to send sql: {args}");
}
server.finish()
}
@ -1076,3 +1096,17 @@ mod cli_integration {
}
}
}
fn remove_debug_info(output: String) -> String {
// Look... sometimes you just gotta copy paste
let output_warning = "\
┌─────────────────────────────────────────────────────────────────────────────┐
│ !!! THIS IS A DEBUG BUILD !!! │
│ Debug builds are not intended for production use and include │
│ tooling and features that we would not recommend people run on │
│ live data. │
└─────────────────────────────────────────────────────────────────────────────┘
";
// The last line in the above is important
output.replace(output_warning, "")
}