OLD | NEW |
| (Empty) |
1 // Copyright 2014 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 "content/browser/tracing/etw_system_event_consumer_win.h" | |
6 | |
7 #include <stdint.h> | |
8 | |
9 #include "base/base64.h" | |
10 #include "base/json/json_string_value_serializer.h" | |
11 #include "base/lazy_instance.h" | |
12 #include "base/memory/singleton.h" | |
13 #include "base/strings/stringprintf.h" | |
14 #include "base/thread_task_runner_handle.h" | |
15 #include "base/time/time.h" | |
16 #include "base/trace_event/trace_event_impl.h" | |
17 #include "content/public/browser/browser_thread.h" | |
18 | |
19 namespace content { | |
20 | |
21 namespace { | |
22 | |
23 const char kETWTracingAgentName[] = "etw"; | |
24 const char kETWTraceLabel[] = "systemTraceEvents"; | |
25 | |
26 const int kEtwBufferSizeInKBytes = 16; | |
27 const int kEtwBufferFlushTimeoutInSeconds = 1; | |
28 | |
29 std::string GuidToString(const GUID& guid) { | |
30 return base::StringPrintf("%08X-%04X-%04X-%02X%02X-%02X%02X%02X%02X%02X%02X", | |
31 guid.Data1, guid.Data2, guid.Data3, | |
32 guid.Data4[0], guid.Data4[1], guid.Data4[2], guid.Data4[3], | |
33 guid.Data4[4], guid.Data4[5], guid.Data4[6], guid.Data4[7]); | |
34 } | |
35 | |
36 } // namespace | |
37 | |
38 EtwSystemEventConsumer::EtwSystemEventConsumer() | |
39 : thread_("EtwConsumerThread") { | |
40 } | |
41 | |
42 EtwSystemEventConsumer::~EtwSystemEventConsumer() { | |
43 } | |
44 | |
45 std::string EtwSystemEventConsumer::GetTracingAgentName() { | |
46 return kETWTracingAgentName; | |
47 } | |
48 | |
49 std::string EtwSystemEventConsumer::GetTraceEventLabel() { | |
50 return kETWTraceLabel; | |
51 } | |
52 | |
53 void EtwSystemEventConsumer::StartAgentTracing( | |
54 const base::trace_event::TraceConfig& trace_config, | |
55 const StartAgentTracingCallback& callback) { | |
56 // Activate kernel tracing. | |
57 if (!StartKernelSessionTracing()) { | |
58 base::ThreadTaskRunnerHandle::Get()->PostTask( | |
59 FROM_HERE, | |
60 base::Bind(callback, GetTracingAgentName(), false /* success */)); | |
61 return; | |
62 } | |
63 | |
64 // Start the consumer thread and start consuming events. | |
65 thread_.Start(); | |
66 thread_.message_loop()->PostTask( | |
67 FROM_HERE, | |
68 base::Bind(&EtwSystemEventConsumer::TraceAndConsumeOnThread, | |
69 base::Unretained(this))); | |
70 | |
71 base::ThreadTaskRunnerHandle::Get()->PostTask( | |
72 FROM_HERE, | |
73 base::Bind(callback, GetTracingAgentName(), true /* success */)); | |
74 } | |
75 | |
76 void EtwSystemEventConsumer::StopAgentTracing( | |
77 const StopAgentTracingCallback& callback) { | |
78 // Deactivate kernel tracing. | |
79 if (!StopKernelSessionTracing()) { | |
80 LOG(FATAL) << "Could not stop system tracing."; | |
81 } | |
82 | |
83 // Stop consuming and flush events. | |
84 thread_.message_loop()->PostTask(FROM_HERE, | |
85 base::Bind(&EtwSystemEventConsumer::FlushOnThread, | |
86 base::Unretained(this), | |
87 callback)); | |
88 } | |
89 | |
90 void EtwSystemEventConsumer::OnStopSystemTracingDone( | |
91 const StopAgentTracingCallback& callback, | |
92 const scoped_refptr<base::RefCountedString>& result) { | |
93 | |
94 // Stop the consumer thread. | |
95 thread_.Stop(); | |
96 | |
97 // Pass the serialized events. | |
98 callback.Run(GetTracingAgentName(), GetTraceEventLabel(), result); | |
99 } | |
100 | |
101 bool EtwSystemEventConsumer::StartKernelSessionTracing() { | |
102 // Enabled flags (tracing facilities). | |
103 uint32_t enabled_flags = EVENT_TRACE_FLAG_IMAGE_LOAD | | |
104 EVENT_TRACE_FLAG_PROCESS | EVENT_TRACE_FLAG_THREAD | | |
105 EVENT_TRACE_FLAG_CSWITCH; | |
106 | |
107 EVENT_TRACE_PROPERTIES& p = *properties_.get(); | |
108 p.LogFileMode = EVENT_TRACE_REAL_TIME_MODE; | |
109 p.FlushTimer = kEtwBufferFlushTimeoutInSeconds; | |
110 p.BufferSize = kEtwBufferSizeInKBytes; | |
111 p.LogFileNameOffset = 0; | |
112 p.EnableFlags = enabled_flags; | |
113 p.Wnode.ClientContext = 1; // QPC timer accuracy. | |
114 | |
115 HRESULT hr = base::win::EtwTraceController::Start( | |
116 KERNEL_LOGGER_NAME, &properties_, &session_handle_); | |
117 | |
118 // It's possible that a previous tracing session has been orphaned. If so | |
119 // try stopping and restarting it. | |
120 if (hr == HRESULT_FROM_WIN32(ERROR_ALREADY_EXISTS)) { | |
121 VLOG(1) << "Session already exists, stopping and restarting it."; | |
122 hr = base::win::EtwTraceController::Stop( | |
123 KERNEL_LOGGER_NAME, &properties_); | |
124 if (FAILED(hr)) { | |
125 VLOG(1) << "EtwTraceController::Stop failed with " << hr << "."; | |
126 return false; | |
127 } | |
128 | |
129 // The session was successfully shutdown so try to restart it. | |
130 hr = base::win::EtwTraceController::Start( | |
131 KERNEL_LOGGER_NAME, &properties_, &session_handle_); | |
132 } | |
133 | |
134 if (FAILED(hr)) { | |
135 VLOG(1) << "EtwTraceController::Start failed with " << hr << "."; | |
136 return false; | |
137 } | |
138 | |
139 return true; | |
140 } | |
141 | |
142 bool EtwSystemEventConsumer::StopKernelSessionTracing() { | |
143 HRESULT hr = base::win::EtwTraceController::Stop( | |
144 KERNEL_LOGGER_NAME, &properties_); | |
145 return SUCCEEDED(hr); | |
146 } | |
147 | |
148 // static | |
149 EtwSystemEventConsumer* EtwSystemEventConsumer::GetInstance() { | |
150 return base::Singleton<EtwSystemEventConsumer>::get(); | |
151 } | |
152 | |
153 // static | |
154 void EtwSystemEventConsumer::ProcessEvent(EVENT_TRACE* event) { | |
155 EtwSystemEventConsumer::GetInstance()->AppendEventToBuffer(event); | |
156 } | |
157 | |
158 void EtwSystemEventConsumer::AddSyncEventToBuffer() { | |
159 // Sync the clocks. | |
160 base::Time walltime = base::Time::NowFromSystemTime(); | |
161 base::TimeTicks now = base::TimeTicks::Now(); | |
162 | |
163 LARGE_INTEGER walltime_in_us; | |
164 walltime_in_us.QuadPart = walltime.ToInternalValue(); | |
165 LARGE_INTEGER now_in_us; | |
166 now_in_us.QuadPart = now.ToInternalValue(); | |
167 | |
168 // Add fields to the event. | |
169 std::unique_ptr<base::DictionaryValue> value(new base::DictionaryValue()); | |
170 value->Set("guid", new base::StringValue("ClockSync")); | |
171 value->Set("walltime", new base::StringValue( | |
172 base::StringPrintf("%08X%08X", | |
173 walltime_in_us.HighPart, | |
174 walltime_in_us.LowPart))); | |
175 value->Set("tick", new base::StringValue( | |
176 base::StringPrintf("%08X%08X", | |
177 now_in_us.HighPart, | |
178 now_in_us.LowPart))); | |
179 | |
180 // Append it to the events buffer. | |
181 events_->Append(value.release()); | |
182 } | |
183 | |
184 void EtwSystemEventConsumer::AppendEventToBuffer(EVENT_TRACE* event) { | |
185 using base::FundamentalValue; | |
186 | |
187 std::unique_ptr<base::DictionaryValue> value(new base::DictionaryValue()); | |
188 | |
189 // Add header fields to the event. | |
190 LARGE_INTEGER ts_us; | |
191 ts_us.QuadPart = event->Header.TimeStamp.QuadPart / 10; | |
192 value->Set("ts", new base::StringValue( | |
193 base::StringPrintf("%08X%08X", ts_us.HighPart, ts_us.LowPart))); | |
194 | |
195 value->Set("guid", new base::StringValue(GuidToString(event->Header.Guid))); | |
196 | |
197 value->Set("op", new FundamentalValue(event->Header.Class.Type)); | |
198 value->Set("ver", new FundamentalValue(event->Header.Class.Version)); | |
199 value->Set("pid", | |
200 new FundamentalValue(static_cast<int>(event->Header.ProcessId))); | |
201 value->Set("tid", | |
202 new FundamentalValue(static_cast<int>(event->Header.ThreadId))); | |
203 value->Set("cpu", new FundamentalValue(event->BufferContext.ProcessorNumber)); | |
204 | |
205 // Base64 encode the payload bytes. | |
206 base::StringPiece buffer(static_cast<const char*>(event->MofData), | |
207 event->MofLength); | |
208 std::string payload; | |
209 base::Base64Encode(buffer, &payload); | |
210 value->Set("payload", new base::StringValue(payload)); | |
211 | |
212 // Append it to the events buffer. | |
213 events_->Append(value.release()); | |
214 } | |
215 | |
216 void EtwSystemEventConsumer::TraceAndConsumeOnThread() { | |
217 // Create the events buffer. | |
218 events_.reset(new base::ListValue()); | |
219 | |
220 // Output a clock sync event. | |
221 AddSyncEventToBuffer(); | |
222 | |
223 HRESULT hr = OpenRealtimeSession(KERNEL_LOGGER_NAME); | |
224 if (FAILED(hr)) | |
225 return; | |
226 Consume(); | |
227 Close(); | |
228 } | |
229 | |
230 void EtwSystemEventConsumer::FlushOnThread( | |
231 const StopAgentTracingCallback& callback) { | |
232 // Add the header information to the stream. | |
233 std::unique_ptr<base::DictionaryValue> header(new base::DictionaryValue()); | |
234 header->Set("name", new base::StringValue("ETW")); | |
235 | |
236 // Release and pass the events buffer. | |
237 header->Set("content", events_.release()); | |
238 | |
239 // Serialize the results as a JSon string. | |
240 std::string output; | |
241 JSONStringValueSerializer serializer(&output); | |
242 serializer.Serialize(*header.get()); | |
243 | |
244 // Pass the result to the UI Thread. | |
245 scoped_refptr<base::RefCountedString> result = | |
246 base::RefCountedString::TakeString(&output); | |
247 BrowserThread::PostTask( | |
248 BrowserThread::UI, FROM_HERE, | |
249 base::Bind(&EtwSystemEventConsumer::OnStopSystemTracingDone, | |
250 base::Unretained(this), | |
251 callback, | |
252 result)); | |
253 } | |
254 | |
255 } // namespace content | |
OLD | NEW |