Skip to content

Profiler-IsEnabled #1503

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.

Sign up for GitHub

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

Merged
George Wu (jywu-mysoft) merged 1 commit into from
Jul 30, 2019
Merged

Profiler-IsEnabled #1503

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
5 changes: 5 additions & 0 deletions onnxruntime/core/common/profiler.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -72,6 +72,11 @@ std::string Profiler::EndProfiling() {
profile_with_logger_ = false;
return std::string();
}

if (session_logger_) {
LOGS(*session_logger_, INFO) << "Writing profiler data to file " << profile_stream_file_;
}

std::lock_guard<OrtMutex> lock(mutex_);
profile_stream_ << "[\n";

Expand Down
5 changes: 4 additions & 1 deletion onnxruntime/core/common/profiler.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -44,7 +44,10 @@ class Profiler {
*/
TimePoint StartTime() const;

bool FEnabled() const {
/*
Whether data collection and output from this profiler is enabled.
*/
bool IsEnabled() const {
return enabled_;
}

Expand Down
8 changes: 4 additions & 4 deletions onnxruntime/core/framework/parallel_executor.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,8 +35,8 @@ Status ParallelExecutor::Execute(const SessionState& session_state, const std::v
const std::unordered_map<size_t, CustomAllocator>& fetch_allocators,
const logging::Logger& logger) {
TimePoint tp;
bool f_profiler_enabled = session_state.Profiler().FEnabled();
if (f_profiler_enabled) {
const bool is_profiler_enabled = session_state.Profiler().IsEnabled();
if (is_profiler_enabled) {
tp = session_state.Profiler().StartTime();
}

Expand Down Expand Up @@ -102,7 +102,7 @@ Status ParallelExecutor::Execute(const SessionState& session_state, const std::v
}
}

if (f_profiler_enabled) {
if (is_profiler_enabled) {
session_state.Profiler().EndTimeAndRecordEvent(profiling::SESSION_EVENT, "ParallelExecutor::Execute", tp);
}

Expand All @@ -121,7 +121,7 @@ Status ParallelExecutor::RunNodeAsync(size_t p_node_index,
auto graph_viewer = session_state.GetGraphViewer();
TimePoint sync_time_begin;
TimePoint kernel_begin_time;
bool f_profiler_enabled = session_state.Profiler().FEnabled();
const bool f_profiler_enabled = session_state.Profiler().IsEnabled();

// Avoid context switching if possible.
while (keep_running) {
Expand Down
14 changes: 7 additions & 7 deletions onnxruntime/core/framework/sequential_executor.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,12 +27,12 @@ Status SequentialExecutor::Execute(const SessionState& session_state, const std:
std::vector<OrtValue>& fetches,
const std::unordered_map<size_t, CustomAllocator>& fetch_allocators,
const logging::Logger& logger) {
bool f_profiler_enabled = session_state.Profiler().FEnabled();
const bool is_profiler_enabled = session_state.Profiler().IsEnabled();
TimePoint tp;
TimePoint sync_time_begin;
TimePoint kernel_begin_time;

if (f_profiler_enabled) {
if (is_profiler_enabled) {
tp = session_state.Profiler().StartTime();
}

Expand Down Expand Up @@ -65,7 +65,7 @@ Status SequentialExecutor::Execute(const SessionState& session_state, const std:
OpKernelContextInternal op_kernel_context(session_state, frame, *p_op_kernel, logger,
p_op_kernel->Node().ImplicitInputDefs(), terminate_flag_);
// TODO: log kernel outputs?
if (f_profiler_enabled) {
if (is_profiler_enabled) {
sync_time_begin = session_state.Profiler().StartTime();
}

Expand Down Expand Up @@ -104,7 +104,7 @@ Status SequentialExecutor::Execute(const SessionState& session_state, const std:
utils::DumpNodeInputs(op_kernel_context, p_op_kernel->Node());
#endif

if (f_profiler_enabled) {
if (is_profiler_enabled) {
session_state.Profiler().EndTimeAndRecordEvent(profiling::NODE_EVENT,
p_op_kernel->Node().Name() + "_fence_before",
sync_time_begin,
Expand All @@ -128,7 +128,7 @@ Status SequentialExecutor::Execute(const SessionState& session_state, const std:
return Status(compute_status.Category(), compute_status.Code(), msg_string);
}

if (f_profiler_enabled) {
if (is_profiler_enabled) {
session_state.Profiler().EndTimeAndRecordEvent(profiling::NODE_EVENT,
p_op_kernel->Node().Name() + "_kernel_time",
kernel_begin_time,
Expand Down Expand Up @@ -159,7 +159,7 @@ Status SequentialExecutor::Execute(const SessionState& session_state, const std:
}
}

if (f_profiler_enabled) {
if (is_profiler_enabled) {
session_state.Profiler().EndTimeAndRecordEvent(profiling::NODE_EVENT,
p_op_kernel->Node().Name() + "_fence_after",
sync_time_begin,
Expand Down Expand Up @@ -199,7 +199,7 @@ Status SequentialExecutor::Execute(const SessionState& session_state, const std:
}
}

if (f_profiler_enabled) {
if (is_profiler_enabled) {
session_state.Profiler().EndTimeAndRecordEvent(profiling::SESSION_EVENT, "SequentialExecutor::Execute", tp);
}

Expand Down
13 changes: 9 additions & 4 deletions onnxruntime/core/session/inference_session.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -220,7 +220,7 @@ common::Status InferenceSession::Load(std::function<common::Status(std::shared_p
status = Status(common::ONNXRUNTIME, common::RUNTIME_EXCEPTION, "Encountered unknown exception in Load()");
}

if (session_profiler_.FEnabled()) {
if (session_profiler_.IsEnabled()) {
session_profiler_.EndTimeAndRecordEvent(profiling::SESSION_EVENT, event_name, tp);
}

Expand Down Expand Up @@ -550,7 +550,7 @@ common::Status InferenceSession::Initialize() {
LOGS(*session_logger_, ERROR) << status.ErrorMessage();
}

if (session_profiler_.FEnabled()) {
if (session_profiler_.IsEnabled()) {
session_profiler_.EndTimeAndRecordEvent(profiling::SESSION_EVENT, "session_initialization", tp);
}
return status;
Expand Down Expand Up @@ -742,7 +742,7 @@ Status InferenceSession::Run(const RunOptions& run_options, const std::vector<st
}

--current_num_runs_;
if (session_profiler_.FEnabled()) {
if (session_profiler_.IsEnabled()) {
session_profiler_.EndTimeAndRecordEvent(profiling::SESSION_EVENT, "model_run", tp);
}

Expand Down Expand Up @@ -859,7 +859,12 @@ void InferenceSession::StartProfiling(const logging::Logger* logger_ptr) {

std::string InferenceSession::EndProfiling() {
if (is_model_loaded_) {
return session_profiler_.EndProfiling();
if (session_profiler_.IsEnabled()) {
return session_profiler_.EndProfiling();
} else {
LOGS(*session_logger_, VERBOSE) << "Profiler is disabled.";
return std::string();
}
}
LOGS(*session_logger_, ERROR) << "Could not write a profile because no model was loaded.";
return std::string();
Expand Down