src/cobalt/trace_event/event_parser.h

// Copyright 2015 Google Inc. All Rights Reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//     http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.

#ifndef COBALT_TRACE_EVENT_EVENT_PARSER_H_
#define COBALT_TRACE_EVENT_EVENT_PARSER_H_

#include <set>
#include <string>
#include <vector>

#include "base/debug/trace_event.h"
#include "base/debug/trace_event_impl.h"
#include "base/hash_tables.h"
#include "base/memory/ref_counted.h"
#include "base/optional.h"
#include "base/time.h"

namespace cobalt {
namespace trace_event {

// EventParser is a class responsible for parsing raw base::debug::TraceLog
// trace events generated by calls to tracing functions found in trace_event.h.
// Example tracing calls include TRACE_EVENT0 and TRACE_EVENT_FLOW_BEGIN0.
// It parses raw sequences of base::debug::TraceEvent structures into
// high level event trees.
// This class will interpret the incoming log data and, as it becomes able to,
// will in turn fire its own higher level events such as when an event flow
// has ended.  This is useful because it compiles all data for flow structures
// as it reads the individual raw trace events and only provides it to the
// client when entire flows have completed and all relevant information about
// them is available and nicely organized.
// Using this trace log parse to re-create the program flow structure
// makes it much easier to write code that analyzes timing and execution results
// available in the trace log.
// EventParser can link TRACE_EVENTs across TRACE_EVENT_FLOWs, allowing entire
// processing pipelines that span multiple thread boundaries to be linked
// together automatically.
class EventParser {
 public:
  // A ScopedEvent represents some Chromium tracing event that has a duration.
  // This includes standard TRACE_EVENTs which are scoped and thus have a
  // beginning and end.  It also includes TRACE_EVENT_FLOWs, which necessarily
  // have an associated beginning and end.
  class ScopedEvent : public base::RefCountedThreadSafe<ScopedEvent> {
   public:
    ScopedEvent(const scoped_refptr<ScopedEvent>& parent,
                const base::debug::TraceEvent& begin_event,
                EventParser* event_parser);

    // Shortcut method to retrieve the event name.  This should be the same
    // amongst begin_event(), end_event() and all instant_events().
    const std::string name() const { return begin_event().name(); }

    // Convenience method for returning the duration of this event's entire
    // flow.  This value may not exist if the trace was terminated before the
    // end of the scoped event's flow occurs.
    base::optional<base::TimeDelta> flow_duration() const {
      if (end_flow_time()) {
        return *end_flow_time() - begin_event().timestamp();
      } else {
        return base::nullopt;
      }
    }

    // Convenience method for returning the duration of this event's scope.
    // This value may not exist if the trace was terminated before the
    // scoped event's end occurs.
    base::optional<base::TimeDelta> in_scope_duration() const {
      if (end_event()) {
        return end_event()->timestamp() - begin_event().timestamp();
      } else {
        return base::nullopt;
      }
    }

    // Returns the event's parent scope.  Informally, this is the scope that
    // was responsible for producing this scope.
    const scoped_refptr<ScopedEvent>& parent() const { return parent_; }

    // Return a list of the event's child events.  Informally, these are the
    // events that were produced by this event.
    const std::vector<scoped_refptr<ScopedEvent> > children() const {
      return children_;
    }

    // Returns the Chromium TraceEvent structure associated with the beginning
    // of this scoped event (e.g. since the event is scoped, it has a beginning
    // and end).
    const base::debug::TraceEvent& begin_event() const { return begin_event_; }

    // Returns the Chromium TraceEvent structure associated with the end of this
    // scoped event.  If the scoped event has not finished yet, this will return
    // nullopt.
    const base::optional<base::debug::TraceEvent>& end_event() const {
      return end_event_;
    }

    // Return a list of instant events that are effectively children of this
    // scoped event.  For example, all TRACE_EVENT_FLOW_STEP calls will attach
    // the generated TraceEvent structure as an instant event to the
    // corresponding flow ScopedEvent.
    const std::vector<base::debug::TraceEvent> instant_events() const {
      return instant_events_;
    }

    // The end flow time is the time when the last of this ScopedEvent's
    // descendants has ended.  This can be much later than the ScopedEvent's
    // local end time.  An example where the end flow time is different from
    // the end time is if within a TRACE_EVENT, a TRACE_EVENT_FLOW is started
    // and the TRACE_EVENT_FLOW ends *after* the TRACE_EVENT ends.  In this
    // case, the TRACE_EVENT's end flow time is equal to the TRACE_EVENT_FLOW's
    // end time, assuming the TRACE_EVENT_FLOW did not spawn any children of its
    // own that could extend the TRACE_EVENT's end flow time even longer.
    const base::optional<base::TimeTicks>& end_flow_time() const {
      return end_flow_time_;
    }

    // Returns the latest generated Chromium TraceEvent we've seen so far.
    // This will return end_event if it exists, otherwise the latest
    // instant_event, otherwise the begin_event.
    const base::debug::TraceEvent& LastTraceEvent() const;

