Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Change the format of output produced by --progress #5341

Merged
merged 3 commits into from
Apr 23, 2024
Merged
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Next Next commit
Change the format of output produced by --progress
The previous implementation had two issues:
* It displayed only the milliseconds portion of the duration, so would
  be incorrect for any verification lasting longer than a second.
* The use of exponential notation for resource count made it more
  difficult to compare values, and impossible to identify small
  differences.

This also changes the overall format of the message slightly.
  • Loading branch information
atomb committed Apr 19, 2024
commit 3bff5a9103c1ab56500b3861c84f4fcc29419ff3
6 changes: 3 additions & 3 deletions Source/DafnyDriver/CliCompilation.cs
Original file line number Diff line number Diff line change
Expand Up @@ -183,12 +183,12 @@ public class CliCompilation {
if (Options.Get(CommonOptionBag.ProgressOption)) {
var token = BoogieGenerator.ToDafnyToken(false, boogieUpdate.VerificationTask.Split.Token);
var runResult = completed.Result;
var resourcesUsed = runResult.ResourceCount.ToString("E1", CultureInfo.InvariantCulture);
var timeString = runResult.RunTime.ToString("g");
Options.OutputWriter.WriteLine(
$"Verification part {canVerifyResult.CompletedParts.Count}/{canVerifyResult.Tasks.Count} of {boogieUpdate.CanVerify.FullDafnyName}" +
$", on line {token.line}, " +
$"{DescribeOutcome(Compilation.GetOutcome(runResult.Outcome))}" +
$", taking {runResult.RunTime.Milliseconds}ms and consuming {resourcesUsed} resources");
$" (time: {timeString}, resource count: {runResult.ResourceCount})");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do you want to put the two time properties in parenthesis, instead of include them in the sentence? Also why "time" instead of "duration" ?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ultimately this makes the message shorter, making it more likely that it'll fit on a single line. When you're seeing many of these go by, the ability to quickly do pattern recognition on the output without explicitly reading it is very helpful, in my experience.

Copy link
Member

@keyboardDrummer keyboardDrummer Apr 23, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you change "time" into "duration", and possibly resource count into resources or ticks, although I appreciate the latter might be a bigger change?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thinking about this more, I'm slightly inclined to make it more like the IDE and include something like (0:00:1.25, 23947 RU). I'm worried about using multiple terms to describe resource usage. So far, we've always said "resource count" as an overall descriptor or used the abbreviation "RU" for the units, and the IDE uses "RU" heavily.

When using a unit suffix instead of a descriptive prefix, having either "time: " or "duration: " before the other one feels inconsistent to me. And it'll be formatted in such a way that I think it's obvious that it's describing a time/duration.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One solution would be to list units for both, and not format the duration in "H:M:S" structure. So it would be something like "(3274.86 s, 23194090 RU)". I think perhaps that's my favorite, because it also makes high duration easier to pick out.

}
if (canVerifyResult.CompletedParts.Count == canVerifyResult.Tasks.Count) {
canVerifyResult.Finished.TrySetResult();
Expand Down Expand Up @@ -311,4 +311,4 @@ record VerificationStatistics {
public int OutOfResourceCount;
public int OutOfMemoryCount;
public int SolverExceptionCount;
}
}