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

cli/sql: make the final time printer more informative #32663

Merged
merged 1 commit into from Nov 29, 2018

Conversation

4 participants
@knz
Copy link
Member

knz commented Nov 28, 2018

Fixes #32656.

By default cockroach sql uses the table formatter which buffers
the input rows in memory and then takes a lot of time to format the
table and display it.

In addition, cockroach sql also prints the query/statement latency
at the end.

Prior to this patch, the printed latency included both the query
latency and also the time needed to print the results. This is
misleading because in many cases the formatter takes much more time to
print than the query spent executing.

This patch improves the UX by changing the latency display to exclude
the printing time. This reduces the discrepancy between the latency
observed with one formatter and that of another formatter.

In addition, if the printing time is larger than 1 second, an
informative message is displayed to inform the user why they may have
the impression the query ran for longer than the time displayed.

For example:

> select * from generate_series(1, 100000)
...
Time: 1.884819457s
Note: an additional delay of 4.073508214s was spent formatting the results.

Release note (cli change): cockroach sql and other commands that
print query results and query execution latency will now exclude the
time required to prepare the display client-side from the latency
measurement.

@knz knz requested a review from jordanlewis Nov 28, 2018

@knz knz added this to To do in Command Line Interface (CLI) via automation Nov 28, 2018

@knz knz requested a review from a-robinson Nov 28, 2018

@knz knz requested review from cockroachdb/cli-prs as code owners Nov 28, 2018

@cockroach-teamcity

This comment has been minimized.

Copy link
Member

cockroach-teamcity commented Nov 28, 2018

This change is Reviewable

@a-robinson
Copy link
Collaborator

a-robinson left a comment

:lgtm:

Reviewed 3 of 3 files at r1.
Reviewable status: :shipit: complete! 1 of 0 LGTMs obtained

@jordanlewis
Copy link
Member

jordanlewis left a comment

:lgtm:, good idea

Reviewable status: :shipit: complete! 2 of 0 LGTMs obtained


pkg/cli/sql_util.go, line 771 at r1 (raw file):

			if renderDelay >= 1*time.Second {
				fmt.Fprintf(w,
					"Note: an additional delay of %s was spent formatting the results.\n", renderDelay)

Consider including a hint here to use the display format.

@knz

This comment has been minimized.

Copy link
Member

knz commented Nov 29, 2018

Consider including a hint here to use the display format.

Done.

@knz knz force-pushed the knz:20181128-cli-sql branch from 36c78a0 to a51b26e Nov 29, 2018

cli/sql: make the final time printer more informative
By default `cockroach sql` uses the `table` formatter which buffers
the input rows in memory and then takes *a lot* of time to format the
tables and display it.

In addition, `cockroach sql` also prints the query/statement latency
at the end.

Prior to this patch, the printed latency included both the query
latency and also the time needed to print the results. This is
misleading because in many cases the formatter takes much more time to
print than the query spent executing.

This patch improves the UX by changing the latency display to exclude
the printing time. This reduces the discrepancy between the latency
observed with one formatter and that of another formatter.

In addition, if the printing time is larger than 1 second, an
informative message is displayed to inform the user why they may have
the impression the query ran for longer than the time displayed.

For example:

```
> select * from generate_series(1, 100000)
...
Time: 1.884819457s
Note: an additional delay of 4.073508214s was spent formatting the results.
```

Release note (cli change): `cockroach sql` and other commands that
print query results and query execution latency will now exclude the
time required to prepare the display client-side from the latency
measurement.

@knz knz force-pushed the knz:20181128-cli-sql branch from a51b26e to 6e31f9c Nov 29, 2018

@knz

This comment has been minimized.

Copy link
Member

knz commented Nov 29, 2018

bors r+

craig bot pushed a commit that referenced this pull request Nov 29, 2018

Merge #32663
32663: cli/sql: make the final time printer more informative r=knz a=knz

Fixes  #32656.

By default `cockroach sql` uses the `table` formatter which buffers
the input rows in memory and then takes *a lot* of time to format the
table and display it.

In addition, `cockroach sql` also prints the query/statement latency
at the end.

Prior to this patch, the printed latency included both the query
latency and also the time needed to print the results. This is
misleading because in many cases the formatter takes much more time to
print than the query spent executing.

This patch improves the UX by changing the latency display to exclude
the printing time. This reduces the discrepancy between the latency
observed with one formatter and that of another formatter.

In addition, if the printing time is larger than 1 second, an
informative message is displayed to inform the user why they may have
the impression the query ran for longer than the time displayed.

For example:

```
> select * from generate_series(1, 100000)
...
Time: 1.884819457s
Note: an additional delay of 4.073508214s was spent formatting the results.
```

Release note (cli change): `cockroach sql` and other commands that
print query results and query execution latency will now exclude the
time required to prepare the display client-side from the latency
measurement.

Co-authored-by: Raphael 'kena' Poss <knz@cockroachlabs.com>
@craig

This comment has been minimized.

Copy link

craig bot commented Nov 29, 2018

Build succeeded

@craig craig bot merged commit 6e31f9c into cockroachdb:master Nov 29, 2018

3 checks passed

GitHub CI (Cockroach) TeamCity build finished
Details
bors Build succeeded
Details
license/cla Contributor License Agreement is signed.
Details

Command Line Interface (CLI) automation moved this from To do to Done Nov 29, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment