event_tracer logging inside method.cpp and program.cpp (#346)

Summary:
Pull Request resolved: #346

Adding event_tracer logging inside method.cpp and program.cpp.

Similar to D48975975 calls to both `internal::ET_EVENT_TRACER_SCOPE_PROF` and `EXECUTORCH_SCOPE_PROF` are present in `method.cpp` and `program.cpp`. Calls to `event_tracer_*` are a no-op for now and `EXECUTORCH_SCOPE_PROF` will be deprecated soon.

Reviewed By: dbort

Differential Revision: D49220572

fbshipit-source-id: a4bca44664b6608e93fac04a7bc4ab71696cd8ff

Author: tarun292

runtime/executor/method.cpp

@@ -505,6 +505,8 @@ Result<Method> Method::load(
 
 Error Method::init(executorch_flatbuffer::ExecutionPlan* s_plan) {
   EXECUTORCH_SCOPE_PROF("Method::init");
+  internal::EventTracerProfileScope event_tracer_profile_scope =
+      internal::EventTracerProfileScope(event_tracer_, "Method::init");
   ET_CHECK_OR_RETURN_ERROR(
       // Don't use !initialized() here because we also want to fail on the
       // InitializationFailed state.
@@ -902,6 +904,8 @@ Error Method::execute_instruction() {
   switch (instruction->instr_args_type()) {
     case executorch_flatbuffer::InstructionArguments::KernelCall: {
       EXECUTORCH_SCOPE_PROF("OPERATOR_CALL");
+      internal::EventTracerProfileScope event_tracer_scope =
+          internal::EventTracerProfileScope(event_tracer_, "OPERATOR_CALL");
       // TODO(T147221312): Also expose the temp allocator and tensor resizer
       // via the context.
       KernelRuntimeContext context(event_tracer_);
@@ -934,6 +938,8 @@ Error Method::execute_instruction() {
     } break;
     case executorch_flatbuffer::InstructionArguments::DelegateCall: {
       EXECUTORCH_SCOPE_PROF("DELEGATE_CALL");
+      internal::EventTracerProfileScope event_tracer_profile_scope =
+          internal::EventTracerProfileScope(event_tracer_, "DELEGATE_CALL");
       auto delegate_idx =
           instruction->instr_args_as_DelegateCall()->delegate_index();
       ET_CHECK_OR_RETURN_ERROR(
@@ -956,6 +962,8 @@ Error Method::execute_instruction() {
     } break;
     case executorch_flatbuffer::InstructionArguments::JumpFalseCall: {
       EXECUTORCH_SCOPE_PROF("JF_CALL");
+      internal::EventTracerProfileScope event_tracer_profile_scope =
+          internal::EventTracerProfileScope(event_tracer_, "JF_CALL");
       auto jf_call = instruction->instr_args_as_JumpFalseCall();
       bool jf_result = parse_cond_value(values_[jf_call->cond_value_index()]);
       if (!jf_result) {
@@ -965,11 +973,15 @@ Error Method::execute_instruction() {
     } break;
     case executorch_flatbuffer::InstructionArguments::MoveCall: {
       EXECUTORCH_SCOPE_PROF("MOVE_CALL");
+      internal::EventTracerProfileScope event_tracer_profile_scope =
+          internal::EventTracerProfileScope(event_tracer_, "MOVE_CALL");
       auto move_call = instruction->instr_args_as_MoveCall();
       mutable_value(move_call->move_to()) = get_value(move_call->move_from());
     } break;
     case executorch_flatbuffer::InstructionArguments::FreeCall: {
       EXECUTORCH_SCOPE_PROF("FREE_CALL");
+      internal::EventTracerProfileScope event_tracer_profile_scope =
+          internal::EventTracerProfileScope(event_tracer_, "FREE_CALL");
       auto free_call = instruction->instr_args_as_FreeCall();
       auto t = values_[free_call->value_index()].toTensor();
       internal::reset_data_ptr(t);
@@ -997,7 +1009,14 @@ Error Method::experimental_step() {
   EXECUTORCH_PROFILE_INSTRUCTION_SCOPE(
       static_cast<int32_t>(step_state_.chain_idx),
       static_cast<uint32_t>(step_state_.instr_idx));
+  internal::EventTracerProfileInstructionScope event_tracer_instr_scope =
+      internal::EventTracerProfileInstructionScope(
+          event_tracer_,
+          static_cast<int32_t>(step_state_.chain_idx),
+          static_cast<uint32_t>(step_state_.instr_idx));
   EXECUTORCH_SCOPE_PROF("Method::step");
+  internal::EventTracerProfileScope event_tracer_profile_scope =
+      internal::EventTracerProfileScope(event_tracer_, "Method::step");
   ET_CHECK_OR_RETURN_ERROR(
       initialized(),
       InvalidState,
@@ -1032,6 +1051,9 @@ Error Method::experimental_step() {
 }
 
 Error Method::execute() {
+  internal::event_tracer_create_event_block(event_tracer_, "Execute");
+  internal::EventTracerProfileScope event_tracer_profile_scope =
+      internal::EventTracerProfileScope(event_tracer_, "Method::execute");
   EXECUTORCH_SCOPE_PROF("Method::execute");
   ET_CHECK_OR_RETURN_ERROR(
       initialized(),
@@ -1056,6 +1078,11 @@ Error Method::execute() {
       EXECUTORCH_PROFILE_INSTRUCTION_SCOPE(
           static_cast<int32_t>(step_state_.chain_idx),
           static_cast<uint32_t>(step_state_.instr_idx));
+      internal::EventTracerProfileInstructionScope event_tracer_instr_scope =
+          internal::EventTracerProfileInstructionScope(
+              event_tracer_,
+              static_cast<ChainID>(step_state_.chain_idx),
+              static_cast<DebugHandle>(step_state_.instr_idx));
       auto status = execute_instruction();
       if (status != Error::Ok) {
         return status;

runtime/executor/program.cpp

@@ -11,6 +11,7 @@
 #include <cstddef>
 #include <cstdint>
 
+#include <executorch/runtime/core/event_tracer_hooks.h>
 #include <executorch/runtime/executor/memory_manager.h>
 #include <executorch/runtime/executor/method.h>
 #include <executorch/runtime/platform/profiler.h>
@@ -170,6 +171,9 @@ Result<Method> Program::load_method(
     MemoryManager* memory_manager,
     EventTracer* event_tracer) const {
   EXECUTORCH_SCOPE_PROF("Program::load_method");
+  internal::event_tracer_create_event_block(event_tracer, "Default");
+  internal::EventTracerProfileScope event_tracer_scope =
+      internal::EventTracerProfileScope(event_tracer, "Program::load_method");
   auto plan = get_execution_plan(internal_program_, method_name);
   if (!plan.ok()) {
     return plan.error();