Add timestamps to "maint time" output
Currently "maint time" will print the amount of time a command took. Sometimes, though, it's useful to have a timestamp as well -- for example if one is correlating a gdb log with some other log. This patch adds a timestamp to the start and end of each command when this setting is in effect. This also removes a "//" comment and changes scoped_command_stats to use DISABLE_COPY_AND_ASSIGN; two minor things I noticed while working on the patch. Tested on x86-64 Fedora 29. gdb/ChangeLog 2019-06-06 Tom Tromey <tromey@adacore.com> * maint.h (class scoped_command_stats): Use DISABLE_COPY_AND_ASSIGN. <print_time>: New method. * maint.c (scoped_command_stats, ~scoped_command_stats): Call print_time. (scoped_command_stats::print_time): New method. gdb/testsuite/ChangeLog 2019-06-06 Tom Tromey <tromey@adacore.com> * gdb.base/maint.exp: Expect command started/finished output.
This commit is contained in:
parent
237df8fe18
commit
3847a7bfbf
5 changed files with 47 additions and 5 deletions
|
@ -1,3 +1,12 @@
|
||||||
|
2019-06-06 Tom Tromey <tromey@adacore.com>
|
||||||
|
|
||||||
|
* maint.h (class scoped_command_stats): Use
|
||||||
|
DISABLE_COPY_AND_ASSIGN.
|
||||||
|
<print_time>: New method.
|
||||||
|
* maint.c (scoped_command_stats, ~scoped_command_stats): Call
|
||||||
|
print_time.
|
||||||
|
(scoped_command_stats::print_time): New method.
|
||||||
|
|
||||||
2019-06-05 Andrew Burgess <andrew.burgess@embecosm.com>
|
2019-06-05 Andrew Burgess <andrew.burgess@embecosm.com>
|
||||||
|
|
||||||
* riscv-tdep.c (riscv_insn::decode): Gracefully ignore
|
* riscv-tdep.c (riscv_insn::decode): Gracefully ignore
|
||||||
|
|
25
gdb/maint.c
25
gdb/maint.c
|
@ -794,6 +794,8 @@ scoped_command_stats::~scoped_command_stats ()
|
||||||
|
|
||||||
if (m_time_enabled && per_command_time)
|
if (m_time_enabled && per_command_time)
|
||||||
{
|
{
|
||||||
|
print_time (_("command finished"));
|
||||||
|
|
||||||
using namespace std::chrono;
|
using namespace std::chrono;
|
||||||
|
|
||||||
run_time_clock::duration cmd_time
|
run_time_clock::duration cmd_time
|
||||||
|
@ -867,6 +869,9 @@ scoped_command_stats::scoped_command_stats (bool msg_type)
|
||||||
m_start_cpu_time = run_time_clock::now ();
|
m_start_cpu_time = run_time_clock::now ();
|
||||||
m_start_wall_time = steady_clock::now ();
|
m_start_wall_time = steady_clock::now ();
|
||||||
m_time_enabled = 1;
|
m_time_enabled = 1;
|
||||||
|
|
||||||
|
if (per_command_time)
|
||||||
|
print_time (_("command started"));
|
||||||
}
|
}
|
||||||
else
|
else
|
||||||
m_time_enabled = 0;
|
m_time_enabled = 0;
|
||||||
|
@ -888,6 +893,26 @@ scoped_command_stats::scoped_command_stats (bool msg_type)
|
||||||
reset_prompt_for_continue_wait_time ();
|
reset_prompt_for_continue_wait_time ();
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/* See maint.h. */
|
||||||
|
|
||||||
|
void
|
||||||
|
scoped_command_stats::print_time (const char *msg)
|
||||||
|
{
|
||||||
|
using namespace std::chrono;
|
||||||
|
|
||||||
|
auto now = system_clock::now ();
|
||||||
|
auto ticks = now.time_since_epoch ().count () / (1000 * 1000);
|
||||||
|
auto millis = ticks % 1000;
|
||||||
|
|
||||||
|
std::time_t as_time = system_clock::to_time_t (now);
|
||||||
|
struct tm *tm = localtime (&as_time);
|
||||||
|
|
||||||
|
char out[100];
|
||||||
|
strftime (out, sizeof (out), "%F %H:%M:%S", tm);
|
||||||
|
|
||||||
|
printf_unfiltered ("%s.%03d - %s\n", out, (int) millis, msg);
|
||||||
|
}
|
||||||
|
|
||||||
/* Handle unknown "mt set per-command" arguments.
|
/* Handle unknown "mt set per-command" arguments.
|
||||||
In this case have "mt set per-command on|off" affect every setting. */
|
In this case have "mt set per-command on|off" affect every setting. */
|
||||||
|
|
||||||
|
|
|
@ -38,9 +38,10 @@ class scoped_command_stats
|
||||||
|
|
||||||
private:
|
private:
|
||||||
|
|
||||||
// No need for these. They are intentionally not defined anywhere.
|
DISABLE_COPY_AND_ASSIGN (scoped_command_stats);
|
||||||
scoped_command_stats &operator= (const scoped_command_stats &);
|
|
||||||
scoped_command_stats (const scoped_command_stats &);
|
/* Print the time, along with a string. */
|
||||||
|
void print_time (const char *msg);
|
||||||
|
|
||||||
/* Zero if the saved time is from the beginning of GDB execution.
|
/* Zero if the saved time is from the beginning of GDB execution.
|
||||||
One if from the beginning of an individual command execution. */
|
One if from the beginning of an individual command execution. */
|
||||||
|
|
|
@ -1,3 +1,7 @@
|
||||||
|
2019-06-06 Tom Tromey <tromey@adacore.com>
|
||||||
|
|
||||||
|
* gdb.base/maint.exp: Expect command started/finished output.
|
||||||
|
|
||||||
2019-06-05 Andrew Burgess <andrew.burgess@embecosm.com>
|
2019-06-05 Andrew Burgess <andrew.burgess@embecosm.com>
|
||||||
|
|
||||||
* gdb.arch/riscv-unwind-long-insn-6.s: Remove use of 'I' in
|
* gdb.arch/riscv-unwind-long-insn-6.s: Remove use of 'I' in
|
||||||
|
|
|
@ -177,9 +177,12 @@ gdb_test_no_output "maint check-symtabs"
|
||||||
|
|
||||||
# Test per-command stats.
|
# Test per-command stats.
|
||||||
gdb_test_no_output "maint set per-command on"
|
gdb_test_no_output "maint set per-command on"
|
||||||
|
set decimal "\[0-9\]+"
|
||||||
|
set time_fmt "${decimal}-${decimal}-${decimal} ${decimal}:${decimal}:${decimal}\\.${decimal}"
|
||||||
gdb_test "pwd" \
|
gdb_test "pwd" \
|
||||||
"Command execution time: \[0-9.\]+ \\(cpu\\), \[0-9.\]+ \\(wall\\)\[\r\n\]+Space used: $decimal \\(\\+$decimal for this command\\)\[\r\n\]+#symtabs: $decimal \\(\\+$decimal\\), #compunits: $decimal \\(\\+$decimal\\), #blocks: $decimal \\(\\+$decimal\\)"
|
"${time_fmt} - command started\r\n.*\r\n${time_fmt} - command finished\r\nCommand execution time: \[0-9.\]+ \\(cpu\\), \[0-9.\]+ \\(wall\\)\[\r\n\]+Space used: $decimal \\(\\+$decimal for this command\\)\[\r\n\]+#symtabs: $decimal \\(\\+$decimal\\), #compunits: $decimal \\(\\+$decimal\\), #blocks: $decimal \\(\\+$decimal\\)"
|
||||||
gdb_test_no_output "maint set per-command off"
|
gdb_test "maint set per-command off" \
|
||||||
|
"${time_fmt} - command started"
|
||||||
|
|
||||||
# The timeout value is raised, because printing all the symbols and
|
# The timeout value is raised, because printing all the symbols and
|
||||||
# statistical information about Cygwin and Windows libraries takes a lot
|
# statistical information about Cygwin and Windows libraries takes a lot
|
||||||
|
|
Loading…
Add table
Add a link
Reference in a new issue