Skip to content

Commit 2d77ca8

Browse files
committed
add json output
Signed-off-by: Connor Tsui <connor.tsui20@gmail.com>
1 parent e634e31 commit 2d77ca8

10 files changed

Lines changed: 98 additions & 27 deletions

File tree

benchmarks/compress-bench/src/main.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@ use regex::Regex;
1515
use vortex::utils::aliases::hash_map::HashMap;
1616
use vortex_bench::Engine;
1717
use vortex_bench::Format;
18+
use vortex_bench::LogFormat;
1819
use vortex_bench::Target;
1920
use vortex_bench::compress::CompressMeasurements;
2021
use vortex_bench::compress::CompressOp;
@@ -75,7 +76,7 @@ struct Args {
7576
async fn main() -> anyhow::Result<()> {
7677
let args = Args::parse();
7778

78-
setup_logging_and_tracing(args.verbose, args.tracing)?;
79+
setup_logging_and_tracing(args.verbose, args.tracing, LogFormat::Text)?;
7980

8081
run_compress(
8182
args.iterations,

benchmarks/datafusion-bench/src/main.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@ use vortex_bench::BenchmarkArg;
3232
use vortex_bench::CompactionStrategy;
3333
use vortex_bench::Engine;
3434
use vortex_bench::Format;
35+
use vortex_bench::LogFormat;
3536
use vortex_bench::Opt;
3637
use vortex_bench::Opts;
3738
use vortex_bench::SESSION;
@@ -110,7 +111,7 @@ async fn main() -> anyhow::Result<()> {
110111
let opts = Opts::from(args.options);
111112

112113
set_join_set_tracer(get_static_tracer())?;
113-
setup_logging_and_tracing(args.verbose, args.tracing)?;
114+
setup_logging_and_tracing(args.verbose, args.tracing, LogFormat::Text)?;
114115

115116
let benchmark = create_benchmark(args.benchmark, &opts)?;
116117

benchmarks/duckdb-bench/src/main.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ use vortex_bench::BenchmarkArg;
1414
use vortex_bench::CompactionStrategy;
1515
use vortex_bench::Engine;
1616
use vortex_bench::Format;
17+
use vortex_bench::LogFormat;
1718
use vortex_bench::Opt;
1819
use vortex_bench::Opts;
1920
use vortex_bench::conversions::convert_parquet_directory_to_vortex;
@@ -87,7 +88,7 @@ fn main() -> anyhow::Result<()> {
8788
let args = Args::parse();
8889
let opts = Opts::from(args.options);
8990

90-
setup_logging_and_tracing(args.verbose, args.tracing)?;
91+
setup_logging_and_tracing(args.verbose, args.tracing, LogFormat::Text)?;
9192

9293
let benchmark = create_benchmark(args.benchmark, &opts)?;
9394

benchmarks/lance-bench/src/main.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ use vortex_bench::Benchmark;
1818
use vortex_bench::BenchmarkArg;
1919
use vortex_bench::Engine;
2020
use vortex_bench::Format;
21+
use vortex_bench::LogFormat;
2122
use vortex_bench::Opt;
2223
use vortex_bench::Opts;
2324
use vortex_bench::create_benchmark;
@@ -74,7 +75,7 @@ async fn main() -> anyhow::Result<()> {
7475
let args = Args::parse();
7576
let opts = Opts::from(args.options);
7677

77-
setup_logging_and_tracing(args.verbose, args.tracing)?;
78+
setup_logging_and_tracing(args.verbose, args.tracing, LogFormat::Text)?;
7879

7980
let benchmark = create_benchmark(args.benchmark, &opts)?;
8081

benchmarks/random-access-bench/src/main.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ use rand_distr::Distribution;
1616
use rand_distr::Exp;
1717
use vortex_bench::Engine;
1818
use vortex_bench::Format;
19+
use vortex_bench::LogFormat;
1920
use vortex_bench::Target;
2021
use vortex_bench::create_output_writer;
2122
use vortex_bench::datasets::feature_vectors::FeatureVectorsData;
@@ -190,7 +191,7 @@ struct Args {
190191
async fn main() -> Result<()> {
191192
let args = Args::parse();
192193

193-
setup_logging_and_tracing(args.verbose, args.tracing)?;
194+
setup_logging_and_tracing(args.verbose, args.tracing, LogFormat::Text)?;
194195

195196
let datasets: Vec<Box<dyn BenchDataset>> = args
196197
.datasets

vortex-bench/Cargo.toml

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,7 @@ tracing = { workspace = true }
5353
tracing-perfetto = { workspace = true }
5454
tracing-subscriber = { workspace = true, features = [
5555
"env-filter",
56+
"json",
5657
"tracing-log",
5758
] }
5859
url = { workspace = true }

vortex-bench/src/bin/data-gen.rs

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ use vortex_bench::Benchmark;
1717
use vortex_bench::BenchmarkArg;
1818
use vortex_bench::CompactionStrategy;
1919
use vortex_bench::Format;
20+
use vortex_bench::LogFormat;
2021
use vortex_bench::Opt;
2122
use vortex_bench::Opts;
2223
use vortex_bench::conversions::convert_parquet_directory_to_vortex;
@@ -37,6 +38,11 @@ struct Args {
3738
#[arg(long)]
3839
tracing: bool,
3940

41+
/// Format for the primary stderr log sink. `text` is the default human
42+
/// readable format; `json` emits newline-delimited JSON suitable for `jq`.
43+
#[arg(long, value_enum, default_value_t = LogFormat::Text)]
44+
log_format: LogFormat,
45+
4046
#[arg(long, value_delimiter = ',', value_parser = value_parser!(Format))]
4147
formats: Vec<Format>,
4248

@@ -49,7 +55,7 @@ async fn main() -> anyhow::Result<()> {
4955
let args = Args::parse();
5056
let opts = Opts::from(args.options);
5157

52-
setup_logging_and_tracing(args.verbose, args.tracing)?;
58+
setup_logging_and_tracing(args.verbose, args.tracing, args.log_format)?;
5359

5460
let benchmark = create_benchmark(args.benchmark, &opts)?;
5561

vortex-bench/src/conversions.rs

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -179,6 +179,11 @@ pub async fn convert_parquet_directory_to_vortex(
179179
let parquet_file_path = parquet_path.join(format!("{filename}.parquet"));
180180
let output_path = vortex_dir.join(format!("{filename}.{}", format.ext()));
181181

182+
let span = tracing::info_span!(
183+
"compress_file",
184+
file = %filename,
185+
strategy = ?compaction,
186+
);
182187
tokio::spawn(
183188
async move {
184189
idempotent_async(output_path.as_path(), move |vtx_file| async move {
@@ -192,7 +197,7 @@ pub async fn convert_parquet_directory_to_vortex(
192197
.await
193198
.expect("Failed to write Vortex file")
194199
}
195-
.in_current_span(),
200+
.instrument(span),
196201
)
197202
})
198203
.buffer_unordered(concurrency)

vortex-bench/src/utils/logging.rs

Lines changed: 72 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -4,34 +4,88 @@
44
use std::fs::File;
55
use std::io::IsTerminal;
66

7+
use clap::ValueEnum;
78
use tracing::level_filters::LevelFilter;
89
use tracing_perfetto::PerfettoLayer;
910
use tracing_subscriber::EnvFilter;
11+
use tracing_subscriber::Layer;
1012
use tracing_subscriber::prelude::*;
1113

12-
/// Initialize logging/tracing for a benchmark
13-
pub fn setup_logging_and_tracing(verbose: bool, tracing: bool) -> anyhow::Result<()> {
14+
/// Format for the primary stderr log sink.
15+
///
16+
/// Selects between a human-oriented text formatter and a newline-delimited JSON
17+
/// formatter. The two are mutually exclusive — pick whichever matches how you'll
18+
/// consume the output. The choice is orthogonal to
19+
/// [`setup_logging_and_tracing`]'s `tracing` flag, which controls a separate
20+
/// Perfetto trace file and is unaffected by the format selected here.
21+
///
22+
/// See the crate-level documentation of `vortex-compressor` for the full
23+
/// inventory of fields emitted under each tracing target.
24+
#[derive(Copy, Clone, Debug, Default, PartialEq, Eq, ValueEnum)]
25+
pub enum LogFormat {
26+
/// Human-readable single-line records, with level, file, and line prefixes.
27+
/// ANSI coloring is enabled automatically when stderr is a terminal. This
28+
/// is the default and matches the historical behavior of this crate.
29+
#[default]
30+
Text,
31+
/// Newline-delimited JSON — one complete JSON object per event, written to
32+
/// stderr. Each record includes the event fields as typed values plus the
33+
/// full span stack under the `spans` key, making it suitable for piping
34+
/// into `jq` or ingestion into a log aggregator.
35+
///
36+
/// Not to be confused with the Perfetto trace format emitted when the
37+
/// `tracing` flag is set — that is a single-document Chrome Trace Event
38+
/// file designed to be loaded into the Perfetto UI, and cannot be
39+
/// meaningfully filtered line-by-line.
40+
Json,
41+
}
42+
43+
/// Initialize logging/tracing for a benchmark.
44+
///
45+
/// - `verbose`: when `RUST_LOG` is unset, raises the default filter from `INFO`
46+
/// to `TRACE`. Has no effect when `RUST_LOG` is set (the env var wins).
47+
/// - `perfetto`: when `true`, additionally attaches a
48+
/// [`tracing_perfetto::PerfettoLayer`] that writes span begin/end events to
49+
/// `trace.json` in the current directory. Intended to be loaded into the
50+
/// Perfetto UI for flamegraph visualization.
51+
/// - `format`: controls the primary stderr sink's formatting. See [`LogFormat`].
52+
pub fn setup_logging_and_tracing(
53+
verbose: bool,
54+
perfetto: bool,
55+
format: LogFormat,
56+
) -> anyhow::Result<()> {
1457
let filter = default_env_filter(verbose);
1558

16-
let fmt_layer = tracing_subscriber::fmt::layer()
17-
.with_writer(std::io::stderr)
18-
.with_level(true)
19-
.with_file(true)
20-
.with_line_number(true)
21-
.with_ansi(std::io::stderr().is_terminal());
59+
let perfetto_layer = perfetto
60+
.then(|| {
61+
Ok::<_, anyhow::Error>(
62+
PerfettoLayer::new(File::create("trace.json")?).with_debug_annotations(true),
63+
)
64+
})
65+
.transpose()?;
66+
67+
// `fmt::layer()` and `fmt::layer().json()` produce different concrete
68+
// types, so we erase each to a `dyn Layer` via `.boxed()` and keep the
69+
// registry chain uniform.
70+
let fmt_layer: Box<dyn Layer<_> + Send + Sync> = match format {
71+
LogFormat::Text => tracing_subscriber::fmt::layer()
72+
.with_writer(std::io::stderr)
73+
.with_level(true)
74+
.with_file(true)
75+
.with_line_number(true)
76+
.with_ansi(std::io::stderr().is_terminal())
77+
.boxed(),
78+
LogFormat::Json => tracing_subscriber::fmt::layer()
79+
.json()
80+
.with_writer(std::io::stderr)
81+
.with_current_span(true)
82+
.with_span_list(true)
83+
.boxed(),
84+
};
2285

2386
tracing_subscriber::registry()
2487
.with(filter)
25-
.with(
26-
tracing
27-
.then(|| {
28-
Ok::<_, anyhow::Error>(
29-
PerfettoLayer::new(File::create("trace.json")?)
30-
.with_debug_annotations(true),
31-
)
32-
})
33-
.transpose()?,
34-
)
88+
.with(perfetto_layer)
3589
.with(fmt_layer)
3690
.init();
3791

vortex-compressor/src/compressor.rs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -358,7 +358,7 @@ impl CascadingCompressor {
358358
/// [`matches`]: Scheme::matches
359359
/// [`stats_options`]: Scheme::stats_options
360360
/// [`choose_scheme`]: Self::choose_scheme
361-
#[expect(clippy::cognitive_complexity, reason = "tracing")]
361+
#[allow(clippy::cognitive_complexity, reason = "tracing sometimes enabled")]
362362
fn choose_and_compress(
363363
&self,
364364
canonical: Canonical,
@@ -542,7 +542,7 @@ impl CascadingCompressor {
542542
/// registration order (earlier in the list wins).
543543
///
544544
/// [`expected_compression_ratio`]: Scheme::expected_compression_ratio
545-
#[expect(clippy::cognitive_complexity, reason = "tracing")]
545+
#[allow(clippy::cognitive_complexity, reason = "tracing sometimes enabled")]
546546
fn choose_best_scheme(
547547
&self,
548548
schemes: &[&'static dyn Scheme],

0 commit comments

Comments
 (0)