2014-02-26 17:50:16 +00:00
|
|
|
/*
|
|
|
|
* Copyright (C) 2012-2013 The Android Open Source Project
|
|
|
|
*
|
|
|
|
* Licensed under the Apache License, Version 2.0 (the "License");
|
|
|
|
* you may not use this file except in compliance with the License.
|
|
|
|
* You may obtain a copy of the License at
|
|
|
|
*
|
|
|
|
* http://www.apache.org/licenses/LICENSE-2.0
|
|
|
|
*
|
|
|
|
* Unless required by applicable law or agreed to in writing, software
|
|
|
|
* distributed under the License is distributed on an "AS IS" BASIS,
|
|
|
|
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
|
|
|
* See the License for the specific language governing permissions and
|
|
|
|
* limitations under the License.
|
|
|
|
*/
|
|
|
|
|
2014-02-15 00:05:05 +00:00
|
|
|
#include <ctype.h>
|
2016-12-29 15:26:30 +00:00
|
|
|
#include <inttypes.h>
|
2014-02-26 17:50:16 +00:00
|
|
|
#include <poll.h>
|
2014-04-28 21:07:23 +00:00
|
|
|
#include <sys/prctl.h>
|
2014-02-26 17:50:16 +00:00
|
|
|
#include <sys/socket.h>
|
2016-02-23 16:55:43 +00:00
|
|
|
#include <sys/types.h>
|
2014-03-24 17:26:47 +00:00
|
|
|
|
2020-05-11 23:29:29 +00:00
|
|
|
#include <chrono>
|
|
|
|
|
2020-06-03 16:23:49 +00:00
|
|
|
#include <android-base/logging.h>
|
2020-05-15 02:25:05 +00:00
|
|
|
#include <android-base/stringprintf.h>
|
2014-02-26 17:50:16 +00:00
|
|
|
#include <cutils/sockets.h>
|
2020-05-12 20:16:41 +00:00
|
|
|
#include <private/android_filesystem_config.h>
|
2016-09-30 20:30:33 +00:00
|
|
|
#include <private/android_logger.h>
|
2014-02-26 17:50:16 +00:00
|
|
|
|
2016-02-23 16:55:43 +00:00
|
|
|
#include "LogBuffer.h"
|
|
|
|
#include "LogBufferElement.h"
|
2020-05-15 17:13:38 +00:00
|
|
|
#include "LogPermissions.h"
|
2016-02-23 16:55:43 +00:00
|
|
|
#include "LogReader.h"
|
|
|
|
#include "LogUtils.h"
|
2020-05-15 02:25:05 +00:00
|
|
|
#include "LogWriter.h"
|
2014-02-26 17:50:16 +00:00
|
|
|
|
2020-05-04 18:13:55 +00:00
|
|
|
static bool CanReadSecurityLogs(SocketClient* client) {
|
|
|
|
return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM;
|
|
|
|
}
|
|
|
|
|
2020-05-15 02:25:05 +00:00
|
|
|
static std::string SocketClientToName(SocketClient* client) {
|
|
|
|
return android::base::StringPrintf("pid %d, fd %d", client->getPid(), client->getSocket());
|
|
|
|
}
|
|
|
|
|
|
|
|
class SocketLogWriter : public LogWriter {
|
|
|
|
public:
|
2020-05-29 04:03:43 +00:00
|
|
|
SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged)
|
|
|
|
: LogWriter(client->getUid(), privileged), reader_(reader), client_(client) {}
|
2020-05-15 02:25:05 +00:00
|
|
|
|
|
|
|
bool Write(const logger_entry& entry, const char* msg) override {
|
|
|
|
struct iovec iovec[2];
|
|
|
|
iovec[0].iov_base = const_cast<logger_entry*>(&entry);
|
|
|
|
iovec[0].iov_len = entry.hdr_size;
|
|
|
|
iovec[1].iov_base = const_cast<char*>(msg);
|
|
|
|
iovec[1].iov_len = entry.len;
|
|
|
|
|
|
|
|
return client_->sendDatav(iovec, 1 + (entry.len != 0)) == 0;
|
|
|
|
}
|
|
|
|
|
|
|
|
void Release() override {
|
|
|
|
reader_->release(client_);
|
|
|
|
client_->decRef();
|
|
|
|
}
|
|
|
|
|
|
|
|
void Shutdown() override { shutdown(client_->getSocket(), SHUT_RDWR); }
|
|
|
|
|
|
|
|
std::string name() const override { return SocketClientToName(client_); }
|
|
|
|
|
|
|
|
private:
|
|
|
|
LogReader* reader_;
|
|
|
|
SocketClient* client_;
|
|
|
|
};
|
|
|
|
|
2020-05-11 23:29:29 +00:00
|
|
|
LogReader::LogReader(LogBuffer* logbuf, LogReaderList* reader_list)
|
|
|
|
: SocketListener(getLogSocket(), true), log_buffer_(logbuf), reader_list_(reader_list) {}
|
2014-02-26 17:50:16 +00:00
|
|
|
|
2018-10-09 00:33:50 +00:00
|
|
|
// Note returning false will release the SocketClient instance.
|
2017-03-10 22:31:54 +00:00
|
|
|
bool LogReader::onDataAvailable(SocketClient* cli) {
|
2015-03-17 14:56:32 +00:00
|
|
|
static bool name_set;
|
|
|
|
if (!name_set) {
|
|
|
|
prctl(PR_SET_NAME, "logd.reader");
|
|
|
|
name_set = true;
|
|
|
|
}
|
2014-04-28 21:07:23 +00:00
|
|
|
|
2014-02-26 17:50:16 +00:00
|
|
|
char buffer[255];
|
|
|
|
|
|
|
|
int len = read(cli->getSocket(), buffer, sizeof(buffer) - 1);
|
|
|
|
if (len <= 0) {
|
2020-05-15 02:25:05 +00:00
|
|
|
DoSocketDelete(cli);
|
2014-02-26 17:50:16 +00:00
|
|
|
return false;
|
|
|
|
}
|
|
|
|
buffer[len] = '\0';
|
|
|
|
|
2020-05-15 02:25:05 +00:00
|
|
|
// Clients are only allowed to send one command, disconnect them if they send another.
|
|
|
|
if (DoSocketDelete(cli)) {
|
|
|
|
return false;
|
2018-10-09 00:33:50 +00:00
|
|
|
}
|
|
|
|
|
2014-02-26 17:50:16 +00:00
|
|
|
unsigned long tail = 0;
|
|
|
|
static const char _tail[] = " tail=";
|
2017-03-10 22:31:54 +00:00
|
|
|
char* cp = strstr(buffer, _tail);
|
2014-02-26 17:50:16 +00:00
|
|
|
if (cp) {
|
|
|
|
tail = atol(cp + sizeof(_tail) - 1);
|
|
|
|
}
|
|
|
|
|
2014-02-15 00:05:05 +00:00
|
|
|
log_time start(log_time::EPOCH);
|
|
|
|
static const char _start[] = " start=";
|
|
|
|
cp = strstr(buffer, _start);
|
|
|
|
if (cp) {
|
|
|
|
// Parse errors will result in current time
|
|
|
|
start.strptime(cp + sizeof(_start) - 1, "%s.%q");
|
|
|
|
}
|
|
|
|
|
2020-05-11 23:29:29 +00:00
|
|
|
std::chrono::steady_clock::time_point deadline = {};
|
2015-11-30 19:35:56 +00:00
|
|
|
static const char _timeout[] = " timeout=";
|
|
|
|
cp = strstr(buffer, _timeout);
|
|
|
|
if (cp) {
|
2020-05-11 23:29:29 +00:00
|
|
|
long timeout_seconds = atol(cp + sizeof(_timeout) - 1);
|
|
|
|
deadline = std::chrono::steady_clock::now() + std::chrono::seconds(timeout_seconds);
|
2015-11-30 19:35:56 +00:00
|
|
|
}
|
|
|
|
|
2014-02-26 17:50:16 +00:00
|
|
|
unsigned int logMask = -1;
|
|
|
|
static const char _logIds[] = " lids=";
|
|
|
|
cp = strstr(buffer, _logIds);
|
|
|
|
if (cp) {
|
|
|
|
logMask = 0;
|
|
|
|
cp += sizeof(_logIds) - 1;
|
2020-06-17 18:40:55 +00:00
|
|
|
while (*cp != '\0') {
|
2014-02-26 17:50:16 +00:00
|
|
|
int val = 0;
|
2014-02-15 00:05:05 +00:00
|
|
|
while (isdigit(*cp)) {
|
|
|
|
val = val * 10 + *cp - '0';
|
2014-02-26 17:50:16 +00:00
|
|
|
++cp;
|
|
|
|
}
|
|
|
|
logMask |= 1 << val;
|
|
|
|
if (*cp != ',') {
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
++cp;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
pid_t pid = 0;
|
|
|
|
static const char _pid[] = " pid=";
|
|
|
|
cp = strstr(buffer, _pid);
|
|
|
|
if (cp) {
|
|
|
|
pid = atol(cp + sizeof(_pid) - 1);
|
|
|
|
}
|
|
|
|
|
|
|
|
bool nonBlock = false;
|
2016-12-02 18:08:48 +00:00
|
|
|
if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) {
|
2014-09-16 16:19:47 +00:00
|
|
|
// Allow writer to get some cycles, and wait for pending notifications
|
|
|
|
sched_yield();
|
2020-05-11 23:29:29 +00:00
|
|
|
reader_list_->reader_threads_lock().lock();
|
|
|
|
reader_list_->reader_threads_lock().unlock();
|
2014-09-16 16:19:47 +00:00
|
|
|
sched_yield();
|
2014-02-26 17:50:16 +00:00
|
|
|
nonBlock = true;
|
|
|
|
}
|
|
|
|
|
2020-05-04 18:13:55 +00:00
|
|
|
bool privileged = clientHasLogCredentials(cli);
|
|
|
|
bool can_read_security = CanReadSecurityLogs(cli);
|
2020-05-29 04:03:43 +00:00
|
|
|
if (!can_read_security) {
|
|
|
|
logMask &= ~(1 << LOG_ID_SECURITY);
|
|
|
|
}
|
2020-05-04 18:13:55 +00:00
|
|
|
|
2020-05-29 04:03:43 +00:00
|
|
|
std::unique_ptr<LogWriter> socket_log_writer(new SocketLogWriter(this, cli, privileged));
|
2020-05-15 02:25:05 +00:00
|
|
|
|
2019-08-21 21:16:34 +00:00
|
|
|
uint64_t sequence = 1;
|
|
|
|
// Convert realtime to sequence number
|
|
|
|
if (start != log_time::EPOCH) {
|
2020-05-05 00:25:34 +00:00
|
|
|
bool start_time_set = false;
|
|
|
|
uint64_t last = sequence;
|
2020-05-28 19:38:21 +00:00
|
|
|
auto log_find_start = [pid, start, &sequence, &start_time_set, &last](
|
|
|
|
log_id_t, pid_t element_pid, uint64_t element_sequence,
|
logd: move leading_dropped logic into FlushTo()
This logic isn't generic, so it should not be in the generic
LogReaderThread.
Moreover, it's currently broken in essentially every case except when
filtering by UID, because it runs as in the filter functions before
the actual filtering by pid/etc takes place. For example, when
filtering by pid, it's possible to get leading chatty messages. The
newly added test was failing previously but is fixed by this change.
It's fundamentally broken in the tail case. Take this example:
1: Normal message
2: Chatty message
3: Normal message
4: Normal message
If you read that log buffer with a tail value of 3, there are three
possible outcomes:
1) Messages #2-4, however this would include a leading chatty message,
which is not allowed.
2) Messages #3-4, however this is only 2, not 3 messages.
3) Messages #1-4, however this is 4, more than the 3 requested
messages.
This code chooses 2) as the correct solution, in this case, we don't
need to account for leading chatty messages when counting the total
logs in the buffer. A test is added for this case as well.
Test: new unit test
Change-Id: Id02eb81a8e77390aba4f85aac659c6cab498dbcd
2020-05-29 03:02:42 +00:00
|
|
|
log_time element_realtime) -> FilterResult {
|
2020-05-27 21:43:19 +00:00
|
|
|
if (pid && pid != element_pid) {
|
2020-05-27 17:46:37 +00:00
|
|
|
return FilterResult::kSkip;
|
2020-05-05 00:25:34 +00:00
|
|
|
}
|
2020-05-27 21:43:19 +00:00
|
|
|
if (start == element_realtime) {
|
|
|
|
sequence = element_sequence;
|
2020-05-05 00:25:34 +00:00
|
|
|
start_time_set = true;
|
2020-05-27 17:46:37 +00:00
|
|
|
return FilterResult::kStop;
|
2020-04-08 21:36:05 +00:00
|
|
|
} else {
|
2020-05-27 21:43:19 +00:00
|
|
|
if (start < element_realtime) {
|
2020-05-05 00:25:34 +00:00
|
|
|
sequence = last;
|
|
|
|
start_time_set = true;
|
2020-05-27 17:46:37 +00:00
|
|
|
return FilterResult::kStop;
|
2014-02-19 15:33:12 +00:00
|
|
|
}
|
2020-05-27 21:43:19 +00:00
|
|
|
last = element_sequence;
|
2014-02-19 15:33:12 +00:00
|
|
|
}
|
2020-05-27 17:46:37 +00:00
|
|
|
return FilterResult::kSkip;
|
2020-05-05 00:25:34 +00:00
|
|
|
};
|
2020-05-28 19:38:21 +00:00
|
|
|
auto flush_to_state = log_buffer_->CreateFlushToState(sequence, logMask);
|
|
|
|
log_buffer_->FlushTo(socket_log_writer.get(), *flush_to_state, log_find_start);
|
2014-02-19 15:33:12 +00:00
|
|
|
|
2020-05-05 00:25:34 +00:00
|
|
|
if (!start_time_set) {
|
2019-08-21 21:16:34 +00:00
|
|
|
if (nonBlock) {
|
|
|
|
return false;
|
|
|
|
}
|
2020-05-21 20:56:33 +00:00
|
|
|
sequence = log_buffer_->sequence();
|
2014-02-19 15:33:12 +00:00
|
|
|
}
|
2014-02-15 00:05:05 +00:00
|
|
|
}
|
|
|
|
|
2020-06-03 16:23:49 +00:00
|
|
|
LOG(INFO) << android::base::StringPrintf(
|
2019-08-21 21:16:34 +00:00
|
|
|
"logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d "
|
2020-06-03 16:23:49 +00:00
|
|
|
"start=%" PRIu64 "ns deadline=%" PRIi64 "ns",
|
2019-08-21 21:16:34 +00:00
|
|
|
cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask,
|
2020-05-11 23:29:29 +00:00
|
|
|
(int)pid, start.nsec(), static_cast<int64_t>(deadline.time_since_epoch().count()));
|
2016-12-29 15:26:30 +00:00
|
|
|
|
2019-08-21 21:16:34 +00:00
|
|
|
if (start == log_time::EPOCH) {
|
2020-05-11 23:29:29 +00:00
|
|
|
deadline = {};
|
2018-10-19 20:51:35 +00:00
|
|
|
}
|
|
|
|
|
2020-05-11 23:29:29 +00:00
|
|
|
auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
|
2020-05-15 02:25:05 +00:00
|
|
|
auto entry = std::make_unique<LogReaderThread>(log_buffer_, reader_list_,
|
|
|
|
std::move(socket_log_writer), nonBlock, tail,
|
|
|
|
logMask, pid, start, sequence, deadline);
|
2018-10-09 00:33:50 +00:00
|
|
|
// release client and entry reference counts once done
|
|
|
|
cli->incRef();
|
2020-05-11 23:29:29 +00:00
|
|
|
reader_list_->reader_threads().emplace_front(std::move(entry));
|
2016-02-23 16:55:43 +00:00
|
|
|
|
|
|
|
// Set acceptable upper limit to wait for slow reader processing b/27242723
|
|
|
|
struct timeval t = { LOGD_SNDTIMEO, 0 };
|
2017-03-10 22:31:54 +00:00
|
|
|
setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t,
|
|
|
|
sizeof(t));
|
2016-02-23 16:55:43 +00:00
|
|
|
|
2014-02-26 17:50:16 +00:00
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
2020-05-15 02:25:05 +00:00
|
|
|
bool LogReader::DoSocketDelete(SocketClient* cli) {
|
|
|
|
auto cli_name = SocketClientToName(cli);
|
2020-05-11 23:29:29 +00:00
|
|
|
auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
|
2020-05-15 02:25:05 +00:00
|
|
|
for (const auto& reader : reader_list_->reader_threads()) {
|
|
|
|
if (reader->name() == cli_name) {
|
|
|
|
reader->release_Locked();
|
|
|
|
return true;
|
2014-02-26 17:50:16 +00:00
|
|
|
}
|
|
|
|
}
|
2020-05-15 02:25:05 +00:00
|
|
|
return false;
|
2014-02-26 17:50:16 +00:00
|
|
|
}
|
2014-03-24 17:26:47 +00:00
|
|
|
|
|
|
|
int LogReader::getLogSocket() {
|
|
|
|
static const char socketName[] = "logdr";
|
|
|
|
int sock = android_get_control_socket(socketName);
|
|
|
|
|
|
|
|
if (sock < 0) {
|
2017-03-10 22:31:54 +00:00
|
|
|
sock = socket_local_server(
|
|
|
|
socketName, ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET);
|
2014-03-24 17:26:47 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
return sock;
|
|
|
|
}
|