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 "syzygy/trace/agent_logger/agent_logger_app.h"
16 :
17 : #include <psapi.h>
18 : #include <userenv.h>
19 : #include <memory>
20 :
21 : #include "base/command_line.h"
22 : #include "base/environment.h"
23 : #include "base/path_service.h"
24 : #include "base/files/file_util.h"
25 : #include "base/files/scoped_temp_dir.h"
26 : #include "base/process/kill.h"
27 : #include "base/process/launch.h"
28 : #include "base/strings/string_util.h"
29 : #include "base/strings/stringprintf.h"
30 : #include "base/strings/utf_string_conversions.h"
31 : #include "gmock/gmock.h"
32 : #include "gtest/gtest.h"
33 : #include "syzygy/common/align.h"
34 : #include "syzygy/common/unittest_util.h"
35 : #include "syzygy/core/unittest_util.h"
36 : #include "syzygy/trace/agent_logger/agent_logger.h"
37 : #include "syzygy/trace/client/client_utils.h"
38 : #include "syzygy/trace/parse/parse_utils.h"
39 : #include "syzygy/trace/protocol/call_trace_defs.h"
40 : #include "syzygy/trace/service/service_rpc_impl.h"
41 :
42 : namespace trace {
43 : namespace agent_logger {
44 :
45 : namespace {
46 :
47 : class TestLoggerApp : public LoggerApp {
48 : public:
49 : using LoggerApp::FindActionHandler;
50 : using LoggerApp::OpenOutputFile;
51 : using LoggerApp::kStart;
52 : using LoggerApp::kSpawn;
53 : using LoggerApp::kStatus;
54 : using LoggerApp::kStop;
55 : using LoggerApp::kInstanceId;
56 : using LoggerApp::kUniqueInstanceId;
57 : using LoggerApp::kOutputFile;
58 : using LoggerApp::kMiniDumpDir;
59 : using LoggerApp::kStdOut;
60 : using LoggerApp::kStdErr;
61 : using LoggerApp::logger_command_line_;
62 : using LoggerApp::app_command_line_;
63 : using LoggerApp::instance_id_;
64 : using LoggerApp::action_;
65 : using LoggerApp::action_handler_;
66 : using LoggerApp::output_file_path_;
67 : using LoggerApp::append_;
68 : using LoggerApp::mini_dump_dir_;
69 : };
70 :
71 : typedef ::application::Application<TestLoggerApp> TestApp;
72 :
73 : class LoggerAppTest : public testing::ApplicationTestBase {
74 : public:
75 : typedef testing::ApplicationTestBase Super;
76 :
77 : LoggerAppTest()
78 E : : cmd_line_(base::FilePath(L"agent_logger.exe")),
79 E : test_impl_(test_app_.implementation()) {
80 E : }
81 :
82 E : void SetUp() {
83 E : Super::SetUp();
84 :
85 : // Several of the tests generate progress and (deliberate) error messages
86 : // that would otherwise clutter the unit-test output.
87 E : logging::SetMinLogLevel(logging::LOG_FATAL);
88 :
89 : // Setup the IO streams.
90 E : CreateTemporaryDir(&temp_dir_);
91 E : stdin_path_ = temp_dir_.Append(L"NUL");
92 E : stdout_path_ = temp_dir_.Append(L"stdout.txt");
93 E : stderr_path_ = temp_dir_.Append(L"stderr.txt");
94 E : InitStreams(stdin_path_, stdout_path_, stderr_path_);
95 :
96 : // Initialize the (potential) input and output path values.
97 E : instance_id_ = base::StringPrintf(L"%d", ::GetCurrentProcessId());
98 E : output_file_path_ = temp_dir_.Append(L"output.txt");
99 :
100 : // Point the application at the test's command-line and IO streams.
101 E : test_app_.set_command_line(&cmd_line_);
102 E : test_app_.set_in(in());
103 E : test_app_.set_out(out());
104 E : test_app_.set_err(err());
105 E : }
106 :
107 : protected:
108 : // Stashes the current log-level before each test instance and restores it
109 : // after each test completes.
110 : testing::ScopedLogLevelSaver log_level_saver;
111 :
112 : // @name The application under test.
113 : // @{
114 : TestApp test_app_;
115 : TestApp::Implementation& test_impl_;
116 : base::FilePath temp_dir_;
117 : base::FilePath stdin_path_;
118 : base::FilePath stdout_path_;
119 : base::FilePath stderr_path_;
120 : // @}
121 :
122 : // @name Command-line and parameters.
123 : // @{
124 : base::CommandLine cmd_line_;
125 : std::wstring instance_id_;
126 : base::FilePath output_file_path_;
127 : // @}
128 : };
129 :
130 : } // namespace
131 :
132 E : TEST_F(LoggerAppTest, GetHelp) {
133 E : cmd_line_.AppendSwitch("help");
134 E : ASSERT_FALSE(test_impl_.ParseCommandLine(&cmd_line_));
135 E : }
136 :
137 E : TEST_F(LoggerAppTest, EmptyCommandLineFails) {
138 E : ASSERT_FALSE(test_impl_.ParseCommandLine(&cmd_line_));
139 E : }
140 :
141 E : TEST_F(LoggerAppTest, ParseUnknownActionFails) {
142 E : cmd_line_.AppendArg("unknown");
143 E : ASSERT_FALSE(test_impl_.ParseCommandLine(&cmd_line_));
144 E : }
145 :
146 E : TEST_F(LoggerAppTest, ParseMispelledActionFails) {
147 E : cmd_line_.AppendArg("star");
148 E : ASSERT_FALSE(test_impl_.ParseCommandLine(&cmd_line_));
149 E : }
150 :
151 E : TEST_F(LoggerAppTest, ParseUniqueInstanceId) {
152 E : cmd_line_.AppendSwitch(TestLoggerApp::kUniqueInstanceId);
153 E : cmd_line_.AppendArg("start");
154 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
155 E : EXPECT_EQ(TestLoggerApp::kMaxInstanceIdLength,
156 E : test_impl_.instance_id_.size());
157 E : }
158 :
159 E : TEST_F(LoggerAppTest, ParseDefaultMiniDumpDir) {
160 E : cmd_line_.AppendArg("start");
161 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
162 :
163 E : base::FilePath cwd;
164 E : ASSERT_TRUE(::PathService::Get(base::DIR_CURRENT, &cwd));
165 :
166 E : EXPECT_EQ(cwd, test_impl_.mini_dump_dir_);
167 E : }
168 :
169 E : TEST_F(LoggerAppTest, ParseMiniDumpDir) {
170 E : base::FilePath new_mini_dump_dir(temp_dir_.Append(L"mini_dumps"));
171 E : ASSERT_FALSE(base::DirectoryExists(new_mini_dump_dir));
172 :
173 E : cmd_line_.AppendSwitchPath(TestLoggerApp::kMiniDumpDir, new_mini_dump_dir);
174 E : cmd_line_.AppendArg("start");
175 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
176 :
177 E : EXPECT_EQ(new_mini_dump_dir, test_impl_.mini_dump_dir_);
178 E : EXPECT_TRUE(base::DirectoryExists(new_mini_dump_dir));
179 E : }
180 :
181 E : TEST_F(LoggerAppTest, ParseBasicStart) {
182 E : cmd_line_.AppendSwitchPath(
183 : TestLoggerApp::kOutputFile, output_file_path_);
184 E : cmd_line_.AppendArgNative(TestLoggerApp::kStart);
185 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
186 E : EXPECT_EQ(output_file_path_, test_impl_.output_file_path_);
187 E : EXPECT_TRUE(test_impl_.instance_id_.empty());
188 E : EXPECT_EQ(std::wstring(TestLoggerApp::kStart), test_impl_.action_);
189 E : EXPECT_TRUE(test_impl_.app_command_line_.get() == NULL);
190 E : EXPECT_EQ(&TestLoggerApp::Start, test_impl_.action_handler_);
191 E : }
192 :
193 E : TEST_F(LoggerAppTest, ParseBasicStartWithCommand) {
194 E : const base::FilePath kFooExe(L"foo.exe");
195 E : cmd_line_.AppendSwitchPath(
196 : TestLoggerApp::kOutputFile, output_file_path_);
197 E : cmd_line_.AppendArgNative(TestLoggerApp::kStart);
198 E : cmd_line_.AppendArgNative(kFooExe.value());
199 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
200 E : EXPECT_EQ(output_file_path_, test_impl_.output_file_path_);
201 E : EXPECT_EQ(std::wstring(TestLoggerApp::kStart), test_impl_.action_);
202 E : EXPECT_TRUE(test_impl_.instance_id_.empty());
203 E : EXPECT_TRUE(test_impl_.app_command_line_.get() != NULL);
204 E : EXPECT_EQ(&TestLoggerApp::Start, test_impl_.action_handler_);
205 E : }
206 :
207 E : TEST_F(LoggerAppTest, ParseFullStartWithCommand) {
208 E : const base::FilePath kFooExe(L"foo.exe");
209 E : const std::wstring kSwitchName(L"switch");
210 E : const std::wstring kSwitchValue(L"value");
211 E : const std::wstring kDash(L"--");
212 E : const std::wstring kArg1 = kDash + kSwitchName + L"=" + kSwitchValue;
213 :
214 E : cmd_line_.AppendSwitchPath(
215 : TestLoggerApp::kOutputFile, output_file_path_);
216 E : cmd_line_.AppendSwitchNative(
217 : TestLoggerApp::kInstanceId, instance_id_);
218 E : cmd_line_.AppendArgNative(TestLoggerApp::kStart);
219 E : cmd_line_.AppendArgNative(kDash);
220 E : cmd_line_.AppendArgNative(kFooExe.value());
221 E : cmd_line_.AppendArgNative(kArg1);
222 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
223 E : EXPECT_EQ(output_file_path_, test_impl_.output_file_path_);
224 E : EXPECT_EQ(instance_id_, test_impl_.instance_id_);
225 E : EXPECT_EQ(std::wstring(TestLoggerApp::kStart), test_impl_.action_);
226 E : const base::CommandLine* app_cmd_line = test_impl_.app_command_line_.get();
227 E : ASSERT_TRUE(app_cmd_line != NULL);
228 E : EXPECT_EQ(kFooExe, app_cmd_line->GetProgram());
229 E : EXPECT_TRUE(app_cmd_line->GetSwitches().empty());
230 E : ASSERT_TRUE(app_cmd_line->GetArgs().size() == 1);
231 E : EXPECT_TRUE(app_cmd_line->GetArgs().at(0) == kArg1);
232 :
233 E : EXPECT_EQ(&TestLoggerApp::Start, test_impl_.action_handler_);
234 E : }
235 :
236 E : TEST_F(LoggerAppTest, ParseSpawn) {
237 E : cmd_line_.AppendSwitchNative(
238 : TestLoggerApp::kInstanceId, instance_id_);
239 E : cmd_line_.AppendArgNative(TestLoggerApp::kSpawn);
240 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
241 E : EXPECT_TRUE(test_impl_.output_file_path_.empty());
242 E : EXPECT_EQ(instance_id_, test_impl_.instance_id_);
243 E : EXPECT_EQ(std::wstring(TestLoggerApp::kSpawn), test_impl_.action_);
244 E : EXPECT_EQ(NULL, test_impl_.app_command_line_.get());
245 E : EXPECT_EQ(&TestLoggerApp::Spawn, test_impl_.action_handler_);
246 E : }
247 :
248 E : TEST_F(LoggerAppTest, ParseStop) {
249 E : cmd_line_.AppendSwitchNative(
250 : TestLoggerApp::kInstanceId, instance_id_);
251 E : cmd_line_.AppendArgNative(TestLoggerApp::kStop);
252 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
253 E : EXPECT_TRUE(test_impl_.output_file_path_.empty());
254 E : EXPECT_EQ(instance_id_, test_impl_.instance_id_);
255 E : EXPECT_EQ(std::wstring(TestLoggerApp::kStop), test_impl_.action_);
256 E : EXPECT_EQ(NULL, test_impl_.app_command_line_.get());
257 E : EXPECT_EQ(&TestLoggerApp::Stop, test_impl_.action_handler_);
258 E : }
259 :
260 E : TEST_F(LoggerAppTest, ParseStatus) {
261 E : cmd_line_.AppendSwitchNative(
262 : TestLoggerApp::kInstanceId, instance_id_);
263 E : cmd_line_.AppendArgNative(TestLoggerApp::kStatus);
264 E : ASSERT_TRUE(test_impl_.ParseCommandLine(&cmd_line_));
265 E : EXPECT_TRUE(test_impl_.output_file_path_.empty());
266 E : EXPECT_EQ(instance_id_, test_impl_.instance_id_);
267 E : EXPECT_EQ(std::wstring(TestLoggerApp::kStatus), test_impl_.action_);
268 E : EXPECT_EQ(NULL, test_impl_.app_command_line_.get());
269 E : EXPECT_EQ(&TestLoggerApp::Status, test_impl_.action_handler_);
270 E : }
271 :
272 E : TEST_F(LoggerAppTest, ParseUnknown) {
273 E : const std::wstring kUnknown(L"unknown");
274 E : cmd_line_.AppendSwitchNative(
275 : TestLoggerApp::kInstanceId, instance_id_);
276 E : cmd_line_.AppendArgNative(kUnknown);
277 E : ASSERT_FALSE(test_impl_.ParseCommandLine(&cmd_line_));
278 E : EXPECT_TRUE(test_impl_.output_file_path_.empty());
279 E : EXPECT_EQ(instance_id_, test_impl_.instance_id_);
280 E : EXPECT_EQ(kUnknown, test_impl_.action_);
281 E : EXPECT_EQ(NULL, test_impl_.app_command_line_.get());
282 E : EXPECT_TRUE(test_impl_.action_handler_ == NULL);
283 E : }
284 :
285 E : TEST_F(LoggerAppTest, StartEndToEnd) {
286 E : cmd_line_.AppendSwitchNative(
287 : TestLoggerApp::kInstanceId, instance_id_);
288 E : cmd_line_.AppendArgNative(TestLoggerApp::kStart);
289 E : cmd_line_.AppendArgNative(L"--");
290 E : cmd_line_.AppendArgNative(L"cmd.exe");
291 E : cmd_line_.AppendArgNative(L"/C");
292 E : cmd_line_.AppendArgNative(L"date /t");
293 :
294 E : ASSERT_EQ(0, test_app_.Run());
295 E : }
296 :
297 E : TEST_F(LoggerAppTest, StartSetsStopResetsEvent) {
298 : // The maximum time we're willing to wait for the process to get
299 : // started/killed. This is very generous, but also prevents the unittests
300 : // from hanging if the event never fires.
301 : static const size_t kTimeOutMs = 10000;
302 :
303 : // We need a different instance ID because we are spawning a new process
304 : // otherwise we get a conflict with the test above (permission issue).
305 : // TODO(georgesak): Look into that issue.
306 E : instance_id_ += L"-0";
307 E : cmd_line_.SetProgram(testing::GetExeRelativePath(L"agent_logger.exe"));
308 E : cmd_line_.AppendSwitchNative(TestLoggerApp::kInstanceId, instance_id_);
309 : // Saving the command line to be used when stopping the logger.
310 E : base::CommandLine cmd_line_saved(cmd_line_);
311 E : cmd_line_.AppendArgNative(TestLoggerApp::kStart);
312 :
313 : // Launch the logger as a separate process and make sure it succeeds.
314 E : base::LaunchOptions options;
315 E : options.start_hidden = true;
316 E : base::Process logger_process = base::LaunchProcess(cmd_line_, options);
317 E : ASSERT_TRUE(logger_process.IsValid());
318 :
319 E : std::wstring event_name;
320 E : AgentLogger::GetSyzygyAgentLoggerEventName(instance_id_, &event_name);
321 E : base::win::ScopedHandle event(
322 : ::CreateEvent(NULL, FALSE, FALSE, event_name.c_str()));
323 E : EXPECT_EQ(WAIT_OBJECT_0, ::WaitForSingleObject(event.Get(), kTimeOutMs));
324 E : cmd_line_ = cmd_line_saved;
325 E : cmd_line_.AppendArgNative(TestLoggerApp::kStop);
326 E : base::Process logger_process_kill = base::LaunchProcess(cmd_line_, options);
327 E : ASSERT_TRUE(logger_process_kill.IsValid());
328 E : int exit_code = 0;
329 E : ASSERT_TRUE(logger_process.WaitForExitWithTimeout(
330 E : base::TimeDelta::FromMilliseconds(kTimeOutMs), &exit_code));
331 E : ASSERT_EQ(WAIT_TIMEOUT, ::WaitForSingleObject(event.Get(), 0));
332 E : }
333 :
334 : } // namespace agent_logger
335 : } // namespace trace
|