Home | History | Annotate | Download | only in wifilogd 
      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 <string.h>
     18 
     19 #include <algorithm>
     20 #include <cinttypes>
     21 #include <string>
     22 #include <tuple>
     23 #include <utility>
     24 
     25 #include "android-base/logging.h"
     26 #include "android-base/stringprintf.h"
     27 
     28 #include "wifilogd/byte_buffer.h"
     29 #include "wifilogd/command_processor.h"
     30 #include "wifilogd/local_utils.h"
     31 #include "wifilogd/memory_reader.h"
     32 #include "wifilogd/protocol.h"
     33 
     34 namespace android {
     35 namespace wifilogd {
     36 
     37 using ::android::base::unique_fd;
     38 
     39 using local_utils::CopyFromBufferOrDie;
     40 using local_utils::GetMaxVal;
     41 
     42 namespace {
     43 
     44 uint32_t NsecToUsec(uint32_t nsec);
     45 
     46 class TimestampHeader {
     47  public:
     48   TimestampHeader& set_since_boot_awake_only(Os::Timestamp new_value) {
     49     since_boot_awake_only = new_value;
     50     return *this;
     51   }
     52 
     53   TimestampHeader& set_since_boot_with_sleep(Os::Timestamp new_value) {
     54     since_boot_with_sleep = new_value;
     55     return *this;
     56   }
     57 
     58   TimestampHeader& set_since_epoch(Os::Timestamp new_value) {
     59     since_epoch = new_value;
     60     return *this;
     61   }
     62 
     63   // Returns a string with a formatted representation of the timestamps
     64   // contained within this header.
     65   std::string ToString() const {
     66     const auto& awake_time = since_boot_awake_only;
     67     const auto& up_time = since_boot_with_sleep;
     68     const auto& wall_time = since_epoch;
     69     return base::StringPrintf("%" PRIu32 ".%06" PRIu32
     70                               " "
     71                               "%" PRIu32 ".%06" PRIu32
     72                               " "
     73                               "%" PRIu32 ".%06" PRIu32,
     74                               awake_time.secs, NsecToUsec(awake_time.nsecs),
     75                               up_time.secs, NsecToUsec(up_time.nsecs),
     76                               wall_time.secs, NsecToUsec(wall_time.nsecs));
     77   }
     78 
     79   Os::Timestamp since_boot_awake_only;
     80   Os::Timestamp since_boot_with_sleep;
     81   Os::Timestamp since_epoch;  // non-monotonic
     82 };
     83 
     84 constexpr char kUnprintableCharReplacement = '?';
     85 
     86 std::string MakeSanitizedString(const uint8_t* buf, size_t buf_len);
     87 
     88 std::string GetStringFromMemoryReader(NONNULL MemoryReader* buffer_reader,
     89                                       const size_t desired_len) {
     90   constexpr char kBufferOverrunError[] = "[buffer-overrun]";
     91   constexpr char kZeroLengthError[] = "[empty]";
     92   if (!desired_len) {
     93     // TODO(b/32098735): Increment stats counter.
     94     return kZeroLengthError;
     95   }
     96 
     97   auto effective_len = desired_len;
     98   if (buffer_reader->size() < effective_len) {
     99     // TODO(b/32098735): Increment stats counter.
    100     effective_len = buffer_reader->size();
    101   }
    102 
    103   auto out = MakeSanitizedString(buffer_reader->GetBytesOrDie(effective_len),
    104                                  effective_len);
    105   if (effective_len < desired_len) {
    106     out += kBufferOverrunError;
    107   }
    108 
    109   return out;
    110 }
    111 
    112 std::string MakeSanitizedString(const uint8_t* buf, size_t buf_len) {
    113   std::string out(buf_len, '\0');
    114   std::replace_copy_if(buf, buf + buf_len, &out.front(),
    115                        [](auto c) { return !local_utils::IsAsciiPrintable(c); },
    116                        kUnprintableCharReplacement);
    117   return out;
    118 }
    119 
    120 uint32_t NsecToUsec(uint32_t nsec) { return nsec / 1000; }
    121 
    122 }  // namespace
    123 
    124 CommandProcessor::CommandProcessor(size_t buffer_size_bytes)
    125     : current_log_buffer_(buffer_size_bytes), os_(new Os()) {}
    126 
    127 CommandProcessor::CommandProcessor(size_t buffer_size_bytes,
    128                                    std::unique_ptr<Os> os)
    129     : current_log_buffer_(buffer_size_bytes), os_(std::move(os)) {}
    130 
    131 CommandProcessor::~CommandProcessor() {}
    132 
    133 bool CommandProcessor::ProcessCommand(const void* input_buffer,
    134                                       size_t n_bytes_read, int fd) {
    135   unique_fd wrapped_fd(fd);
    136 
    137   if (n_bytes_read < sizeof(protocol::Command)) {
    138     // TODO(b/32098735): Increment stats counter.
    139     return false;
    140   }
    141 
    142   const auto& command_header =
    143       CopyFromBufferOrDie<protocol::Command>(input_buffer, n_bytes_read);
    144   switch (command_header.opcode) {
    145     using protocol::Opcode;
    146     case Opcode::kWriteAsciiMessage:
    147       // Copy the entire command to the log. This defers the cost of
    148       // validating the rest of the CommandHeader until we dump the
    149       // message.
    150       //
    151       // Note that most messages will be written but never read. So, in
    152       // the common case, the validation cost is actually eliminated,
    153       // rather than just deferred.
    154       return CopyCommandToLog(input_buffer, n_bytes_read);
    155     case Opcode::kDumpBuffers:
    156       return Dump(std::move(wrapped_fd));
    157   }
    158 
    159   LOG(DEBUG) << "Received unexpected opcode "
    160              << local_utils::CastEnumToInteger(command_header.opcode);
    161   // TODO(b/32098735): Increment stats counter.
    162   return false;
    163 }
    164 
    165 // Private methods below.
    166 
    167 bool CommandProcessor::CopyCommandToLog(const void* command_buffer,
    168                                         size_t command_len_in) {
    169   const uint16_t command_len =
    170       SAFELY_CLAMP(command_len_in, uint16_t, 0, protocol::kMaxMessageSize);
    171 
    172   uint16_t total_size;
    173   static_assert(GetMaxVal(total_size) > sizeof(TimestampHeader) &&
    174                     GetMaxVal(total_size) - sizeof(TimestampHeader) >=
    175                         protocol::kMaxMessageSize,
    176                 "total_size cannot represent some input messages");
    177   total_size = sizeof(TimestampHeader) + command_len;
    178   CHECK(current_log_buffer_.CanFitEver(total_size));
    179 
    180   if (!current_log_buffer_.CanFitNow(total_size)) {
    181     // TODO(b/31867689):
    182     // 1. compress current buffer
    183     // 2. move old buffer to linked list
    184     // 3. prune old buffers, if needed
    185     current_log_buffer_.Clear();
    186   }
    187   CHECK(current_log_buffer_.CanFitNow(total_size));
    188 
    189   const auto tstamp_header =
    190       TimestampHeader()
    191           .set_since_boot_awake_only(os_->GetTimestamp(CLOCK_MONOTONIC))
    192           .set_since_boot_with_sleep(os_->GetTimestamp(CLOCK_BOOTTIME))
    193           .set_since_epoch(os_->GetTimestamp(CLOCK_REALTIME));
    194   const auto message_buf =
    195       ByteBuffer<sizeof(TimestampHeader) + protocol::kMaxMessageSize>()
    196           .AppendOrDie(&tstamp_header, sizeof(tstamp_header))
    197           .AppendOrDie(command_buffer, command_len);
    198   bool did_write = current_log_buffer_.Append(
    199       message_buf.data(),
    200       SAFELY_CLAMP(message_buf.size(), uint16_t, 0, GetMaxVal<uint16_t>()));
    201   if (!did_write) {
    202     // Given that we checked for enough free space, Append() should
    203     // have succeeded. Hence, a failure here indicates a logic error,
    204     // rather than a runtime error.
    205     LOG(FATAL) << "Unexpected failure to Append()";
    206   }
    207 
    208   return true;
    209 }
    210 
    211 bool CommandProcessor::Dump(unique_fd dump_fd) {
    212   MessageBuffer::ScopedRewinder rewinder(&current_log_buffer_);
    213   while (auto buffer_reader =
    214              MemoryReader(current_log_buffer_.ConsumeNextMessage())) {
    215     const auto& tstamp_header = buffer_reader.CopyOutOrDie<TimestampHeader>();
    216     const auto& command_header =
    217         buffer_reader.CopyOutOrDie<protocol::Command>();
    218 
    219     // TOOO(b/32256098): validate |buffer_reader.size()| against payload_len,
    220     // and use a smaller size if necessary. Update a stats counter if
    221     // payload_len and
    222     // buflen do not match.
    223 
    224     std::string output_string = tstamp_header.ToString();
    225     switch (command_header.opcode) {
    226       using protocol::Opcode;
    227       case Opcode::kWriteAsciiMessage:
    228         output_string += ' ' + FormatAsciiMessage(buffer_reader);
    229         break;
    230       case Opcode::kDumpBuffers:
    231         LOG(FATAL) << "Unexpected DumpBuffers command in log";
    232         break;
    233     }
    234     output_string += '\n';
    235 
    236     size_t n_written;
    237     Os::Errno err;
    238     std::tie(n_written, err) =
    239         os_->Write(dump_fd, output_string.data(), output_string.size());
    240     if (err == EINTR) {
    241       // The next write will probably succeed. We dont't retry the current
    242       // message, however, because we want to guarantee forward progress.
    243       //
    244       // TODO(b/32098735): Increment a counter, and attempt to output that
    245       // counter after we've dumped all the log messages.
    246     } else if (err) {
    247       // Any error other than EINTR is considered unrecoverable.
    248       LOG(ERROR) << "Terminating log dump, due to " << strerror(err);
    249       return false;
    250     }
    251   }
    252 
    253   return true;
    254 }
    255 
    256 std::string CommandProcessor::FormatAsciiMessage(MemoryReader buffer_reader) {
    257   constexpr char kShortHeaderError[] = "[truncated-header]";
    258   if (buffer_reader.size() < sizeof(protocol::AsciiMessage)) {
    259     // TODO(b/32098735): Increment stats counter.
    260     return kShortHeaderError;
    261   }
    262 
    263   const auto& ascii_message_header =
    264       buffer_reader.CopyOutOrDie<protocol::AsciiMessage>();
    265   const std::string& formatted_tag =
    266       GetStringFromMemoryReader(&buffer_reader, ascii_message_header.tag_len);
    267   const std::string& formatted_msg =
    268       GetStringFromMemoryReader(&buffer_reader, ascii_message_header.data_len);
    269   return formatted_tag + ' ' + formatted_msg;
    270 }
    271 
    272 }  // namespace wifilogd
    273 }  // namespace android
    274