src/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/debug/trace_event_win.h"
   8 #include "base/files/file_path.h"
   9 #include "base/lazy_instance.h"
  10 #include "base/logging_win.h"
  11 #include "base/synchronization/lock.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 base/debug/trace_event_win.cc's
  43 // TraceEventETWProvider::TraceEvent.  TraceEventETWProvider should expose a way
  44 // to map an event type back to a trace type.
  45 char EventTypeToTraceType(uint8 event_type) {
  46   switch (event_type) {
  47     case base::debug::kTraceEventTypeBegin:
  48       return TRACE_EVENT_PHASE_BEGIN;
  49       break;
  50     case base::debug::kTraceEventTypeEnd:
  51       return TRACE_EVENT_PHASE_END;
  52       break;
  53     case base::debug::kTraceEventTypeInstant:
  54       return TRACE_EVENT_PHASE_INSTANT;
  55       break;
  56     default:
  57       NOTREACHED();
  58       return '\0';
  59       break;
  60   }
  61 }
  62
  63 class LogFileReader {
  64  public:
  65   explicit LogFileReader(LogFileDelegate* delegate);
  66   ~LogFileReader();
  67
  68   static void ReadFile(const base::FilePath& log_file,
  69                        LogFileDelegate* delegate);
  70
  71  private:
  72   // An implementation of a trace consumer that delegates to a given (at
  73   // compile-time) event processing function.
  74   template<void (*ProcessEventFn)(EVENT_TRACE*)>
  75   class TraceConsumer
  76       : public base::win::EtwTraceConsumerBase<TraceConsumer<ProcessEventFn> > {
  77    public:
  78     TraceConsumer() { }
  79     static void ProcessEvent(EVENT_TRACE* event) { (*ProcessEventFn)(event); }
  80    private:
  81     DISALLOW_COPY_AND_ASSIGN(TraceConsumer);
  82   };
  83
  84   // Delegates to DispatchEvent() of the current LogDumper instance.
  85   static void ProcessEvent(EVENT_TRACE* event);
  86
  87   // Handlers for the supported event types.
  88   bool OnLogMessageEvent(const EVENT_TRACE* event);
  89   bool OnLogMessageFullEvent(const EVENT_TRACE* event);
  90   bool OnTraceEvent(const EVENT_TRACE* event);
  91   bool OnFileHeader(const EVENT_TRACE* event);
  92
  93   // Parses an event and passes it along to the delegate for processing.
  94   void DispatchEvent(const EVENT_TRACE* event);
  95
  96   // Reads the file using a trace consumer.  |ProcessEvent| will be invoked for
  97   // each event in the file.
  98   void Read(const base::FilePath& log_file);
  99
 100   // Protects use of the class; only one instance may be live at a time.
 101   static base::LazyInstance<base::Lock>::Leaky reader_lock_;
 102
 103   // The currently living instance.
 104   static LogFileReader* instance_;
 105
 106   // The delegate to be notified of events.
 107   LogFileDelegate* delegate_;
 108 };
 109
 110 // static
 111 base::LazyInstance<base::Lock>::Leaky LogFileReader::reader_lock_ =
 112     LAZY_INSTANCE_INITIALIZER;
 113
 114 // static
 115 LogFileReader* LogFileReader::instance_ = NULL;
 116
 117 LogFileReader::LogFileReader(LogFileDelegate* delegate)
 118     : delegate_(delegate) {
 119   DCHECK(instance_ == NULL);
 120   DCHECK(delegate != NULL);
 121   instance_ = this;
 122 }
 123
 124 LogFileReader::~LogFileReader() {
 125   DCHECK_EQ(instance_, this);
 126   instance_ = NULL;
 127 }
 128
 129 // static
 130 void LogFileReader::ProcessEvent(EVENT_TRACE* event) {
 131   if (instance_ != NULL)
 132     instance_->DispatchEvent(event);
 133 }
 134
 135 bool LogFileReader::OnLogMessageEvent(const EVENT_TRACE* event) {
 136   base::StringPiece message;
 137   MofDataParser parser(event);
 138
 139   // See LogEventProvider::LogMessage where ENABLE_LOG_MESSAGE_ONLY is set.
 140   if (parser.ReadString(&message) && parser.empty()) {
 141     delegate_->OnLogMessage(event,
 142                             EventLevelToSeverity(event->Header.Class.Level),
 143                             message);
 144     return true;
 145   }
 146   return false;
 147 }
 148
 149 bool LogFileReader::OnLogMessageFullEvent(const EVENT_TRACE* event) {
 150   DWORD stack_depth = 0;
 151   const intptr_t* backtrace = NULL;
 152   int line = 0;
 153   base::StringPiece file;
 154   base::StringPiece message;
 155   MofDataParser parser(event);
 156
 157   // See LogEventProvider::LogMessage where ENABLE_LOG_MESSAGE_ONLY is not set.
 158   if (parser.ReadDWORD(&stack_depth) &&
 159       parser.ReadPointerArray(stack_depth, &backtrace) &&
 160       parser.ReadInt(&line) &&
 161       parser.ReadString(&file) &&
 162       parser.ReadString(&message) &&
 163       parser.empty()) {
 164     delegate_->OnLogMessageFull(event,
 165         EventLevelToSeverity(event->Header.Class.Level), stack_depth, backtrace,
 166         line, file, message);
 167     return true;
 168   }
 169   return false;
 170 }
 171
 172 bool LogFileReader::OnTraceEvent(const EVENT_TRACE* event) {
 173   MofDataParser parser(event);
 174   base::StringPiece name;
 175   intptr_t id = 0;
 176   base::StringPiece extra;
 177   DWORD stack_depth = 0;
 178   const intptr_t* backtrace = NULL;
 179
 180   // See TraceEventETWProvider::TraceEvent.
 181   if (parser.ReadString(&name) &&
 182       parser.ReadPointer(&id) &&
 183       parser.ReadString(&extra) &&
 184       (parser.empty() ||
 185        parser.ReadDWORD(&stack_depth) &&
 186        parser.ReadPointerArray(stack_depth, &backtrace) &&
 187        parser.empty())) {
 188     delegate_->OnTraceEvent(event, name,
 189         EventTypeToTraceType(event->Header.Class.Type), id, extra, stack_depth,
 190         backtrace);
 191     return true;
 192   }
 193   return false;
 194 }
 195
 196 bool LogFileReader::OnFileHeader(const EVENT_TRACE* event) {
 197   MofDataParser parser(event);
 198   const TRACE_LOGFILE_HEADER* header = NULL;
 199
 200   if (parser.ReadStructure(&header)) {
 201     delegate_->OnFileHeader(event, header);
 202     return true;
 203   }
 204   return false;
 205 }
 206
 207 void LogFileReader::DispatchEvent(const EVENT_TRACE* event) {
 208   bool parsed = true;
 209
 210   if (IsEqualGUID(event->Header.Guid, logging::kLogEventId)) {
 211     if (event->Header.Class.Type == logging::LOG_MESSAGE)
 212       parsed = OnLogMessageEvent(event);
 213     else if (event->Header.Class.Type == logging::LOG_MESSAGE_FULL)
 214       parsed = OnLogMessageFullEvent(event);
 215   } else if (IsEqualGUID(event->Header.Guid, base::debug::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 }  // logging_win