1 : // Copyright 2012 Google Inc. All Rights Reserved.
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 : #include <iostream>
16 :
17 : #include "base/at_exit.h"
18 : #include "base/command_line.h"
19 : #include "base/environment.h"
20 : #include "base/file_util.h"
21 : #include "base/files/file_path.h"
22 : #include "base/logging.h"
23 : #include "base/memory/scoped_ptr.h"
24 : #include "base/path_service.h"
25 : #include "base/process/kill.h"
26 : #include "base/process/launch.h"
27 : #include "base/strings/string_number_conversions.h"
28 : #include "base/strings/string_piece.h"
29 : #include "base/strings/string_util.h"
30 : #include "base/strings/utf_string_conversions.h"
31 : #include "base/threading/thread.h"
32 : #include "syzygy/common/com_utils.h"
33 : #include "syzygy/common/rpc/helpers.h"
34 : #include "syzygy/trace/common/service_util.h"
35 : #include "syzygy/trace/protocol/call_trace_defs.h"
36 : #include "syzygy/trace/service/service.h"
37 : #include "syzygy/trace/service/service_rpc_impl.h"
38 : #include "syzygy/trace/service/session_trace_file_writer_factory.h"
39 :
40 : namespace trace {
41 : namespace service {
42 : namespace {
43 :
44 : using ::common::rpc::CreateRpcBinding;
45 : using ::common::rpc::InvokeRpc;
46 :
47 : // Minimum buffer size to allow (1 MB).
48 : const int kMinBufferSize = 1024 * 1024;
49 :
50 : // Minimum number of buffers to allocate.
51 : const int kMinBuffers = 16;
52 :
53 : // A static location to which the current instance id can be saved. We
54 : // persist it here so that OnConsoleCtrl can have access to the instance
55 : // id when it is invoked on the signal handler thread.
56 : wchar_t saved_instance_id[16] = {0};
57 :
58 : // Forward declaration.
59 : bool StopService(const base::StringPiece16& instance_id);
60 :
61 : // Handler function to be called on exit signals (Ctrl-C, TERM, etc...).
62 i : BOOL WINAPI OnConsoleCtrl(DWORD ctrl_type) {
63 i : if (ctrl_type != CTRL_LOGOFF_EVENT) {
64 i : StopService(saved_instance_id);
65 i : return TRUE;
66 : }
67 i : return FALSE;
68 i : }
69 :
70 : const char* const kInstanceId = "instance-id";
71 :
72 : const char kUsage[] =
73 : "Usage: call_trace_service [OPTIONS] ACTION [-- command]\n"
74 : "\n"
75 : "Actions:\n"
76 : " start Start the call trace service. This causes an\n"
77 : " instance of the service to be launched as a\n"
78 : " foreground process.\n"
79 : " spawn Spawns an instance of the call trace service, waits\n"
80 : " for it to be ready, and returns. The call trace\n"
81 : " service continues running in the background.\n"
82 : " stop Stop the call trace service.\n"
83 : "\n"
84 : "Options:\n"
85 : " --help Show this help message.\n"
86 : " --trace-dir=PATH The directory in which to write the trace files.\n"
87 : " --buffer-size=NUM The size (in bytes) of each buffer to allocate.\n"
88 : " --num-incremental-buffers=NUM\n"
89 : " The number of buffers by which to grow the buffer\n"
90 : " pool each time the client exhausts its available\n"
91 : " buffer space.\n"
92 : " --enable-exits Enable exit tracing (off by default).\n"
93 : " --verbose Increase the logging verbosity to also include\n"
94 : " debug-level information.\n"
95 : " --instance-id=ID A unique identifier to use for the RPC endpoint.\n"
96 : " This allows multiple instances of the service to\n"
97 : " run concurrently. By default this is empty.\n"
98 : "\n";
99 :
100 i : int Usage() {
101 i : std::cout << kUsage;
102 i : return 1;
103 i : }
104 :
105 E : bool GetInstanceId(const CommandLine* cmd_line, std::wstring* id) {
106 E : DCHECK(cmd_line != NULL);
107 E : DCHECK(id != NULL);
108 :
109 : // If not specified, this defaults to the empty string.
110 E : *id = cmd_line->GetSwitchValueNative(kInstanceId);
111 :
112 E : const size_t kMaxLength = arraysize(saved_instance_id) - 1;
113 E : if (id->length() > kMaxLength) {
114 i : LOG(ERROR) << "The instance id '" << *id << "' is too long. "
115 : << "The max length is " << kMaxLength << " characters.";
116 i : return false;
117 : }
118 :
119 E : return true;
120 E : }
121 :
122 : // A helper function which sets the Syzygy RPC instance id environment variable
123 : // then runs a given command line to completion.
124 : // TODO(etienneb): We should merge common code of logger and call_service.
125 : bool RunApp(const CommandLine& command_line,
126 : const std::wstring& instance_id,
127 i : int* exit_code) {
128 i : DCHECK(exit_code != NULL);
129 i : scoped_ptr<base::Environment> env(base::Environment::Create());
130 i : CHECK(env != NULL);
131 i : env->SetVar(kSyzygyRpcInstanceIdEnvVar, base::WideToUTF8(instance_id));
132 :
133 i : LOG(INFO) << "Launching '" << command_line.GetProgram().value() << "'.";
134 i : VLOG(1) << "Command Line: " << command_line.GetCommandLineString();
135 :
136 : // Launch a new process in the background.
137 : base::ProcessHandle process_handle;
138 i : base::LaunchOptions options;
139 i : options.start_hidden = false;
140 i : if (!base::LaunchProcess(command_line, options, &process_handle)) {
141 i : LOG(ERROR)
142 : << "Failed to launch '" << command_line.GetProgram().value() << "'.";
143 i : return false;
144 : }
145 :
146 : // Wait for and return the processes exit code.
147 : // Note that this closes the process handle.
148 i : if (!base::WaitForExitCode(process_handle, exit_code)) {
149 i : LOG(ERROR) << "Failed to get exit code.";
150 i : return false;
151 : }
152 :
153 i : return true;
154 i : }
155 :
156 : bool RunService(const CommandLine* cmd_line,
157 E : const scoped_ptr<CommandLine>* app_cmd_line) {
158 E : DCHECK(cmd_line != NULL);
159 E : DCHECK(app_cmd_line != NULL);
160 :
161 E : base::Thread writer_thread("trace-file-writer");
162 : if (!writer_thread.StartWithOptions(
163 E : base::Thread::Options(base::MessageLoop::TYPE_IO, 0))) {
164 i : LOG(ERROR) << "Failed to start call trace service writer thread.";
165 i : return 1;
166 : }
167 :
168 E : base::MessageLoop* message_loop = writer_thread.message_loop();
169 E : SessionTraceFileWriterFactory session_trace_file_writer_factory(message_loop);
170 E : Service call_trace_service(&session_trace_file_writer_factory);
171 E : RpcServiceInstanceManager rpc_instance(&call_trace_service);
172 :
173 : // Get/set the instance id.
174 E : std::wstring instance_id;
175 E : if (!GetInstanceId(cmd_line, &instance_id))
176 i : return false;
177 :
178 E : call_trace_service.set_instance_id(instance_id);
179 : base::wcslcpy(saved_instance_id,
180 : instance_id.c_str(),
181 E : arraysize(saved_instance_id));
182 :
183 : // Set up the trace directory.
184 E : base::FilePath trace_directory(cmd_line->GetSwitchValuePath("trace-dir"));
185 E : if (trace_directory.empty())
186 E : trace_directory = base::FilePath(L".");
187 E : if (!session_trace_file_writer_factory.SetTraceFileDirectory(trace_directory))
188 i : return false;
189 :
190 : // Setup the buffer size.
191 E : std::wstring buffer_size_str(cmd_line->GetSwitchValueNative("buffer-size"));
192 E : if (!buffer_size_str.empty()) {
193 i : int num = 0;
194 i : if (!base::StringToInt(buffer_size_str, &num) || num < kMinBufferSize) {
195 i : LOG(ERROR) << "Buffer size is too small (<" << kMinBufferSize << ").";
196 i : return false;
197 : }
198 i : call_trace_service.set_buffer_size_in_bytes(num);
199 : }
200 :
201 E : if (cmd_line->HasSwitch("enable-exits")) {
202 i : call_trace_service.set_flags(TRACE_FLAG_ENTER | TRACE_FLAG_EXIT);
203 : }
204 :
205 : // Setup the number of incremental buffers
206 : std::wstring buffers_str(
207 E : cmd_line->GetSwitchValueNative("num-incremental-buffers"));
208 E : if (!buffers_str.empty()) {
209 i : int num = 0;
210 i : if (!base::StringToInt(buffers_str, &num) || num < kMinBuffers) {
211 i : LOG(ERROR) << "Number of incremental buffers is too small (<"
212 : << kMinBuffers << ").";
213 i : return false;
214 : }
215 i : call_trace_service.set_num_incremental_buffers(num);
216 : }
217 :
218 E : if (app_cmd_line->get() != NULL) {
219 : // Run the service in non-blocking mode.
220 i : call_trace_service.Start(true);
221 :
222 : // We have a command to run, so launch that command and when it finishes
223 : // stop the logger.
224 i : int exit_code = 0;
225 : if (!RunApp(*app_cmd_line->get(), instance_id, &exit_code) ||
226 i : exit_code != 0) {
227 i : return false;
228 : }
229 i : } else {
230 : // Setup the handler for exit signals.
231 E : if (!SetConsoleCtrlHandler(&OnConsoleCtrl, TRUE)) {
232 i : DWORD error = ::GetLastError();
233 i : LOG(ERROR) << "Failed to register shutdown handler: "
234 : << ::common::LogWe(error) << ".";
235 i : return false;
236 : }
237 :
238 : // Run the service in blocking mode. This will not return until the service
239 : // has been externally stopped.
240 E : call_trace_service.Start(false);
241 :
242 : // We no longer need to look out for exit signals.
243 E : SetConsoleCtrlHandler(&OnConsoleCtrl, FALSE);
244 : }
245 :
246 : // The call trace service will be stopped on destruction.
247 E : return true;
248 E : }
249 :
250 i : bool SpawnService(const CommandLine* cmd_line) {
251 : // Get the path to ourselves.
252 i : base::FilePath self_path;
253 i : PathService::Get(base::FILE_EXE, &self_path);
254 :
255 : // Build a command line for starting a new instance of the service.
256 i : CommandLine service_cmd(self_path);
257 i : service_cmd.AppendArg("start");
258 :
259 : // Copy over any other switches.
260 : CommandLine::SwitchMap::const_iterator it =
261 i : cmd_line->GetSwitches().begin();
262 i : for (; it != cmd_line->GetSwitches().end(); ++it)
263 i : service_cmd.AppendSwitchNative(it->first, it->second);
264 :
265 : // Get the instance id.
266 i : std::wstring instance_id;
267 i : if (!GetInstanceId(cmd_line, &instance_id))
268 i : return false;
269 :
270 : // Launch a new process in the background.
271 i : LOG(INFO) << "Launching background call trace service with instance ID \""
272 : << instance_id << "\".";
273 : base::ProcessHandle service_process;
274 i : base::LaunchOptions options;
275 i : options.start_hidden = true;
276 i : if (!base::LaunchProcess(service_cmd, options, &service_process)) {
277 i : LOG(ERROR) << "Failed to launch process.";
278 i : return false;
279 : }
280 i : DCHECK_NE(base::kNullProcessHandle, service_process);
281 :
282 : // Get the name of the event that will be signaled when the service is up
283 : // and running.
284 i : std::wstring event_name;
285 i : ::GetSyzygyCallTraceRpcEventName(instance_id, &event_name);
286 : base::win::ScopedHandle rpc_event(
287 i : ::CreateEvent(NULL, TRUE, FALSE, event_name.c_str()));
288 i : if (!rpc_event.IsValid()) {
289 i : LOG(ERROR) << "Unable to create RPC event for instance id \""
290 : << instance_id << "\".";
291 i : return false;
292 : }
293 :
294 : // We wait on both the RPC event and the process, as if the process fails for
295 : // any reason, it'll exit and its handle will become signaled.
296 i : HANDLE handles[] = { rpc_event.Get(), service_process };
297 : if (::WaitForMultipleObjects(arraysize(handles),
298 : handles,
299 : FALSE,
300 i : INFINITE) != WAIT_OBJECT_0) {
301 i : LOG(ERROR) << "The spawned call trace service exited in error.";
302 i : return false;
303 : }
304 :
305 i : LOG(INFO) << "Background call trace service with instance ID \""
306 : << instance_id << "\" is ready.";
307 :
308 i : return true;
309 i : }
310 :
311 E : bool StopService(const base::StringPiece16& instance_id) {
312 E : std::wstring protocol;
313 E : std::wstring endpoint;
314 :
315 E : ::GetSyzygyCallTraceRpcProtocol(&protocol);
316 E : ::GetSyzygyCallTraceRpcEndpoint(instance_id, &endpoint);
317 :
318 E : LOG(INFO) << "Stopping call trace logging service instance at '"
319 : << endpoint << "' via " << protocol << '.';
320 :
321 E : handle_t binding = NULL;
322 E : if (!CreateRpcBinding(protocol, endpoint, &binding)) {
323 i : LOG(ERROR) << "Failed to connect to call trace logging service.";
324 i : return false;
325 : }
326 :
327 E : if (!InvokeRpc(CallTraceClient_Stop, binding).succeeded()) {
328 i : LOG(ERROR) << "Failed to stop call trace logging service.";
329 i : return false;
330 : }
331 :
332 : // TODO(rogerm): It would be nice to make this blocking until the
333 : // service actually shuts down. Perhaps with retries on the stop
334 : // request.
335 E : LOG(INFO) << "Call trace service shutdown has been requested.";
336 E : return true;
337 E : }
338 :
339 E : extern "C" int main(int argc, char** argv) {
340 E : base::AtExitManager at_exit_manager;
341 E : CommandLine::Init(argc, argv);
342 E : const int kVlogLevelVerbose = -2;
343 :
344 E : logging::LoggingSettings settings;
345 E : settings.logging_dest = logging::LOG_TO_SYSTEM_DEBUG_LOG;
346 E : settings.lock_log = logging::DONT_LOCK_LOG_FILE;
347 E : settings.delete_old = logging::APPEND_TO_OLD_LOG_FILE;
348 E : if (!logging::InitLogging(settings))
349 i : return 1;
350 :
351 : // TODO(rogerm): Turn on ETW logging as well.
352 :
353 E : CommandLine* cmd_line = CommandLine::ForCurrentProcess();
354 E : DCHECK(cmd_line != NULL);
355 :
356 E : CommandLine calltrace_command_line(CommandLine::NO_PROGRAM);
357 E : scoped_ptr<CommandLine> app_command_line;
358 : if (!trace::common::SplitCommandLine(
359 : cmd_line,
360 : &calltrace_command_line,
361 E : &app_command_line)) {
362 i : LOG(ERROR) << "Failed to split command_line into logger and app parts.";
363 i : return false;
364 : }
365 :
366 : // Save the command-line in case we need to spawn.
367 E : cmd_line = &calltrace_command_line;
368 :
369 E : if (cmd_line->HasSwitch("verbose")) {
370 E : logging::SetMinLogLevel(kVlogLevelVerbose);
371 : }
372 :
373 E : if (cmd_line->HasSwitch("help") || cmd_line->GetArgs().size() < 1) {
374 i : return Usage();
375 : }
376 :
377 E : if (LowerCaseEqualsASCII(cmd_line->GetArgs()[0], "stop")) {
378 E : std::wstring id;
379 E : return (GetInstanceId(cmd_line, &id) && StopService(id)) ? 0 : 1;
380 : }
381 :
382 E : if (LowerCaseEqualsASCII(cmd_line->GetArgs()[0], "start")) {
383 E : return RunService(cmd_line, &app_command_line) ? 0 : 1;
384 : }
385 :
386 i : if (LowerCaseEqualsASCII(cmd_line->GetArgs()[0], "spawn")) {
387 i : return SpawnService(cmd_line) ? 0 : 1;
388 : }
389 :
390 i : return Usage();
391 E : }
392 :
393 : } // namespace
394 : } // namespace service
395 : } // namespace trace
|