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.
EventLevelToSeverity(uint8 level)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.
EventTypeToTraceType(uint8 event_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:
TraceConsumer()78 TraceConsumer() { }
ProcessEvent(EVENT_TRACE * event)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
LogFileReader(LogFileDelegate * delegate)117 LogFileReader::LogFileReader(LogFileDelegate* delegate)
118 : delegate_(delegate) {
119 DCHECK(instance_ == NULL);
120 DCHECK(delegate != NULL);
121 instance_ = this;
122 }
123
~LogFileReader()124 LogFileReader::~LogFileReader() {
125 DCHECK_EQ(instance_, this);
126 instance_ = NULL;
127 }
128
129 // static
ProcessEvent(EVENT_TRACE * event)130 void LogFileReader::ProcessEvent(EVENT_TRACE* event) {
131 if (instance_ != NULL)
132 instance_->DispatchEvent(event);
133 }
134
OnLogMessageEvent(const EVENT_TRACE * event)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
OnLogMessageFullEvent(const EVENT_TRACE * event)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
OnTraceEvent(const EVENT_TRACE * event)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
OnFileHeader(const EVENT_TRACE * event)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
DispatchEvent(const EVENT_TRACE * event)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
Read(const base::FilePath & log_file)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
ReadFile(const base::FilePath & log_file,LogFileDelegate * delegate)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
LogFileDelegate()251 LogFileDelegate::LogFileDelegate() {
252 }
253
~LogFileDelegate()254 LogFileDelegate::~LogFileDelegate() {
255 }
256
ReadLogFile(const base::FilePath & log_file,LogFileDelegate * delegate)257 void ReadLogFile(const base::FilePath& log_file, LogFileDelegate* delegate) {
258 DCHECK(delegate);
259 LogFileReader::ReadFile(log_file, delegate);
260 }
261
262 } // logging_win
263