Skip to content

Commit 8605c92

Browse files
daboehmedaboehme
authored
Increase timer resolution (LLNL#487)
* Add exclusive time option for spot controller * Use nsec resolution for timer * Enable multiplexing in example flops spec * Record time durations as integers * Print verbose test output in Github actions
1 parent 1f56c8e commit 8605c92

20 files changed

+174
-189
lines changed

‎.github/workflows/cmake.yml

+1-1
Original file line numberDiff line numberDiff line change
@@ -37,5 +37,5 @@ jobs:
3737
working-directory: ${{github.workspace}}/build
3838
# Execute tests defined by the CMake configuration.
3939
# See https://cmake.org/cmake/help/latest/manual/ctest.1.html for more detail
40-
run: ctest -C ${{env.BUILD_TYPE}}
40+
run: ctest -C ${{env.BUILD_TYPE}} --rerun-failed --output-on-failure
4141

‎examples/configs/flops.json

+2-1
Original file line numberDiff line numberDiff line change
@@ -44,7 +44,8 @@
4444
"services": [ "papi" ],
4545
"config":
4646
{
47-
"CALI_PAPI_COUNTERS": "PAPI_DP_OPS,PAPI_SP_OPS"
47+
"CALI_PAPI_COUNTERS": "PAPI_DP_OPS,PAPI_SP_OPS",
48+
"CALI_PAPI_ENABLE_MULTIPLEXING": "true"
4849
},
4950
"query":
5051
[

‎python/cali2traceevent.py

+2-1
Original file line numberDiff line numberDiff line change
@@ -25,9 +25,10 @@ def _get_timestamp(rec):
2525

2626
timestamp_attributes = {
2727
"cupti.timestamp" : 1e-3,
28-
"gputrace.timestamp" : 1e-3,
2928
"rocm.host.timestamp" : 1e-3,
29+
"time.offset.ns" : 1e-3,
3030
"time.offset" : 1.0,
31+
"gputrace.timestamp" : 1e-3,
3132
"cupti.activity.start" : 1e-3,
3233
"rocm.starttime" : 1e-3
3334
}

‎src/caliper/RegionProfile.cpp

+21-6
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
// Copyright (c) 2015-2022, Lawrence Livermore National Security, LLC.
1+
// Copyright (c) 2015-2022, Lawrence Livermore National Security, LLC.
22
// See top-level LICENSE file for details.
33

44
#include "caliper/RegionProfile.h"
@@ -42,38 +42,53 @@ RegionProfile::region_profile_t
4242
RegionProfile::exclusive_region_times(const std::string& region_type)
4343
{
4444
Caliper c;
45-
FlatExclusiveRegionProfile rp(c, "sum#time.duration", region_type.c_str());
45+
FlatExclusiveRegionProfile rp(c, "sum#time.duration.ns", region_type.c_str());
4646

4747
if (channel())
4848
c.flush(channel(), SnapshotView(), rp);
4949
else
5050
Log(1).stream() << "RegionProfile::exclusive_region_times(): channel is not enabled"
5151
<< std::endl;
5252

53-
return rp.result();
53+
auto res = rp.result();
54+
55+
// convert from nanosec to sec
56+
std::get<1>(res) *= 1e-9;
57+
std::get<2>(res) *= 1e-9;
58+
for (auto &p : std::get<0>(res))
59+
p.second *= 1e-9;
60+
61+
return res;
5462
}
5563

5664

5765
RegionProfile::region_profile_t
5866
RegionProfile::inclusive_region_times(const std::string& region_type)
5967
{
6068
Caliper c;
61-
FlatInclusiveRegionProfile rp(c, "sum#time.duration", region_type.c_str());
69+
FlatInclusiveRegionProfile rp(c, "sum#time.duration.ns", region_type.c_str());
6270

6371
if (channel())
6472
c.flush(channel(), SnapshotView(), rp);
6573
else
6674
Log(1).stream() << "RegionProfile::inclusive_region_times(): channel is not enabled"
6775
<< std::endl;
6876

69-
return rp.result();
77+
auto res = rp.result();
78+
79+
std::get<1>(res) *= 1e-9;
80+
std::get<2>(res) *= 1e-9;
81+
for (auto &p : std::get<0>(res))
82+
p.second *= 1e-9;
83+
84+
return res;
7085
}
7186

7287
void
7388
RegionProfile::clear()
7489
{
7590
Channel* chn = channel();
76-
91+
7792
if (chn)
7893
Caliper::instance().clear(chn);
7994
}

‎src/caliper/controllers/HatchetRegionProfileController.cpp

+2
Original file line numberDiff line numberDiff line change
@@ -61,6 +61,7 @@ class HatchetRegionProfileController : public cali::ChannelController
6161
config()["CALI_MPIREPORT_WRITE_ON_FINALIZE"] = "false";
6262
config()["CALI_MPIREPORT_CONFIG" ] =
6363
opts.build_query("local", {
64+
{ "let", "sum#time.duration=scale(sum#time.duration.ns,1e-9)" },
6465
{ "select", "*,sum(sum#time.duration) as time unit sec" },
6566
{ "group by", "path,mpi.rank" },
6667
{ "format", format }
@@ -70,6 +71,7 @@ class HatchetRegionProfileController : public cali::ChannelController
7071
config()["CALI_REPORT_FILENAME" ] = output;
7172
config()["CALI_REPORT_CONFIG" ] =
7273
opts.build_query("local", {
74+
{ "let", "sum#time.duration=scale(sum#time.duration.ns,1e-9)" },
7375
{ "select", "*,sum(sum#time.duration) as time unit sec" },
7476
{ "group by", "path" },
7577
{ "format", format }

‎src/caliper/controllers/LoopReportController.cpp

+8-8
Original file line numberDiff line numberDiff line change
@@ -83,13 +83,13 @@ class LoopReportController : public cali::internal::CustomOutputController
8383
" loop"
8484
",count()"
8585
",sum(loop.iterations)"
86-
",sum(time.duration)"
86+
",scale(time.duration.ns,1e-9)"
8787
",min(iter_per_sec)"
8888
",max(iter_per_sec)"
8989
",avg(iter_per_sec)";
9090

9191
std::string query = m_opts.build_query("local", {
92-
{ "let", "iter_per_sec = ratio(loop.iterations,time.duration)" },
92+
{ "let", "iter_per_sec = ratio(loop.iterations,time.duration.ns,1e9)" },
9393
{ "select", select },
9494
{ "group by", "loop" },
9595
{ "where", "loop" }
@@ -102,10 +102,10 @@ class LoopReportController : public cali::internal::CustomOutputController
102102
const char* select =
103103
" loop as Loop"
104104
",max(sum#loop.iterations) as \"Iterations\""
105-
",max(sum#time.duration) as \"Time (s)\""
105+
",max(scale#time.duration.ns) as \"Time (s)\""
106106
",min(min#iter_per_sec) as \"Iter/s (min)\""
107107
",max(max#iter_per_sec) as \"Iter/s (max)\""
108-
",ratio(sum#loop.iterations,sum#time.duration) as \"Iter/s (avg)\"";
108+
",ratio(sum#loop.iterations,scale#time.duration.ns) as \"Iter/s (avg)\"";
109109

110110
std::string query = m_opts.build_query("cross", {
111111
{ "select", select },
@@ -120,9 +120,9 @@ class LoopReportController : public cali::internal::CustomOutputController
120120
Aggregator timeseries_local_aggregation(Caliper& c, CaliperMetadataDB& db, const std::string& loopname, int blocksize) {
121121
const char* select =
122122
" Block"
123-
",sum(time.duration)"
123+
",scale(time.duration.ns,1e-9)"
124124
",sum(loop.iterations)"
125-
",ratio(loop.iterations,time.duration)";
125+
",ratio(loop.iterations,time.duration.ns,1e9)";
126126

127127
std::string block =
128128
std::string("Block = truncate(loop.start_iteration,") + std::to_string(blocksize) + ")";
@@ -141,8 +141,8 @@ class LoopReportController : public cali::internal::CustomOutputController
141141
const char* select =
142142
" Block"
143143
",max(sum#loop.iterations) as \"Iterations\""
144-
",max(sum#time.duration) as \"Time (s)\""
145-
",avg(ratio#loop.iterations/time.duration) as \"Iter/s\"";
144+
",max(scale#time.duration.ns) as \"Time (s)\""
145+
",avg(ratio#loop.iterations/time.duration.ns) as \"Iter/s\"";
146146

147147
std::string query = m_opts.build_query("cross", {
148148
{ "select", select },

‎src/caliper/controllers/OpenMPReportController.cpp

+2-1
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,8 @@ class OpenMPReportController : public cali::ChannelController
2525
: ChannelController(name, 0, initial_cfg)
2626
{
2727
const char* let =
28-
" n.threads=first(omp.num.threads)"
28+
" sum#time.duration=scale(sum#time.duration.ns,1e-9)"
29+
",n.threads=first(omp.num.threads)"
2930
",t.initial=first(sum#time.duration) if omp.thread.type=initial";
3031

3132
// Config for first aggregation step in MPI mode (process-local aggregation)

‎src/caliper/controllers/ROCmActivityProfileController.cpp

+2-2
Original file line numberDiff line numberDiff line change
@@ -63,7 +63,7 @@ class RocmActivityProfileController : public cali::ChannelController
6363
opts.build_query("local", {
6464
{ "select",
6565
"*,scale(sum#rocm.activity.duration,1e-9) as \"time (gpu)\" unit sec"
66-
" ,sum(sum#time.duration) as \"time\" unit sec"
66+
" ,scale(sum#time.duration.ns,1e-9) as \"time\" unit sec"
6767
},
6868
{ "group by", "path,rocm.kernel.name,rocm.activity.kind,mpi.rank" },
6969
{ "format", format }
@@ -75,7 +75,7 @@ class RocmActivityProfileController : public cali::ChannelController
7575
opts.build_query("local", {
7676
{ "select",
7777
"*,scale(sum#rocm.activity.duration,1e-9) as \"time (gpu)\" unit sec"
78-
" ,sum(sum#time.duration) as \"time\" unit sec" },
78+
" ,sale(sum#time.duration.ns,1e-9) as \"time\" unit sec" },
7979
{ "group by", "path,rocm.kernel.name,rocm.activity.kind" },
8080
{ "format", format }
8181
});

‎src/caliper/controllers/ROCmActivityReportController.cpp

+4-4
Original file line numberDiff line numberDiff line change
@@ -28,18 +28,18 @@ class RocmActivityReportController : public cali::ChannelController
2828
{
2929
// Config for first aggregation step in MPI mode (process-local aggregation)
3030
std::string local_select =
31-
" inclusive_sum(sum#time.duration)"
31+
" inclusive_scale(sum#time.duration.ns,1e-9)"
3232
",inclusive_scale(sum#rocm.activity.duration,1e-9)";
3333
// Config for serial-mode aggregation
3434
std::string serial_select =
35-
" inclusive_sum(sum#time.duration) as \"Host Time\""
35+
" inclusive_scale(sum#time.duration.ns,1e-9) as \"Host Time\""
3636
",inclusive_scale(sum#rocm.activity.duration,1e-9) as \"GPU Time\""
3737
",inclusive_ratio(sum#rocm.activity.duration,sum#time.duration,1e-7) as \"GPU %\"";
3838

3939
// Config for second aggregation step in MPI mode (cross-process aggregation)
4040
std::string cross_select =
41-
" avg(inclusive#sum#time.duration) as \"Avg Host Time\""
42-
",max(inclusive#sum#time.duration) as \"Max Host Time\""
41+
" avg(inclusive#scale#time.duration.ns) as \"Avg Host Time\""
42+
",max(inclusive#scale#time.duration.ns) as \"Max Host Time\""
4343
",avg(iscale#sum#rocm.activity.duration) as \"Avg GPU Time\""
4444
",max(iscale#sum#rocm.activity.duration) as \"Max GPU Time\""
4545
",ratio(iscale#sum#rocm.activity.duration,inclusive#sum#time.duration,100.0) as \"GPU %\"";

‎src/caliper/controllers/RuntimeReportController.cpp

+5
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,9 @@ class RuntimeReportController : public cali::ChannelController
2626
RuntimeReportController(bool use_mpi, const char* name, const config_map_t& initial_cfg, const ConfigManager::Options& opts)
2727
: ChannelController(name, 0, initial_cfg)
2828
{
29+
std::string local_let =
30+
"sum#time.duration=scale(sum#time.duration.ns,1e-9)";
31+
2932
// Config for first aggregation step in MPI mode (process-local aggregation)
3033
std::string local_select =
3134
" sum(sum#time.duration)";
@@ -60,6 +63,7 @@ class RuntimeReportController : public cali::ChannelController
6063
config()["CALI_MPIREPORT_WRITE_ON_FINALIZE"] = "false";
6164
config()["CALI_MPIREPORT_LOCAL_CONFIG"] =
6265
opts.build_query("local", {
66+
{ "let", local_let },
6367
{ "select", local_select },
6468
{ "group by", "path" }
6569
});
@@ -74,6 +78,7 @@ class RuntimeReportController : public cali::ChannelController
7478
config()["CALI_REPORT_FILENAME" ] = opts.get("output", "stderr").to_string();
7579
config()["CALI_REPORT_CONFIG" ] =
7680
opts.build_query("local", {
81+
{ "let", local_let },
7782
{ "select", serial_select },
7883
{ "group by", "path" },
7984
{ "format", format }

0 commit comments

Comments
 (0)