1 /* 2 * Copyright (C) 2016, The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 #include <errno.h> 18 #include <unistd.h> 19 20 #include <algorithm> 21 #include <cstring> 22 #include <memory> 23 #include <string> 24 #include <tuple> 25 #include <type_traits> 26 #include <utility> 27 28 #include "android-base/unique_fd.h" 29 #include "gmock/gmock.h" 30 #include "gtest/gtest.h" 31 32 #include "wifilogd/byte_buffer.h" 33 #include "wifilogd/local_utils.h" 34 #include "wifilogd/protocol.h" 35 #include "wifilogd/tests/mock_os.h" 36 37 #include "wifilogd/command_processor.h" 38 39 namespace android { 40 namespace wifilogd { 41 namespace { 42 43 using ::android::base::unique_fd; 44 using ::testing::_; 45 using ::testing::AnyNumber; 46 using ::testing::AtLeast; 47 using ::testing::EndsWith; 48 using ::testing::HasSubstr; 49 using ::testing::Invoke; 50 using ::testing::Return; 51 using ::testing::StartsWith; 52 using ::testing::StrictMock; 53 using local_utils::GetMaxVal; 54 55 // The CommandBuffer is deliberately larger than the maximal permitted 56 // command, so that we can test the CommandProcessor's handling of oversized 57 // inputs. 58 using CommandBuffer = ByteBuffer<protocol::kMaxMessageSize * 2>; 59 60 constexpr size_t kBufferSizeBytes = protocol::kMaxMessageSize * 16; 61 constexpr char kLogRecordSeparator = '\n'; 62 constexpr size_t kMaxAsciiMessagePayloadLen = protocol::kMaxMessageSize - 63 sizeof(protocol::Command) - 64 sizeof(protocol::AsciiMessage); 65 66 class CommandProcessorTest : public ::testing::Test { 67 public: 68 CommandProcessorTest() { 69 os_ = new StrictMock<MockOs>(); 70 auto& accumulator = written_to_os_; 71 ON_CALL(*os_, Write(_, _, _)) 72 .WillByDefault(Invoke( 73 [&accumulator](int /*fd*/, const void* write_buf, size_t buflen) { 74 accumulator.append(static_cast<const char*>(write_buf), buflen); 75 return std::tuple<size_t, Os::Errno>(buflen, 0); 76 })); 77 command_processor_ = std::unique_ptr<CommandProcessor>( 78 new CommandProcessor(kBufferSizeBytes, std::unique_ptr<Os>(os_))); 79 } 80 81 protected: 82 CommandBuffer BuildAsciiMessageCommandWithAdjustments( 83 const std::string& tag, const std::string& message, 84 ssize_t command_payload_len_adjustment, 85 ssize_t ascii_message_tag_len_adjustment, 86 ssize_t ascii_message_data_len_adjustment) { 87 const size_t adjusted_tag_len = 88 tag.length() + ascii_message_tag_len_adjustment; 89 const size_t adjusted_data_len = 90 message.length() + ascii_message_data_len_adjustment; 91 const auto& ascii_message_header = 92 protocol::AsciiMessage() 93 .set_tag_len(SAFELY_CLAMP( 94 adjusted_tag_len, uint8_t, 0, 95 GetMaxVal<decltype(protocol::AsciiMessage::tag_len)>())) 96 .set_data_len(SAFELY_CLAMP( 97 adjusted_data_len, uint16_t, 0, 98 GetMaxVal<decltype(protocol::AsciiMessage::data_len)>())) 99 .set_severity(protocol::MessageSeverity::kError); 100 EXPECT_EQ(adjusted_tag_len, ascii_message_header.tag_len); 101 EXPECT_EQ(adjusted_data_len, ascii_message_header.data_len); 102 103 const size_t payload_len = sizeof(ascii_message_header) + tag.length() + 104 message.length() + 105 command_payload_len_adjustment; 106 const auto& command = 107 protocol::Command() 108 .set_opcode(protocol::Opcode::kWriteAsciiMessage) 109 .set_payload_len(SAFELY_CLAMP( 110 payload_len, uint16_t, 0, 111 GetMaxVal<decltype(protocol::Command::payload_len)>())); 112 EXPECT_EQ(payload_len, command.payload_len); 113 return CommandBuffer() 114 .AppendOrDie(&command, sizeof(command)) 115 .AppendOrDie(&ascii_message_header, sizeof(ascii_message_header)) 116 .AppendOrDie(tag.data(), tag.length()) 117 .AppendOrDie(message.data(), message.length()); 118 } 119 120 CommandBuffer BuildAsciiMessageCommand(const std::string& tag, 121 const std::string& message) { 122 return BuildAsciiMessageCommandWithAdjustments(tag, message, 0, 0, 0); 123 } 124 125 bool SendAsciiMessageWithAdjustments( 126 const std::string& tag, const std::string& message, 127 ssize_t transport_len_adjustment, ssize_t command_payload_len_adjustment, 128 ssize_t ascii_message_tag_len_adjustment, 129 ssize_t ascii_message_data_len_adjustment) { 130 const CommandBuffer& command_buffer(BuildAsciiMessageCommandWithAdjustments( 131 tag, message, command_payload_len_adjustment, 132 ascii_message_tag_len_adjustment, ascii_message_data_len_adjustment)); 133 EXPECT_CALL(*os_, GetTimestamp(CLOCK_MONOTONIC)); 134 EXPECT_CALL(*os_, GetTimestamp(CLOCK_BOOTTIME)); 135 EXPECT_CALL(*os_, GetTimestamp(CLOCK_REALTIME)); 136 return command_processor_->ProcessCommand( 137 command_buffer.data(), command_buffer.size() + transport_len_adjustment, 138 Os::kInvalidFd); 139 } 140 141 bool SendAsciiMessage(const std::string& tag, const std::string& message) { 142 return SendAsciiMessageWithAdjustments(tag, message, 0, 0, 0, 0); 143 } 144 145 bool SendDumpBuffers() { 146 const auto& command = protocol::Command() 147 .set_opcode(protocol::Opcode::kDumpBuffers) 148 .set_payload_len(0); 149 const auto& buf = CommandBuffer().AppendOrDie(&command, sizeof(command)); 150 constexpr int kFakeFd = 100; 151 return command_processor_->ProcessCommand(buf.data(), buf.size(), kFakeFd); 152 } 153 154 std::string written_to_os_; // Must out-live |os_| 155 std::unique_ptr<CommandProcessor> command_processor_; 156 // We use a raw pointer to access the mock, since ownership passes 157 // to |command_processor_|. 158 StrictMock<MockOs>* os_; 159 }; 160 161 } // namespace 162 163 // A valid ASCII message should, of course, be processed successfully. 164 TEST_F(CommandProcessorTest, ProcessCommandOnValidAsciiMessageSucceeds) { 165 EXPECT_TRUE(SendAsciiMessage("tag", "message")); 166 } 167 168 // If the buffer given to ProcessCommand() is shorter than a protocol::Command, 169 // then we discard the data. 170 TEST_F(CommandProcessorTest, 171 ProcessCommandOnAsciiMessageShorterThanCommandFails) { 172 const CommandBuffer& command_buffer( 173 BuildAsciiMessageCommand("tag", "message")); 174 EXPECT_FALSE(command_processor_->ProcessCommand( 175 command_buffer.data(), sizeof(protocol::Command) - 1, Os::kInvalidFd)); 176 } 177 178 // In all other cases, we save the data we got, and will try to salvage the 179 // contents when dumping. 180 TEST_F(CommandProcessorTest, ProcessCommandOnAsciiMessageWithEmtpyTagSucceeds) { 181 EXPECT_TRUE(SendAsciiMessage("", "message")); 182 } 183 184 TEST_F(CommandProcessorTest, 185 ProcessCommandOnAsciiMessageWithEmptyMessageSucceeds) { 186 EXPECT_TRUE(SendAsciiMessage("tag", "")); 187 } 188 189 TEST_F(CommandProcessorTest, 190 ProcessCommandOnAsciiMessageWithEmptyTagAndMessageSucceeds) { 191 EXPECT_TRUE(SendAsciiMessage("", "")); 192 } 193 194 TEST_F(CommandProcessorTest, 195 ProcessCommandOnAsciiMessageWithBadCommandLengthSucceeds) { 196 EXPECT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", 0, 1, 0, 0)); 197 EXPECT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", 0, -1, 0, 0)); 198 } 199 200 TEST_F(CommandProcessorTest, 201 ProcessCommandOnAsciiMessageWithBadTagLengthSucceeds) { 202 EXPECT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", 0, 0, 1, 0)); 203 EXPECT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", 0, 0, -1, 0)); 204 } 205 206 TEST_F(CommandProcessorTest, 207 ProcessCommandOnAsciiMessageWithBadMessageLengthSucceeds) { 208 EXPECT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", 0, 0, 0, 1)); 209 EXPECT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", 0, 0, 0, -1)); 210 } 211 212 TEST_F(CommandProcessorTest, ProcessCommandOnOverlyLargeAsciiMessageSucceeds) { 213 const std::string tag{"tag"}; 214 EXPECT_TRUE(SendAsciiMessage( 215 tag, std::string(kMaxAsciiMessagePayloadLen - tag.size() + 1, '.'))); 216 } 217 218 TEST_F(CommandProcessorTest, ProcessCommandInvalidOpcodeReturnsFailure) { 219 using opcode_enum_t = decltype(protocol::Command::opcode); 220 using opcode_integral_t = std::underlying_type<opcode_enum_t>::type; 221 constexpr auto invalid_opcode = GetMaxVal<opcode_integral_t>(); 222 223 const auto& command = 224 protocol::Command() 225 .set_opcode(local_utils::CopyFromBufferOrDie<opcode_enum_t>( 226 &invalid_opcode, sizeof(invalid_opcode))) 227 .set_payload_len(0); 228 const auto& buf = CommandBuffer().AppendOrDie(&command, sizeof(command)); 229 constexpr int kFakeFd = 100; 230 EXPECT_FALSE( 231 command_processor_->ProcessCommand(buf.data(), buf.size(), kFakeFd)); 232 } 233 234 TEST_F(CommandProcessorTest, ProcessCommandSucceedsEvenAfterFillingBuffer) { 235 const std::string tag{"tag"}; 236 const std::string message(kMaxAsciiMessagePayloadLen - tag.size(), '.'); 237 for (size_t cumulative_payload_bytes = 0; 238 cumulative_payload_bytes <= kBufferSizeBytes; 239 cumulative_payload_bytes += (tag.size() + message.size())) { 240 EXPECT_TRUE(SendAsciiMessage(tag, message)); 241 } 242 } 243 244 TEST_F(CommandProcessorTest, 245 ProcessCommandDumpBuffersOutputIncludesCorrectlyFormattedTimestamps) { 246 const CommandBuffer& command_buf(BuildAsciiMessageCommand("tag", "message")); 247 EXPECT_CALL(*os_, GetTimestamp(CLOCK_MONOTONIC)) 248 .WillOnce(Return(Os::Timestamp{0, 999})); 249 EXPECT_CALL(*os_, GetTimestamp(CLOCK_BOOTTIME)) 250 .WillOnce(Return(Os::Timestamp{1, 1000})); 251 EXPECT_CALL(*os_, GetTimestamp(CLOCK_REALTIME)) 252 .WillOnce(Return(Os::Timestamp{123456, 123456000})); 253 EXPECT_TRUE(command_processor_->ProcessCommand( 254 command_buf.data(), command_buf.size(), Os::kInvalidFd)); 255 256 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 257 EXPECT_TRUE(SendDumpBuffers()); 258 EXPECT_THAT(written_to_os_, StartsWith("0.000000 1.000001 123456.123456")); 259 } 260 261 TEST_F(CommandProcessorTest, ProcessCommandDumpBuffersSucceedsOnEmptyLog) { 262 EXPECT_CALL(*os_, Write(_, _, _)).Times(0); 263 EXPECT_TRUE(SendDumpBuffers()); 264 } 265 266 TEST_F(CommandProcessorTest, ProcessCommandDumpBuffersIncludesAllMessages) { 267 constexpr int kNumMessages = 5; 268 for (size_t i = 0; i < kNumMessages; ++i) { 269 ASSERT_TRUE(SendAsciiMessage("tag", "message")); 270 } 271 272 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 273 EXPECT_TRUE(SendDumpBuffers()); 274 EXPECT_EQ(kNumMessages, 275 std::count(written_to_os_.begin(), written_to_os_.end(), 276 kLogRecordSeparator)); 277 } 278 279 TEST_F(CommandProcessorTest, 280 ProcessCommandDumpBuffersAsciiMessageIncludesTagAndMessage) { 281 ASSERT_TRUE(SendAsciiMessage("tag", "message")); 282 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 283 ASSERT_TRUE(SendDumpBuffers()); 284 EXPECT_THAT(written_to_os_, EndsWith("tag message\n")); 285 } 286 287 TEST_F(CommandProcessorTest, 288 ProcessCommandDumpBuffersAsciiMessageHandlesEmptyTag) { 289 ASSERT_TRUE(SendAsciiMessage("", "message")); 290 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 291 ASSERT_TRUE(SendDumpBuffers()); 292 EXPECT_THAT(written_to_os_, EndsWith("[empty] message\n")); 293 } 294 295 TEST_F(CommandProcessorTest, 296 ProcessCommandDumpBuffersAsciiMessageHandlesEmptyMessage) { 297 ASSERT_TRUE(SendAsciiMessage("tag", "")); 298 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 299 ASSERT_TRUE(SendDumpBuffers()); 300 EXPECT_THAT(written_to_os_, EndsWith("tag [empty]\n")); 301 } 302 303 TEST_F(CommandProcessorTest, 304 ProcessCommandDumpBuffersAsciiMessageHandlesEmptyTagAndEmptyMessage) { 305 ASSERT_TRUE(SendAsciiMessage("", "")); 306 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 307 ASSERT_TRUE(SendDumpBuffers()); 308 EXPECT_THAT(written_to_os_, EndsWith("[empty] [empty]\n")); 309 } 310 311 TEST_F(CommandProcessorTest, 312 ProcessCommandDumpBuffersAsciiMessageSanitizesUnprintableChars) { 313 ASSERT_TRUE(SendAsciiMessage("\xfftag\xff", "\xffmessage\xff")); 314 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 315 ASSERT_TRUE(SendDumpBuffers()); 316 EXPECT_THAT(written_to_os_, EndsWith("?tag? ?message?\n")); 317 } 318 319 TEST_F( 320 CommandProcessorTest, 321 ProcessCommandDumpBuffersAsciiMessageHandlesMessageTooShortForAsciiMessage) { // NOLINT(whitespace/line_length) 322 ASSERT_TRUE(SendAsciiMessageWithAdjustments("", "", -1, 0, 0, 0)); 323 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 324 ASSERT_TRUE(SendDumpBuffers()); 325 EXPECT_THAT(written_to_os_, EndsWith("[truncated-header]\n")); 326 } 327 328 TEST_F(CommandProcessorTest, 329 ProcessCommandDumpBuffersAsciiMessageHandlesMessageTooShortForTagStart) { 330 constexpr char kTag[] = "tag"; 331 constexpr char kMessage[] = "message"; 332 ASSERT_TRUE(SendAsciiMessageWithAdjustments( 333 kTag, kMessage, -(std::strlen(kTag) + std::strlen(kMessage)), 0, 0, 0)); 334 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 335 ASSERT_TRUE(SendDumpBuffers()); 336 EXPECT_THAT(written_to_os_, EndsWith("[buffer-overrun] [buffer-overrun]\n")); 337 } 338 339 TEST_F(CommandProcessorTest, 340 ProcessCommandDumpBuffersAsciiMessageHandlesMessageTooShortForTagEnd) { 341 constexpr char kTag[] = "tag"; 342 constexpr char kMessage[] = "message"; 343 ASSERT_TRUE(SendAsciiMessageWithAdjustments( 344 kTag, kMessage, -(1 + std::strlen(kMessage)), 0, 0, 0)); 345 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 346 ASSERT_TRUE(SendDumpBuffers()); 347 EXPECT_THAT(written_to_os_, 348 EndsWith("ta[buffer-overrun] [buffer-overrun]\n")); 349 } 350 351 TEST_F( 352 CommandProcessorTest, 353 ProcessCommandDumpBuffersAsciiMessageHandlesMessageTooShortForLogMessageStart) { // NOLINT(whitespace/line_length) 354 constexpr char kTag[] = "tag"; 355 constexpr char kMessage[] = "message"; 356 ASSERT_TRUE(SendAsciiMessageWithAdjustments(kTag, kMessage, 357 -std::strlen(kMessage), 0, 0, 0)); 358 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 359 ASSERT_TRUE(SendDumpBuffers()); 360 EXPECT_THAT(written_to_os_, EndsWith("tag [buffer-overrun]\n")); 361 } 362 363 TEST_F( 364 CommandProcessorTest, 365 ProcessCommandDumpBuffersAsciiMessageHandlesMessageTooShortForLogMessageEnd) { // NOLINT(whitespace/line_length) 366 ASSERT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", -1, 0, 0, 0)); 367 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 368 ASSERT_TRUE(SendDumpBuffers()); 369 EXPECT_THAT(written_to_os_, EndsWith("tag messag[buffer-overrun]\n")); 370 } 371 372 TEST_F(CommandProcessorTest, 373 ProcessCommandDumpBuffersAsciiMessageHandlesMessageTooLongForTag) { 374 ASSERT_TRUE(SendAsciiMessageWithAdjustments("tag", "", 100, 0, 0, 0)); 375 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 376 ASSERT_TRUE(SendDumpBuffers()); 377 EXPECT_THAT(written_to_os_, EndsWith("tag [empty]\n")); 378 } 379 380 TEST_F(CommandProcessorTest, 381 ProcessCommandDumpBuffersAsciiMessageHandlesMessageTooLongForMessage) { 382 ASSERT_TRUE(SendAsciiMessageWithAdjustments("tag", "message", 100, 0, 0, 0)); 383 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 384 ASSERT_TRUE(SendDumpBuffers()); 385 EXPECT_THAT(written_to_os_, EndsWith("tag message\n")); 386 } 387 388 TEST_F(CommandProcessorTest, ProcessCommandDumpBuffersStopsAfterFirstError) { 389 ASSERT_TRUE(SendAsciiMessage("tag", "message")); 390 ASSERT_TRUE(SendAsciiMessage("tag", "message")); 391 392 EXPECT_CALL(*os_, Write(_, _, _)) 393 .WillOnce(Return(std::tuple<size_t, Os::Errno>{-1, EBADF})); 394 ASSERT_FALSE(SendDumpBuffers()); 395 } 396 397 TEST_F(CommandProcessorTest, ProcessCommandDumpBuffersContinuesPastEintr) { 398 constexpr int kNumMessages = 5; 399 for (size_t i = 0; i < kNumMessages; ++i) { 400 ASSERT_TRUE(SendAsciiMessage("tag", "message")); 401 } 402 403 std::string written_to_os; 404 EXPECT_CALL(*os_, Write(_, _, _)) 405 .WillRepeatedly(Invoke( 406 [&written_to_os](int /*fd*/, const void* write_buf, size_t buflen) { 407 written_to_os.append(static_cast<const char*>(write_buf), buflen); 408 return std::tuple<size_t, Os::Errno>{buflen / 2, EINTR}; 409 })); 410 EXPECT_TRUE(SendDumpBuffers()); 411 EXPECT_EQ(kNumMessages, std::count(written_to_os.begin(), written_to_os.end(), 412 kLogRecordSeparator)); 413 } 414 415 TEST_F(CommandProcessorTest, ProcessCommandDumpBuffersIsIdempotent) { 416 ASSERT_TRUE(SendAsciiMessage("tag", "message")); 417 418 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 419 ASSERT_TRUE(SendDumpBuffers()); 420 ASSERT_GT(written_to_os_.size(), 0U); 421 written_to_os_.clear(); 422 ASSERT_EQ(0U, written_to_os_.size()); 423 424 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 425 EXPECT_TRUE(SendDumpBuffers()); 426 EXPECT_GT(written_to_os_.size(), 0U); 427 } 428 429 TEST_F(CommandProcessorTest, 430 ProcessCommandDumpBuffersIsIdempotentEvenWithWriteFailure) { 431 ASSERT_TRUE(SendAsciiMessage("tag", "message")); 432 EXPECT_CALL(*os_, Write(_, _, _)) 433 .WillOnce(Return(std::tuple<size_t, Os::Errno>{-1, EBADF})); 434 ASSERT_FALSE(SendDumpBuffers()); 435 ASSERT_EQ(0U, written_to_os_.size()); 436 437 EXPECT_CALL(*os_, Write(_, _, _)).Times(AtLeast(1)); 438 EXPECT_TRUE(SendDumpBuffers()); 439 EXPECT_GT(written_to_os_.size(), 0U); 440 } 441 442 // Strictly speaking, this is not a unit test. But there's no easy way to get 443 // unique_fd to call on an instance of our Os. 444 TEST_F(CommandProcessorTest, ProcessCommandClosesFd) { 445 int pipe_fds[2]; 446 ASSERT_EQ(0, pipe(pipe_fds)); 447 448 const unique_fd our_fd{pipe_fds[0]}; 449 const int their_fd = pipe_fds[1]; 450 const CommandBuffer& command_buffer( 451 BuildAsciiMessageCommand("tag", "message")); 452 EXPECT_CALL(*os_, GetTimestamp(_)).Times(AnyNumber()); 453 EXPECT_TRUE(command_processor_->ProcessCommand( 454 command_buffer.data(), command_buffer.size(), their_fd)); 455 EXPECT_EQ(-1, close(their_fd)); 456 EXPECT_EQ(EBADF, errno); 457 } 458 459 // Strictly speaking, this is not a unit test. But there's no easy way to get 460 // unique_fd to call on an instance of our Os. 461 TEST_F(CommandProcessorTest, ProcessCommandClosesFdEvenOnFailure) { 462 int pipe_fds[2]; 463 ASSERT_EQ(0, pipe(pipe_fds)); 464 465 const unique_fd our_fd{pipe_fds[0]}; 466 const int their_fd = pipe_fds[1]; 467 const CommandBuffer command_buffer; 468 EXPECT_FALSE(command_processor_->ProcessCommand( 469 command_buffer.data(), command_buffer.size(), their_fd)); 470 EXPECT_EQ(-1, close(their_fd)); 471 EXPECT_EQ(EBADF, errno); 472 } 473 474 } // namespace wifilogd 475 } // namespace android 476