Skip to content

Commit e8efb27

Browse files
committed
Add progress indicator and log file output for concise terminal output
When in an interactive terminal, `kani main.rs --log-file log.txt` will now print: ``` $ kani main.rs --log-file log.txt Kani Rust Verifier 0.66.0 (standalone) [00:00:00] [########################################] 2/2 (0s) Verification complete | Succeeded: 2 | Failed: 0 | Timed out: 0 Manual Harness Summary: Complete - 2 successfully verified harnesses, 0 failures, 2 total. ``` where `########################################` will be updated up until the run is complete. This enables users to more quickly grasp how much work Kani has already completed, which may be particularly useful when running thousands of harnesses with `autoharness`. Co-authored-by: Kani autonomous agent
1 parent 1e3dc05 commit e8efb27

File tree

10 files changed

+309
-7
lines changed

10 files changed

+309
-7
lines changed

Cargo.lock

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -866,6 +866,19 @@ dependencies = [
866866
"serde_core",
867867
]
868868

869+
[[package]]
870+
name = "indicatif"
871+
version = "0.18.3"
872+
source = "registry+https://github.com/rust-lang/crates.io-index"
873+
checksum = "9375e112e4b463ec1b1c6c011953545c65a30164fbab5b581df32b3abf0dcb88"
874+
dependencies = [
875+
"console",
876+
"portable-atomic",
877+
"unicode-width",
878+
"unit-prefix",
879+
"web-time",
880+
]
881+
869882
[[package]]
870883
name = "indoc"
871884
version = "2.0.7"
@@ -1002,6 +1015,7 @@ dependencies = [
10021015
"clap",
10031016
"comfy-table",
10041017
"console",
1018+
"indicatif",
10051019
"kani_metadata",
10061020
"once_cell",
10071021
"pathdiff",
@@ -2377,6 +2391,12 @@ version = "0.2.2"
23772391
source = "registry+https://github.com/rust-lang/crates.io-index"
23782392
checksum = "b4ac048d71ede7ee76d585517add45da530660ef4390e49b098733c6e897f254"
23792393

2394+
[[package]]
2395+
name = "unit-prefix"
2396+
version = "0.5.2"
2397+
source = "registry+https://github.com/rust-lang/crates.io-index"
2398+
checksum = "81e544489bf3d8ef66c953931f56617f423cd4b5494be343d9b9d3dda037b9a3"
2399+
23802400
[[package]]
23812401
name = "unsafe-libyaml"
23822402
version = "0.2.11"
@@ -2480,6 +2500,16 @@ dependencies = [
24802500
"unicode-ident",
24812501
]
24822502

2503+
[[package]]
2504+
name = "web-time"
2505+
version = "1.1.0"
2506+
source = "registry+https://github.com/rust-lang/crates.io-index"
2507+
checksum = "5a6580f308b1fad9207618087a65c04e7a10bc77e02c8e84e9b00dd4b12fa0bb"
2508+
dependencies = [
2509+
"js-sys",
2510+
"wasm-bindgen",
2511+
]
2512+
24832513
[[package]]
24842514
name = "which"
24852515
version = "7.0.3"

kani-driver/Cargo.toml

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@ which = "8"
3636
time = {version = "0.3.36", features = ["formatting"]}
3737
tokio = { version = "1.40.0", features = ["io-util", "process", "rt", "time"] }
3838
chrono = { version = "0.4.41", default-features = false, features = [ "clock" ]}
39+
indicatif = "0.18"
3940

4041

4142
# A good set of suggested dependencies can be found in rustup:

kani-driver/src/args/mod.rs

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -326,6 +326,12 @@ pub struct VerificationArgs {
326326
#[arg(long, hide_short_help = true)]
327327
pub output_into_files: bool,
328328

329+
/// Write verbose and terse log output to the specified file.
330+
/// When enabled with an interactive terminal, progress indicator will be shown on terminal
331+
/// while detailed logs are written to the file.
332+
#[arg(long, value_name = "PATH")]
333+
pub log_file: Option<PathBuf>,
334+
329335
/// Print final LLBC for Lean backend. This requires the `-Z lean` option.
330336
#[arg(long, hide = true)]
331337
pub print_llbc: bool,

kani-driver/src/call_cbmc.rs

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ use std::collections::BTreeMap;
99
use std::collections::btree_map::Entry;
1010
use std::ffi::OsString;
1111
use std::fmt::Write;
12+
use std::io::IsTerminal;
1213
use std::path::Path;
1314
use std::sync::OnceLock;
1415
use std::time::{Duration, Instant};
@@ -120,6 +121,10 @@ impl KaniSession {
120121

121122
let start_time = Instant::now();
122123

124+
// Determine if we should suppress terminal output (redirect to log file)
125+
let suppress_terminal = self.args.log_file.is_some() && std::io::stdout().is_terminal();
126+
let log_file_path = self.args.log_file.clone();
127+
123128
let res = if let Some(timeout) = self.args.harness_timeout {
124129
tokio::time::timeout(
125130
timeout.into(),
@@ -129,6 +134,8 @@ impl KaniSession {
129134
self.args.extra_pointer_checks,
130135
self.args.common_args.quiet,
131136
&self.args.output_format,
137+
suppress_terminal,
138+
log_file_path.as_ref(),
132139
)
133140
}),
134141
)
@@ -140,6 +147,8 @@ impl KaniSession {
140147
self.args.extra_pointer_checks,
141148
self.args.common_args.quiet,
142149
&self.args.output_format,
150+
suppress_terminal,
151+
log_file_path.as_ref(),
143152
)
144153
})
145154
.await)

