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:
set_since_boot_awake_only(Os::Timestamp new_value)48   TimestampHeader& set_since_boot_awake_only(Os::Timestamp new_value) {
49     since_boot_awake_only = new_value;
50     return *this;
51   }
52 
set_since_boot_with_sleep(Os::Timestamp new_value)53   TimestampHeader& set_since_boot_with_sleep(Os::Timestamp new_value) {
54     since_boot_with_sleep = new_value;
55     return *this;
56   }
57 
set_since_epoch(Os::Timestamp new_value)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.
ToString() const65   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 
GetStringFromMemoryReader(NONNULL MemoryReader * buffer_reader,const size_t desired_len)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 
MakeSanitizedString(const uint8_t * buf,size_t buf_len)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 
NsecToUsec(uint32_t nsec)120 uint32_t NsecToUsec(uint32_t nsec) { return nsec / 1000; }
121 
122 }  // namespace
123 
CommandProcessor(size_t buffer_size_bytes)124 CommandProcessor::CommandProcessor(size_t buffer_size_bytes)
125     : current_log_buffer_(buffer_size_bytes), os_(new Os()) {}
126 
CommandProcessor(size_t buffer_size_bytes,std::unique_ptr<Os> os)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 
~CommandProcessor()131 CommandProcessor::~CommandProcessor() {}
132 
ProcessCommand(const void * input_buffer,size_t n_bytes_read,int fd)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 
CopyCommandToLog(const void * command_buffer,size_t command_len_in)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 
Dump(unique_fd dump_fd)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     }
233     output_string += '\n';
234 
235     size_t n_written;
236     Os::Errno err;
237     std::tie(n_written, err) =
238         os_->Write(dump_fd, output_string.data(), output_string.size());
239     if (err == EINTR) {
240       // The next write will probably succeed. We dont't retry the current
241       // message, however, because we want to guarantee forward progress.
242       //
243       // TODO(b/32098735): Increment a counter, and attempt to output that
244       // counter after we've dumped all the log messages.
245     } else if (err) {
246       // Any error other than EINTR is considered unrecoverable.
247       LOG(ERROR) << "Terminating log dump, due to " << strerror(err);
248       return false;
249     }
250   }
251 
252   return true;
253 }
254 
FormatAsciiMessage(MemoryReader buffer_reader)255 std::string CommandProcessor::FormatAsciiMessage(MemoryReader buffer_reader) {
256   constexpr char kShortHeaderError[] = "[truncated-header]";
257   if (buffer_reader.size() < sizeof(protocol::AsciiMessage)) {
258     // TODO(b/32098735): Increment stats counter.
259     return kShortHeaderError;
260   }
261 
262   const auto& ascii_message_header =
263       buffer_reader.CopyOutOrDie<protocol::AsciiMessage>();
264   const std::string& formatted_tag =
265       GetStringFromMemoryReader(&buffer_reader, ascii_message_header.tag_len);
266   const std::string& formatted_msg =
267       GetStringFromMemoryReader(&buffer_reader, ascii_message_header.data_len);
268   return formatted_tag + ' ' + formatted_msg;
269 }
270 
271 }  // namespace wifilogd
272 }  // namespace android
273