1 : // Copyright 2012 Google Inc.
2 : //
3 : // Licensed under the Apache License, Version 2.0 (the "License");
4 : // you may not use this file except in compliance with the License.
5 : // You may obtain a copy of the License at
6 : //
7 : // http://www.apache.org/licenses/LICENSE-2.0
8 : //
9 : // Unless required by applicable law or agreed to in writing, software
10 : // distributed under the License is distributed on an "AS IS" BASIS,
11 : // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 : // See the License for the specific language governing permissions and
13 : // limitations under the License.
14 : //
15 : // Implementation of the Call Trace Client DLL.
16 :
17 : #include "syzygy/agent/call_trace/client_rpc.h"
18 :
19 : #include <windows.h> // NOLINT
20 : #include <psapi.h>
21 : #include <tlhelp32.h>
22 : #include <vector>
23 :
24 : #include "base/at_exit.h"
25 : #include "base/command_line.h"
26 : #include "base/environment.h"
27 : #include "base/lazy_instance.h"
28 : #include "base/logging.h"
29 : #include "base/utf_string_conversions.h"
30 : #include "base/win/pe_image.h"
31 : #include "sawbuck/common/com_utils.h"
32 : #include "syzygy/agent/common/process_utils.h"
33 : #include "syzygy/agent/common/scoped_last_error_keeper.h"
34 : #include "syzygy/common/logging.h"
35 : #include "syzygy/common/path_util.h"
36 : #include "syzygy/trace/client/client_utils.h"
37 : #include "syzygy/trace/protocol/call_trace_defs.h"
38 : #include "syzygy/trace/rpc/rpc_helpers.h"
39 :
40 : using agent::client::Client;
41 : using agent::common::ScopedLastErrorKeeper;
42 :
43 : namespace {
44 :
45 : // All tracing runs through this object.
46 : base::LazyInstance<Client> static_client_instance = LAZY_INSTANCE_INITIALIZER;
47 :
48 : // Copies the arguments under an SEH handler so we don't crash by under-running
49 : // the stack.
50 : void CopyArguments(ArgumentWord *dst, const ArgumentWord *src, size_t num) {
51 : __try {
52 : for (size_t i = 0; i < num; ++i)
53 : *dst++ = *src++;
54 : } __except(EXCEPTION_EXECUTE_HANDLER) {
55 : }
56 : }
57 :
58 : } // namespace
59 :
60 E : BOOL WINAPI DllMain(HMODULE instance, DWORD reason, LPVOID reserved) {
61 : // Our AtExit manager required by base.
62 : static base::AtExitManager* at_exit = NULL;
63 :
64 E : if (reason == DLL_PROCESS_ATTACH) {
65 E : DCHECK(at_exit == NULL);
66 E : at_exit = new base::AtExitManager();
67 : }
68 :
69 E : BOOL ret = Client::Instance()->DllMain(instance, reason, reserved);
70 :
71 E : if (reason == DLL_PROCESS_DETACH) {
72 E : DCHECK(at_exit != NULL);
73 E : delete at_exit;
74 E : at_exit = NULL;
75 : }
76 :
77 E : return ret;
78 E : }
79 :
80 : // This instrumentation hook is used for all function calls except for
81 : // calls to a DLL entry point.
82 : //
83 : // Note that the calling convention to this function is non-conventional.
84 : // This function is invoked by a generated stub that does:
85 : //
86 : // push <original function>
87 : // jmp _indirect_penter
88 : //
89 : // This function will trace the entry to <original function>, and then on
90 : // exit, will arrange for execution to jump to <original function>. If
91 : // required, it will also arrange for the return from <original function>
92 : // to be captured.
93 E : extern "C" void __declspec(naked) _cdecl _indirect_penter() {
94 : __asm {
95 : // Stash volatile registers.
96 E : push eax
97 E : push ecx
98 E : push edx
99 E : pushfd
100 :
101 : // Retrieve the address pushed by our caller.
102 E : mov eax, DWORD PTR[esp + 0x10]
103 E : push eax
104 :
105 : // Calculate the position of the return address on stack, and
106 : // push it. This becomes the EntryFrame argument.
107 E : lea eax, DWORD PTR[esp + 0x18]
108 E : push eax
109 E : call Client::FunctionEntryHook
110 :
111 : // Restore volatile registers.
112 E : popfd
113 E : pop edx
114 E : pop ecx
115 E : pop eax
116 :
117 : // Return to the address pushed by our caller.
118 E : ret
119 : }
120 : }
121 :
122 : // This instrumentation hook is used for calls to a DLL's entry point.
123 : //
124 : // Note that the calling convention to this function is non-conventional.
125 : // This function is invoked by a generated stub that does:
126 : //
127 : // push <original dllmain>
128 : // jmp _indirect_penter_dllmain
129 : //
130 : // This function will trace the entry to <original dllmain>, capture the
131 : // nature of the module event being generated, and then on exit, will
132 : // arrange for execution to jump to <original dllmain>. If required,
133 : // it will also arrange for the return from <original dllmain> to be
134 : // captured.
135 E : extern "C" void __declspec(naked) _cdecl _indirect_penter_dllmain() {
136 : __asm {
137 : // Stash volatile registers.
138 E : push eax
139 E : push ecx
140 E : push edx
141 E : pushfd
142 :
143 : // Retrieve the address pushed by our caller.
144 E : mov eax, DWORD PTR[esp + 0x10]
145 E : push eax
146 :
147 : // Calculate the position of the return address on stack, and
148 : // push it. This becomes the EntryFrame argument.
149 E : lea eax, DWORD PTR[esp + 0x18]
150 E : push eax
151 E : call Client::DllMainEntryHook
152 :
153 : // Restore volatile registers.
154 E : popfd
155 E : pop edx
156 E : pop ecx
157 E : pop eax
158 :
159 : // Return to the address pushed by our caller.
160 E : ret
161 : }
162 : }
163 :
164 : namespace agent {
165 : namespace client {
166 :
167 : class Client::ThreadLocalData {
168 : public:
169 : explicit ThreadLocalData(Client* module);
170 :
171 E : bool IsInitialized() const {
172 E : return segment.header != NULL;
173 E : }
174 :
175 : // Allocates a new FuncCall.
176 : FuncCall* AllocateFuncCall();
177 :
178 : // Flushes the current trace file segment.
179 : bool FlushSegment();
180 :
181 : // The call trace client to which this data belongs.
182 : // TODO(rogerm): This field isn't necessary, it's only used in DCHECKs.
183 : Client* const client;
184 :
185 : // The owning thread's current trace-file segment, if any.
186 : trace::client::TraceFileSegment segment;
187 :
188 : // The current batch record we're extending, if any.
189 : // This will point into the associated trace file segment's buffer.
190 : TraceBatchEnterData* batch;
191 : };
192 :
193 E : Client::Client() {
194 E : }
195 :
196 E : Client::~Client() {
197 E : }
198 :
199 E : Client* Client::Instance() {
200 E : return static_client_instance.Pointer();
201 E : }
202 :
203 : BOOL Client::DllMain(HMODULE /* module */,
204 : DWORD reason,
205 E : LPVOID /* reserved */) {
206 E : switch (reason) {
207 : case DLL_PROCESS_ATTACH:
208 : // Initialize logging ASAP.
209 E : CommandLine::Init(0, NULL);
210 E : ::common::InitLoggingForDll(L"call_trace");
211 E : break;
212 :
213 : case DLL_THREAD_ATTACH:
214 : // Session creation and thread-local data allocation are performed
215 : // just-in-time when the first instrumented entry point is invoked.
216 E : break;
217 :
218 : case DLL_PROCESS_DETACH:
219 E : OnClientProcessDetach();
220 E : break;
221 :
222 : case DLL_THREAD_DETACH:
223 E : OnClientThreadDetach();
224 E : break;
225 :
226 : default:
227 i : NOTREACHED() << "Unrecognized reason in DllMain: " << reason << ".";
228 : }
229 :
230 E : return TRUE;
231 E : }
232 :
233 E : void Client::OnClientProcessDetach() {
234 E : if (!session_.IsTracing())
235 E : return;
236 :
237 E : session_.CloseSession();
238 E : FreeThreadData();
239 E : session_.FreeSharedMemory();
240 E : }
241 :
242 E : void Client::OnClientThreadDetach() {
243 E : if (!session_.IsTracing())
244 i : return;
245 :
246 : // Get the thread data. If this thread has never called an instrumented
247 : // function, no thread local call trace data will be associated with it.
248 E : ThreadLocalData* data = GetThreadData();
249 E : if (data != NULL) {
250 E : session_.ReturnBuffer(&data->segment);
251 E : FreeThreadData(data);
252 : }
253 E : }
254 :
255 E : void Client::DllMainEntryHook(EntryFrame *entry_frame, FuncAddr function) {
256 E : ScopedLastErrorKeeper save_and_restore_last_error;
257 :
258 E : Client* client = Instance();
259 E : CHECK(client != NULL) << "Failed to get call trace client instance.";
260 :
261 E : if (client->session_.IsDisabled())
262 E : return;
263 :
264 E : HMODULE module = reinterpret_cast<HMODULE>(entry_frame->args[0]);
265 E : DWORD reason = entry_frame->args[1];
266 :
267 E : client->LogEvent_FunctionEntry(entry_frame, function, module, reason);
268 E : }
269 :
270 E : void Client::FunctionEntryHook(EntryFrame *entry_frame, FuncAddr function) {
271 E : ScopedLastErrorKeeper save_and_restore_last_error;
272 :
273 E : Client* client = Instance();
274 E : CHECK(client != NULL) << "Failed to get call trace client instance.";
275 :
276 E : if (client->session_.IsDisabled())
277 E : return;
278 :
279 E : client->LogEvent_FunctionEntry(entry_frame, function, NULL, -1);
280 E : }
281 :
282 : void Client::LogEvent_ModuleEvent(ThreadLocalData *data,
283 : HMODULE module,
284 E : DWORD reason) {
285 E : DCHECK(data != NULL);
286 E : DCHECK(module != NULL);
287 E : DCHECK(session_.IsTracing());
288 :
289 : // Perform a sanity check.
290 E : switch (reason) {
291 : case DLL_PROCESS_ATTACH:
292 : case DLL_PROCESS_DETACH:
293 E : break;
294 :
295 : case DLL_THREAD_ATTACH:
296 : case DLL_THREAD_DETACH:
297 : // We don't log these.
298 E : return;
299 : break;
300 :
301 : default:
302 i : LOG(WARNING) << "Unrecognized module event: " << reason << ".";
303 i : return;
304 : }
305 :
306 : // This already logs verbosely.
307 E : if (!agent::common::LogModule(module, &session_, &data->segment))
308 i : return;
309 :
310 : // We need to flush module events right away, so that the module is
311 : // defined in the trace file before events using that module start to
312 : // occur (in another thread).
313 E : if (reason == DLL_PROCESS_ATTACH)
314 E : data->FlushSegment();
315 E : }
316 :
317 :
318 : void Client::LogEvent_FunctionEntry(EntryFrame *entry_frame,
319 : FuncAddr function,
320 : HMODULE module,
321 E : DWORD reason ) {
322 : // TODO(rogerm): Split this up so that we don't have to pass unused
323 : // module and reason paramters on every call. This is really
324 : // sub-optimal, so address it ASAP.
325 :
326 : // If we're not currently tracing then this is (one of) the first calls
327 : // to an instrumented function. We attempt to initialize a session. If
328 : // we're not able to initialize a session, we disable the call trace
329 : // client.
330 E : ThreadLocalData *data = GetOrAllocateThreadData();
331 E : CHECK(data != NULL) << "Failed to get call trace thread context.";
332 :
333 E : if (!session_.IsTracing() && !session_.IsDisabled()) {
334 E : base::AutoLock scoped_lock(init_lock_);
335 E : if (session_.IsDisabled())
336 i : return;
337 :
338 E : if (!session_.IsTracing()) {
339 E : scoped_ptr<base::Environment> env(base::Environment::Create());
340 E : std::string id;
341 E : env->GetVar(::kSyzygyRpcInstanceIdEnvVar, &id);
342 E : session_.set_instance_id(UTF8ToWide(id));
343 E : if (!session_.CreateSession(&data->segment))
344 E : return;
345 E : }
346 E : }
347 :
348 E : DCHECK(!session_.IsDisabled());
349 E : DCHECK(session_.IsTracing());
350 :
351 E : if (!data->IsInitialized()) {
352 E : CHECK(session_.AllocateBuffer(&data->segment))
353 : << "Failed to allocate trace buffer.";
354 : }
355 :
356 : if ((module != NULL) &&
357 E : (reason == DLL_PROCESS_ATTACH || reason == DLL_THREAD_ATTACH)) {
358 E : LogEvent_ModuleEvent(data, module, reason);
359 : }
360 :
361 : // Capture the basic call info and timestamp.
362 E : FuncCall* call_info = data->AllocateFuncCall();
363 E : if (call_info != NULL) {
364 E : call_info->function = function;
365 E : call_info->tick_count = ::GetTickCount();
366 : }
367 E : }
368 :
369 E : Client::ThreadLocalData* Client::GetThreadData() {
370 E : return tls_.Get();
371 E : }
372 :
373 E : Client::ThreadLocalData* Client::GetOrAllocateThreadData() {
374 E : ThreadLocalData *data = tls_.Get();
375 E : if (data != NULL)
376 E : return data;
377 :
378 E : data = new ThreadLocalData(this);
379 E : if (data == NULL) {
380 i : LOG(ERROR) << "Unable to allocate per-thread data";
381 i : return NULL;
382 : }
383 :
384 E : tls_.Set(data);
385 E : return data;
386 E : }
387 :
388 E : void Client::FreeThreadData(ThreadLocalData *data) {
389 E : DCHECK(data != NULL);
390 :
391 E : delete data;
392 E : tls_.Set(NULL);
393 E : }
394 :
395 E : void Client::FreeThreadData() {
396 E : ThreadLocalData* data = GetThreadData();
397 E : if (data != NULL)
398 E : FreeThreadData(data);
399 E : }
400 :
401 E : Client::ThreadLocalData::ThreadLocalData(Client* c) : client(c), batch(NULL) {
402 E : }
403 :
404 E : FuncCall* Client::ThreadLocalData::AllocateFuncCall() {
405 : // Do we have a batch record that we can grow?
406 E : if (batch != NULL && segment.CanAllocateRaw(sizeof(FuncCall))) {
407 E : FuncCall* call_info = reinterpret_cast<FuncCall*>(segment.write_ptr);
408 : // The order of operations from here is pretty important. The issue is that
409 : // threads can be terminated at any point, and this happens as a matter of
410 : // fact at process exit, for any other threads than the one calling
411 : // ExitProcess. We want our shared memory buffers to be in a self-consistent
412 : // state at all times, so we proceed here by:
413 : // - allocating and initializing a new record first.
414 : // - then update the bookkeeping for the enclosures from the outermost,
415 : // inward. E.g. first we grow the file segment, then the record enclosure,
416 : // and lastly update the record itself.
417 :
418 : // Initialize the new record.
419 E : memset(call_info, 0, sizeof(*call_info));
420 :
421 : // Update the file segment size.
422 E : segment.write_ptr += sizeof(FuncCall);
423 E : segment.header->segment_length += sizeof(FuncCall);
424 :
425 : // Extend the record enclosure.
426 E : RecordPrefix* prefix = trace::client::GetRecordPrefix(batch);
427 E : prefix->size += sizeof(FuncCall);
428 :
429 : // And lastly update the inner counter.
430 E : DCHECK(call_info == batch->calls + batch->num_calls);
431 E : batch->num_calls += 1;
432 :
433 E : return call_info;
434 : }
435 :
436 : // Do we need to scarf a new buffer?
437 E : if (batch != NULL || !segment.CanAllocate(sizeof(TraceBatchEnterData))) {
438 i : if (!client->session_.ExchangeBuffer(&segment)) {
439 i : return NULL;
440 : }
441 : }
442 :
443 E : batch = segment.AllocateTraceRecord<TraceBatchEnterData>();
444 E : batch->thread_id = segment.header->thread_id;
445 E : batch->num_calls = 1;
446 :
447 E : return &batch->calls[0];
448 E : }
449 :
450 E : bool Client::ThreadLocalData::FlushSegment() {
451 E : DCHECK(IsInitialized());
452 :
453 E : batch = NULL;
454 E : return client->session_.ExchangeBuffer(&segment);
455 E : }
456 :
457 : } // namespace agent::client
458 : } // namespace agent
|