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/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 FilePath& log_file, LogFileDelegate* delegate);
  69
  70  private:
  71   // An implementation of a trace consumer that delegates to a given (at
  72   // compile-time) event processing function.
  73   template<void (*ProcessEventFn)(EVENT_TRACE*)>
  74   class TraceConsumer
  75       : public base::win::EtwTraceConsumerBase<TraceConsumer<ProcessEventFn> > {
  76    public:
  77     TraceConsumer() { }
  78     static void ProcessEvent(EVENT_TRACE* event) { (*ProcessEventFn)(event); }
  79    private:
  80     DISALLOW_COPY_AND_ASSIGN(TraceConsumer);
  81   };
  82
  83   // Delegates to DispatchEvent() of the current LogDumper instance.
  84   static void ProcessEvent(EVENT_TRACE* event);
  85
  86   // Handlers for the supported event types.
  87   bool OnLogMessageEvent(const EVENT_TRACE* event);
  88   bool OnLogMessageFullEvent(const EVENT_TRACE* event);
  89   bool OnTraceEvent(const EVENT_TRACE* event);
  90   bool OnFileHeader(const EVENT_TRACE* event);
  91
  92   // Parses an event and passes it along to the delegate for processing.
  93   void DispatchEvent(const EVENT_TRACE* event);
  94
  95   // Reads the file using a trace consumer.  |ProcessEvent| will be invoked for
  96   // each event in the file.
  97   void Read(const FilePath& log_file);
  98
  99   // Protects use of the class; only one instance may be live at a time.
 100   static base::LazyInstance<base::Lock>::Leaky reader_lock_;
 101
 102   // The currently living instance.
 103   static LogFileReader* instance_;
 104
 105   // The delegate to be notified of events.
 106   LogFileDelegate* delegate_;
 107 };
 108
 109 // static
 110 base::LazyInstance<base::Lock>::Leaky LogFileReader::reader_lock_ =
 111     LAZY_INSTANCE_INITIALIZER;
 112
 113 // static
 114 LogFileReader* LogFileReader::instance_ = NULL;
 115
 116 LogFileReader::LogFileReader(LogFileDelegate* delegate)
 117     : delegate_(delegate) {
 118   DCHECK(instance_ == NULL);
 119   DCHECK(delegate != NULL);
 120   instance_ = this;
 121 }
 122
 123 LogFileReader::~LogFileReader() {
 124   DCHECK_EQ(instance_, this);
 125   instance_ = NULL;
 126 }
 127
 128 // static
 129 void LogFileReader::ProcessEvent(EVENT_TRACE* event) {
 130   if (instance_ != NULL)
 131     instance_->DispatchEvent(event);
 132 }
 133
 134 bool LogFileReader::OnLogMessageEvent(const EVENT_TRACE* event) {
 135   base::StringPiece message;
 136   MofDataParser parser(event);
 137
 138   // See LogEventProvider::LogMessage where ENABLE_LOG_MESSAGE_ONLY is set.
 139   if (parser.ReadString(&message) && parser.empty()) {
 140     delegate_->OnLogMessage(event,
 141                             EventLevelToSeverity(event->Header.Class.Level),
 142                             message);
 143     return true;
 144   }
 145   return false;
 146 }
 147
 148 bool LogFileReader::OnLogMessageFullEvent(const EVENT_TRACE* event) {
 149   DWORD stack_depth = 0;
 150   const intptr_t* backtrace = NULL;
 151   int line = 0;
 152   base::StringPiece file;
 153   base::StringPiece message;
 154   MofDataParser parser(event);
 155
 156   // See LogEventProvider::LogMessage where ENABLE_LOG_MESSAGE_ONLY is not set.
 157   if (parser.ReadDWORD(&stack_depth) &&
 158       parser.ReadPointerArray(stack_depth, &backtrace) &&
 159       parser.ReadInt(&line) &&
 160       parser.ReadString(&file) &&
 161       parser.ReadString(&message) &&
 162       parser.empty()) {
 163     delegate_->OnLogMessageFull(event,
 164         EventLevelToSeverity(event->Header.Class.Level), stack_depth, backtrace,
 165         line, file, message);
 166     return true;
 167   }
 168   return false;
 169 }
 170
 171 bool LogFileReader::OnTraceEvent(const EVENT_TRACE* event) {
 172   MofDataParser parser(event);
 173   base::StringPiece name;
 174   intptr_t id = 0;
 175   base::StringPiece extra;
 176   DWORD stack_depth = 0;
 177   const intptr_t* backtrace = NULL;
 178
 179   // See TraceEventETWProvider::TraceEvent.
 180   if (parser.ReadString(&name) &&
 181       parser.ReadPointer(&id) &&
 182       parser.ReadString(&extra) &&
 183       (parser.empty() ||
 184        parser.ReadDWORD(&stack_depth) &&
 185        parser.ReadPointerArray(stack_depth, &backtrace) &&
 186        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, base::debug::kTraceEventClass32)) {
 215     parsed = OnTraceEvent(event);
 216   } else if (IsEqualGUID(event->Header.Guid, EventTraceGuid)) {
 217     parsed = OnFileHeader(event);
 218   } else {
 219     DCHECK(parsed);
 220     delegate_->OnUnknownEvent(event);
 221   }
 222   if (!parsed)
 223     delegate_->OnUnparsableEvent(event);
 224 }
 225
 226 void LogFileReader::Read(const FilePath& log_file) {
 227   TraceConsumer<&ProcessEvent> consumer;
 228   HRESULT hr = S_OK;
 229
 230   hr = consumer.OpenFileSession(log_file.value().c_str());
 231   if (FAILED(hr)) {
 232     LOG(ERROR) << "Failed to open session for log file " << log_file.value()
 233                << "; hr=" << std::hex << hr;
 234   } else {
 235     consumer.Consume();
 236     consumer.Close();
 237   }
 238 }
 239
 240 // static
 241 void LogFileReader::ReadFile(const FilePath& log_file,
 242                              LogFileDelegate* delegate) {
 243   base::AutoLock lock(reader_lock_.Get());
 244
 245   LogFileReader(delegate).Read(log_file);
 246 }
 247
 248 }  // namespace
 249
 250 LogFileDelegate::LogFileDelegate() {
 251 }
 252
 253 LogFileDelegate::~LogFileDelegate() {
 254 }
 255
 256 void ReadLogFile(const FilePath& log_file, LogFileDelegate* delegate) {
 257   DCHECK(delegate);
 258   LogFileReader::ReadFile(log_file, delegate);
 259 }
 260
 261 }  // logging_win