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
15namespace logging_win {
16
17namespace {
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.
22logging::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.
45char 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
63class 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
111base::LazyInstance<base::Lock>::Leaky LogFileReader::reader_lock_ =
112    LAZY_INSTANCE_INITIALIZER;
113
114// static
115LogFileReader* LogFileReader::instance_ = NULL;
116
117LogFileReader::LogFileReader(LogFileDelegate* delegate)
118    : delegate_(delegate) {
119  DCHECK(instance_ == NULL);
120  DCHECK(delegate != NULL);
121  instance_ = this;
122}
123
124LogFileReader::~LogFileReader() {
125  DCHECK_EQ(instance_, this);
126  instance_ = NULL;
127}
128
129// static
130void LogFileReader::ProcessEvent(EVENT_TRACE* event) {
131  if (instance_ != NULL)
132    instance_->DispatchEvent(event);
133}
134
135bool 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
149bool 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
172bool 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
196bool 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
207void 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
227void 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
242void 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
251LogFileDelegate::LogFileDelegate() {
252}
253
254LogFileDelegate::~LogFileDelegate() {
255}
256
257void ReadLogFile(const base::FilePath& log_file, LogFileDelegate* delegate) {
258  DCHECK(delegate);
259  LogFileReader::ReadFile(log_file, delegate);
260}
261
262}  // logging_win
263