    // The state is used to keep track of what state the ScopedEvent is in.
    // ScopedEvents may persist for much longer after they have been ended.
    // Newly started event scopes will begin life in the kState_Active state.
    enum State {
      // kState_Active means that the ScopedEvent has not yet received a
      // end signal (e.g. TRACE_EVENT_FLOW_BEGIN is not yet matched with
      // TRACE_EVENT_FLOW_END).
      kActiveState,
      // kState_Ended means that the ScopedEvent has received an end signal,
      // but it still has descendants that have not received their end signal
      // and thus the end flow time for this ScopedEvent is not currently
      // available.
      kEndedState,
      // kState_EndedAndLastTouched exists to handle a bit of a special case
      // where a TRACE_EVENT_FLOW is ended, and it has no children, but
      // since it can potentially be linked as a parent to a subsequent
      // TRACE_EVENT call (e.g. as is done in MessageLoop::RunTask), it should
      // not be marked as having its flow ended yet.  Being "last touched"
      // means that this event was last on a thread to be modified on any
      // thread (e.g. started, stepped or ended).
      kEndedAndLastTouchedState,
      // kState_FlowEnded indicates that this ScopedEvent and all its
      // descendants have ended their flows, and the state of the event will
      // no longer be changing.
      kFlowEndedState,
      // kState_Aborted indicates that the ScopedEvent did not end properly
      // and was instead aborted prematurely.  Not all fields (like end_event)
      // may be available, but the object will no longer be changing.
      kAbortedState,
    };
    State state() const { return state_; }

   private:
    virtual ~ScopedEvent();
    friend class base::RefCountedThreadSafe<ScopedEvent>;

    // Many of these methods will be called by EventParser in response to event
    // processing.
    void OnEnd(const base::debug::TraceEvent& end_event);
    void OnEndFlow(const base::TimeTicks& timestamp);
    bool AreEndFlowConditionsMet() const;
    void AddInstantEvent(const base::debug::TraceEvent& event);
    void OnNotLastTouched();
    void Abort();

    // Returns a set of all leaf nodes in the event tree rooted at this
    // ScopedEvent node.  If this node is a leaf node, the returned set
    // will contain this node as the single item.
    std::set<scoped_refptr<ScopedEvent> > GetLeafEvents();

    scoped_refptr<ScopedEvent> parent_;
    std::vector<scoped_refptr<ScopedEvent> > children_;

    base::debug::TraceEvent begin_event_;
    base::optional<base::debug::TraceEvent> end_event_;
    base::optional<base::TimeTicks> end_flow_time_;

    std::vector<base::debug::TraceEvent> instant_events_;

    // How many of our children have flows that have not ended yet?  If this
    // is non-zero, then our flow cannot yet be ended.
    int flow_active_children_;

    State state_;

    // The parent event parser this ScopedEvent is apart of.
    EventParser* event_parser_;

    friend class EventParser;
  };

  typedef base::Callback<void(const scoped_refptr<ScopedEvent>& event)>
      ScopedEventFlowEndCallback;

  // The passed in scoped_event_flow_end_callback will be run every time we
  // encounter a ScopedEvent whose flow has ended (e.g. the event is over and
  // so are all its descendants).  It is important to realize that an event's
  // "flow end" is different from the end of the event's scope.  For example,
  // if a TRACE_EVENT posts a message to a message loop, and then the
  // TRACE_EVENT goes out of scope, the event's scope has ended but its flow
  // has not.  The flow will only end when the posted message is processed
  // and that message did not post any messages of its own to extend the flow
  // farther.
  explicit EventParser(
      const ScopedEventFlowEndCallback& scoped_event_flow_end_callback);
  ~EventParser();

  // This is the function that drives the event parser.  As raw events are fed
  // to EventParser from base::debug::TraceLog, the event parser is updated and
  // may produce its own higher level events.
  void ParseEvent(const base::debug::TraceEvent& event);

 private:
  // Used to keep track of information local to specific threads, such as
  // which events are currently on the stack for that thread, and what the last
  // event touched on that thread was.
  struct ThreadInfo {
    std::vector<scoped_refptr<ScopedEvent> > event_stack_;
    scoped_refptr<ScopedEvent> last_touched_event_;
  };

  void UpdateLastTouchedEvent(ThreadInfo* thread_info,
                              const scoped_refptr<ScopedEvent>& event);

  std::set<scoped_refptr<ScopedEvent> > GetLeafEvents();

  friend class ScopedEvent;

  ScopedEventFlowEndCallback scoped_event_flow_end_callback_;

  typedef base::hash_map<int, ThreadInfo> ThreadMap;
  ThreadMap thread_id_to_info_map_;

  // Keep a mapping of all active flow events (which may span multiple threads)
  // for easy lookup if we need to process a flow event.
  typedef base::hash_map<uint64_t, scoped_refptr<ScopedEvent> > FlowEventMap;
  FlowEventMap flow_id_to_event_map_;
};

}  // namespace trace_event
}  // namespace cobalt

#endif  // COBALT_TRACE_EVENT_EVENT_PARSER_H_