chrome/test/logging/win/log_file_reader.cc

   1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "chrome/test/logging/win/log_file_reader.h"
   6
   7 #include "base/files/file_path.h"
   8 #include "base/lazy_instance.h"
   9 #include "base/logging_win.h"
  10 #include "base/synchronization/lock.h"
  11 #include "base/trace_event/trace_event_win.h"
  12 #include "base/win/event_trace_consumer.h"
  13 #include "chrome/test/logging/win/mof_data_parser.h"
  14
  15 namespace logging_win {
  16
  17 namespace {
  18
  19 // TODO(grt) This reverses a mapping produced by base/logging_win.cc's
  20 // LogEventProvider::LogMessage.  LogEventProvider should expose a way to map an
  21 // event level back to a log severity.
  22 logging::LogSeverity EventLevelToSeverity(uint8 level) {
  23   switch (level) {
  24   case TRACE_LEVEL_NONE:
  25     NOTREACHED();
  26     return logging::LOG_ERROR;
  27   case TRACE_LEVEL_FATAL:
  28     return logging::LOG_FATAL;
  29   case TRACE_LEVEL_ERROR:
  30     return logging::LOG_ERROR;
  31   case TRACE_LEVEL_WARNING:
  32     return logging::LOG_WARNING;
  33   case TRACE_LEVEL_INFORMATION:
  34     return logging::LOG_INFO;
  35   default:
  36     // Trace levels above information correspond to negative severity levels,
  37     // which are used for VLOG verbosity levels.
  38     return TRACE_LEVEL_INFORMATION - level;
  39   }
  40 }
  41
  42 // TODO(grt): This reverses a mapping produced by
  43 // base/trace_event/trace_event_win.cc's TraceEventETWProvider::TraceEvent.
  44 // TraceEventETWProvider should expose a way to map an event type back to a
  45 // trace type.
  46 char EventTypeToTraceType(uint8 event_type) {
  47   switch (event_type) {
  48     case base::trace_event::kTraceEventTypeBegin:
  49       return TRACE_EVENT_PHASE_BEGIN;
  50       break;
  51     case base::trace_event::kTraceEventTypeEnd:
  52       return TRACE_EVENT_PHASE_END;
  53       break;
  54     case base::trace_event::kTraceEventTypeInstant:
  55       return TRACE_EVENT_PHASE_INSTANT;
  56       break;
  57     default:
  58       NOTREACHED();
  59       return '\0';
  60       break;
  61   }
  62 }
  63
  64 class LogFileReader {
  65  public:
  66   explicit LogFileReader(LogFileDelegate* delegate);
  67   ~LogFileReader();
  68
  69   static void ReadFile(const base::FilePath& log_file,
  70                        LogFileDelegate* delegate);
  71
  72  private:
  73   // An implementation of a trace consumer that delegates to a given (at
  74   // compile-time) event processing function.
  75   template<void (*ProcessEventFn)(EVENT_TRACE*)>
  76   class TraceConsumer
  77       : public base::win::EtwTraceConsumerBase<TraceConsumer<ProcessEventFn> > {
  78    public:
  79     TraceConsumer() { }
  80     static void ProcessEvent(EVENT_TRACE* event) { (*ProcessEventFn)(event); }
  81    private:
  82     DISALLOW_COPY_AND_ASSIGN(TraceConsumer);
  83   };
  84
  85   // Delegates to DispatchEvent() of the current LogDumper instance.
  86   static void ProcessEvent(EVENT_TRACE* event);
  87
  88   // Handlers for the supported event types.
  89   bool OnLogMessageEvent(const EVENT_TRACE* event);
  90   bool OnLogMessageFullEvent(const EVENT_TRACE* event);
  91   bool OnTraceEvent(const EVENT_TRACE* event);
  92   bool OnFileHeader(const EVENT_TRACE* event);
  93
  94   // Parses an event and passes it along to the delegate for processing.
  95   void DispatchEvent(const EVENT_TRACE* event);
  96
  97   // Reads the file using a trace consumer.  |ProcessEvent| will be invoked for
  98   // each event in the file.
  99   void Read(const base::FilePath& log_file);
 100
 101   // Protects use of the class; only one instance may be live at a time.
 102   static base::LazyInstance<base::Lock>::Leaky reader_lock_;
 103
 104   // The currently living instance.
 105   static LogFileReader* instance_;
 106
 107   // The delegate to be notified of events.
 108   LogFileDelegate* delegate_;
 109 };
 110
 111 // static
 112 base::LazyInstance<base::Lock>::Leaky LogFileReader::reader_lock_ =
 113     LAZY_INSTANCE_INITIALIZER;
 114
 115 // static
 116 LogFileReader* LogFileReader::instance_ = NULL;
 117
 118 LogFileReader::LogFileReader(LogFileDelegate* delegate)
 119     : delegate_(delegate) {
 120   DCHECK(instance_ == NULL);
 121   DCHECK(delegate != NULL);
 122   instance_ = this;
 123 }
 124
 125 LogFileReader::~LogFileReader() {
 126   DCHECK_EQ(instance_, this);
 127   instance_ = NULL;
 128 }
 129
 130 // static
 131 void LogFileReader::ProcessEvent(EVENT_TRACE* event) {
 132   if (instance_ != NULL)
 133     instance_->DispatchEvent(event);
 134 }
 135
 136 bool LogFileReader::OnLogMessageEvent(const EVENT_TRACE* event) {
 137   base::StringPiece message;
 138   MofDataParser parser(event);
 139
 140   // See LogEventProvider::LogMessage where ENABLE_LOG_MESSAGE_ONLY is set.
 141   if (parser.ReadString(&message) && parser.empty()) {
 142     delegate_->OnLogMessage(event,
 143                             EventLevelToSeverity(event->Header.Class.Level),
 144                             message);
 145     return true;
 146   }
 147   return false;
 148 }
 149
 150 bool LogFileReader::OnLogMessageFullEvent(const EVENT_TRACE* event) {
 151   DWORD stack_depth = 0;
 152   const intptr_t* backtrace = NULL;
 153   int line = 0;
 154   base::StringPiece file;
 155   base::StringPiece message;
 156   MofDataParser parser(event);
 157
 158   // See LogEventProvider::LogMessage where ENABLE_LOG_MESSAGE_ONLY is not set.
 159   if (parser.ReadDWORD(&stack_depth) &&
 160       parser.ReadPointerArray(stack_depth, &backtrace) &&
 161       parser.ReadInt(&line) &&
 162       parser.ReadString(&file) &&
 163       parser.ReadString(&message) &&
 164       parser.empty()) {
 165     delegate_->OnLogMessageFull(event,
 166         EventLevelToSeverity(event->Header.Class.Level), stack_depth, backtrace,
 167         line, file, message);
 168     return true;
 169   }
 170   return false;
 171 }
 172
 173 bool LogFileReader::OnTraceEvent(const EVENT_TRACE* event) {
 174   MofDataParser parser(event);
 175   base::StringPiece name;
 176   intptr_t id = 0;
 177   base::StringPiece extra;
 178   DWORD stack_depth = 0;
 179   const intptr_t* backtrace = NULL;
 180
 181   // See TraceEventETWProvider::TraceEvent.
 182   if (parser.ReadString(&name) && parser.ReadPointer(&id) &&
 183       parser.ReadString(&extra) &&
 184       (parser.empty() ||
 185        (parser.ReadDWORD(&stack_depth) &&
 186         parser.ReadPointerArray(stack_depth, &backtrace) && parser.empty()))) {
 187     delegate_->OnTraceEvent(event, name,
 188         EventTypeToTraceType(event->Header.Class.Type), id, extra, stack_depth,
 189         backtrace);
 190     return true;
 191   }
 192   return false;
 193 }
 194
 195 bool LogFileReader::OnFileHeader(const EVENT_TRACE* event) {
 196   MofDataParser parser(event);
 197   const TRACE_LOGFILE_HEADER* header = NULL;
 198
 199   if (parser.ReadStructure(&header)) {
 200     delegate_->OnFileHeader(event, header);
 201     return true;
 202   }
 203   return false;
 204 }
 205
 206 void LogFileReader::DispatchEvent(const EVENT_TRACE* event) {
 207   bool parsed = true;
 208
 209   if (IsEqualGUID(event->Header.Guid, logging::kLogEventId)) {
 210     if (event->Header.Class.Type == logging::LOG_MESSAGE)
 211       parsed = OnLogMessageEvent(event);
 212     else if (event->Header.Class.Type == logging::LOG_MESSAGE_FULL)
 213       parsed = OnLogMessageFullEvent(event);
 214   } else if (IsEqualGUID(event->Header.Guid,
 215                          base::trace_event::kTraceEventClass32)) {
 216     parsed = OnTraceEvent(event);
 217   } else if (IsEqualGUID(event->Header.Guid, EventTraceGuid)) {
 218     parsed = OnFileHeader(event);
 219   } else {
 220     DCHECK(parsed);
 221     delegate_->OnUnknownEvent(event);
 222   }
 223   if (!parsed)
 224     delegate_->OnUnparsableEvent(event);
 225 }
 226
 227 void LogFileReader::Read(const base::FilePath& log_file) {
 228   TraceConsumer<&ProcessEvent> consumer;
 229   HRESULT hr = S_OK;
 230
 231   hr = consumer.OpenFileSession(log_file.value().c_str());
 232   if (FAILED(hr)) {
 233     LOG(ERROR) << "Failed to open session for log file " << log_file.value()
 234                << "; hr=" << std::hex << hr;
 235   } else {
 236     consumer.Consume();
 237     consumer.Close();
 238   }
 239 }
 240
 241 // static
 242 void LogFileReader::ReadFile(const base::FilePath& log_file,
 243                              LogFileDelegate* delegate) {
 244   base::AutoLock lock(reader_lock_.Get());
 245
 246   LogFileReader(delegate).Read(log_file);
 247 }
 248
 249 }  // namespace
 250
 251 LogFileDelegate::LogFileDelegate() {
 252 }
 253
 254 LogFileDelegate::~LogFileDelegate() {
 255 }
 256
 257 void ReadLogFile(const base::FilePath& log_file, LogFileDelegate* delegate) {
 258   DCHECK(delegate);
 259   LogFileReader::ReadFile(log_file, delegate);
 260 }
 261
 262 }  // namespace logging_win