kani-driver/src/cbmc_property_renderer.rs

Lines changed: 28 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,9 @@ use once_cell::sync::Lazy;
1010
use regex::Regex;
1111
use rustc_demangle::demangle;
1212
use std::collections::HashMap;
13+
use std::fs::OpenOptions;
14+
use std::io::Write;
15+
use std::path::PathBuf;
1316

1417
type CbmcAltDescriptions = HashMap<&'static str, Vec<(&'static str, Option<&'static str>)>>;
1518

@@ -165,12 +168,15 @@ impl ParserItem {
165168
/// filter and transform it into the format we expect.
166169
///
167170
/// This will output "messages" live as they stream in if `output_format` is
168-
/// set to `regular` but will otherwise not print.
171+
/// set to `regular` but will otherwise not print. When `suppress_terminal` is true
172+
/// and a log file path is provided, output is redirected to the log file instead.
169173
pub fn kani_cbmc_output_filter(
170174
item: ParserItem,
171175
extra_ptr_checks: bool,
172176
quiet: bool,
173177
output_format: &OutputFormat,
178+
suppress_terminal: bool,
179+
log_file: Option<&PathBuf>,
174180
) -> Option<ParserItem> {
175181
// Some items (e.g., messages) are skipped.
176182
// We could also process them and decide to skip later.
@@ -183,14 +189,34 @@ pub fn kani_cbmc_output_filter(
183189
if !quiet {
184190
let formatted_item = format_item(&processed_item, output_format);
185191
if let Some(fmt_item) = formatted_item {
186-
println!("{fmt_item}");
192+
if suppress_terminal {
193+
// Write to log file instead of terminal
194+
if let Some(log_path) = log_file {
195+
if let Err(e) = write_to_log_file(log_path, &fmt_item) {
196+
eprintln!(
197+
"Failed to write CBMC output to log file {}: {}",
198+
log_path.display(),
199+
e
200+
);
201+
}
202+
}
203+
} else {
204+
// Normal terminal output
205+
println!("{fmt_item}");
206+
}
187207
}
188208
}
189209
// TODO: Record processed items and dump them into a JSON file
190210
// <https://github.com/model-checking/kani/issues/942>
191211
Some(processed_item)
192212
}
193213

214+
/// Helper function to write output to log file
215+
fn write_to_log_file(log_file_path: &PathBuf, content: &str) -> std::io::Result<()> {
216+
let mut file = OpenOptions::new().create(true).append(true).open(log_file_path)?;
217+
writeln!(file, "{}", content)
218+
}
219+
194220
/// Processes a `ParserItem`. In general, all items are returned as they are,
195221
/// except for:
196222
/// * Error messages, which may be edited.

kani-driver/src/harness_runner.rs

Lines changed: 63 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -5,11 +5,12 @@ use anyhow::{Error, Result, bail};
55
use kani_metadata::{ArtifactType, HarnessKind, HarnessMetadata};
66
use rayon::prelude::*;
77
use std::fs::File;
8-
use std::io::Write;
8+
use std::io::{IsTerminal, Write};
99
use std::path::Path;
1010

1111
use crate::args::{NumThreads, OutputFormat};
1212
use crate::call_cbmc::{VerificationResult, VerificationStatus};
13+
use crate::progress_indicator::ProgressIndicator;
1314
use crate::project::Project;
1415
use crate::session::{BUG_REPORT_URL, KaniSession};
1516

@@ -56,6 +57,15 @@ impl<'pr> HarnessRunner<'_, 'pr> {
5657
harnesses: &'pr [&HarnessMetadata],
5758
) -> Result<Vec<HarnessResult<'pr>>> {
5859
let sorted_harnesses = crate::metadata::sort_harnesses_by_loc(harnesses);
60+
61+
// Determine if we should show progress indicator
62+
let show_progress = self.sess.args.log_file.is_some()
63+
&& !self.sess.args.common_args.quiet
64+
&& std::io::stdout().is_terminal();
65+
66+
// Create progress indicator
67+
let progress_indicator = ProgressIndicator::new(sorted_harnesses.len(), show_progress);
68+
5969
let pool = {
6070
let mut builder = rayon::ThreadPoolBuilder::new();
6171
match self.sess.args.jobs() {
@@ -86,6 +96,15 @@ impl<'pr> HarnessRunner<'_, 'pr> {
8696
}
8797

8898
let result = self.sess.check_harness(goto_file, harness)?;
99+
100+
// Update progress indicator if active
101+
if progress_indicator.is_active() {
102+
let succeeded = result.status == VerificationStatus::Success;
103+
let timed_out =
104+
matches!(&result.results, Err(crate::call_cbmc::ExitStatus::Timeout));
105+
progress_indicator.update_with_result(succeeded, timed_out);
106+
}
107+
89108
if self.sess.args.fail_fast && result.status == VerificationStatus::Failure {
90109
Err(Error::new(FailFastHarnessInfo {
91110
index_to_failing_harness: idx,
@@ -97,6 +116,10 @@ impl<'pr> HarnessRunner<'_, 'pr> {
97116
})
98117
.collect::<Result<Vec<_>>>()
99118
});
119+
120+
// Finish progress indicator
121+
progress_indicator.finish();
122+
100123
match results {
101124
Ok(results) => Ok(results),
102125
Err(err) => {
@@ -127,14 +150,40 @@ impl KaniSession {
127150
}
128151

129152
let output = result.render(&self.args.output_format, harness.attributes.should_panic);
130-
if rayon::current_num_threads() > 1 {
131-
println!("Thread {thread_index}: {output}");
153+
154+
// If log file is specified, write to log file instead of stdout
155+
if let Some(ref log_file_path) = self.args.log_file {
156+
self.write_to_log_file(log_file_path, &output, thread_index);
132157
} else {
133-
println!("{output}");
158+
// Normal stdout output
159+
if rayon::current_num_threads() > 1 {
160+
println!("Thread {thread_index}: {output}");
161+
} else {
162+
println!("{output}");
163+
}
134164
}
135165
}
136166
}
137167

168+
fn write_to_log_file(&self, log_file_path: &PathBuf, output: &str, thread_index: usize) {
169+
use std::fs::OpenOptions;
170+
171+
let result = OpenOptions::new().create(true).append(true).open(log_file_path).and_then(
172+
|mut file| {
173+
let formatted_output = if rayon::current_num_threads() > 1 {
174+
format!("Thread {thread_index}: {output}\n")
175+
} else {
176+
format!("{output}\n")
177+
};
178+
file.write_all(formatted_output.as_bytes())
179+
},
180+
);
181+
182+
if let Err(e) = result {
183+
eprintln!("Failed to write to log file {}: {}", log_file_path.display(), e);
184+
}
185+
}
186+
138187
fn should_print_output(&self) -> bool {
139188
!self.args.common_args.quiet && self.args.output_format != OutputFormat::Old
140189
}
@@ -179,6 +228,10 @@ impl KaniSession {
179228
harness: &HarnessMetadata,
180229
) -> Result<VerificationResult> {
181230
let thread_index = rayon::current_thread_index().unwrap_or_default();
231+
232+
// Determine if we should suppress console output (when using log file with progress indicator)
233+
let suppress_console = self.args.log_file.is_some() && std::io::stdout().is_terminal();
234+
182235
if !self.args.common_args.quiet {
183236
// If the harness is automatically generated, pretty_name refers to the function under verification.
184237
let mut msg = if harness.is_automatically_generated {
@@ -201,7 +254,12 @@ impl KaniSession {
201254
msg = format!("Thread {thread_index}: {msg}");
202255
}
203256

204-
println!("{msg}");
257+
// Write to log file if specified, otherwise to stdout
258+
if let Some(ref log_file_path) = self.args.log_file {
259+
self.write_to_log_file(log_file_path, &msg, thread_index);
260+
} else if !suppress_console {
261+
println!("{msg}");
262+
}
205263
}
206264

207265
let mut result = self.with_timer(|| self.run_cbmc(binary, harness), "run_cbmc")?;

kani-driver/src/main.rs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,7 @@ mod coverage;
3535
mod harness_runner;
3636
mod list;
3737
mod metadata;
38+
mod progress_indicator;
3839
mod project;
3940
mod session;
4041
mod util;

0 commit comments

Comments
 (0)