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
34namespace android {
35namespace wifilogd {
36
37using ::android::base::unique_fd;
38
39using local_utils::CopyFromBufferOrDie;
40using local_utils::GetMaxVal;
41
42namespace {
43
44uint32_t NsecToUsec(uint32_t nsec);
45
46class 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
84constexpr char kUnprintableCharReplacement = '?';
85
86std::string MakeSanitizedString(const uint8_t* buf, size_t buf_len);
87
88std::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
112std::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
120uint32_t NsecToUsec(uint32_t nsec) { return nsec / 1000; }
121
122}  // namespace
123
124CommandProcessor::CommandProcessor(size_t buffer_size_bytes)
125    : current_log_buffer_(buffer_size_bytes), os_(new Os()) {}
126
127CommandProcessor::CommandProcessor(size_t buffer_size_bytes,
128                                   std::unique_ptr<Os> os)
129    : current_log_buffer_(buffer_size_bytes), os_(std::move(os)) {}
130
131CommandProcessor::~CommandProcessor() {}
132
133bool 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
167bool 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
211bool 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
256std::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