Merge "Migrate off of streaming logging" into main (65a9d4be) · Commits · e / os / platform_frameworks_native

libs/binder/Binder.cpp

+15 −16

Original line number	Diff line number	Diff line
		@@ -19,7 +19,6 @@
		#include <atomic>
		#include <set>

		#include <android-base/logging.h>
		#include <android-base/unique_fd.h>
		#include <binder/BpBinder.h>
		#include <binder/IInterface.h>
		@@ -308,7 +307,7 @@ status_t BBinder::startRecordingTransactions(const Parcel& data) {
		Extras* e = getOrCreateExtras();
		RpcMutexUniqueLock lock(e->mLock);
		if (mRecordingOn) {
		LOG(INFO) << "Could not start Binder recording. Another is already in progress.";
		ALOGI("Could not start Binder recording. Another is already in progress.");
		return INVALID_OPERATION;
		} else {
		status_t readStatus = data.readUniqueFileDescriptor(&(e->mRecordingFd));
		@@ -316,7 +315,7 @@ status_t BBinder::startRecordingTransactions(const Parcel& data) {
		return readStatus;
		}
		mRecordingOn = true;
		LOG(INFO) << "Started Binder recording.";
		ALOGI("Started Binder recording.");
		return NO_ERROR;
		}
		}
		@@ -340,10 +339,10 @@ status_t BBinder::stopRecordingTransactions() {
		if (mRecordingOn) {
		e->mRecordingFd.reset();
		mRecordingOn = false;
		LOG(INFO) << "Stopped Binder recording.";
		ALOGI("Stopped Binder recording.");
		return NO_ERROR;
		} else {
		LOG(INFO) << "Could not stop Binder recording. One is not in progress.";
		ALOGI("Could not stop Binder recording. One is not in progress.");
		return INVALID_OPERATION;
		}
		}
		@@ -377,11 +376,11 @@ status_t BBinder::transact(
		err = stopRecordingTransactions();
		break;
		case EXTENSION_TRANSACTION:
		CHECK(reply != nullptr);
		LOG_ALWAYS_FATAL_IF(reply == nullptr, "reply == nullptr");
		err = reply->writeStrongBinder(getExtension());
		break;
		case DEBUG_PID_TRANSACTION:
		CHECK(reply != nullptr);
		LOG_ALWAYS_FATAL_IF(reply == nullptr, "reply == nullptr");
		err = reply->writeInt32(getDebugPid());
		break;
		case SET_RPC_CLIENT_TRANSACTION: {
		@@ -414,10 +413,10 @@ status_t BBinder::transact(
		reply ? *reply : emptyReply, err);
		if (transaction) {
		if (status_t err = transaction->dumpToFile(e->mRecordingFd); err != NO_ERROR) {
		LOG(INFO) << "Failed to dump RecordedTransaction to file with error " << err;
		ALOGI("Failed to dump RecordedTransaction to file with error %d", err);
		}
		} else {
		LOG(INFO) << "Failed to create RecordedTransaction object.";
		ALOGI("Failed to create RecordedTransaction object.");
		}
		}
		}
		@@ -705,7 +704,7 @@ status_t BBinder::setRpcClientDebug(android::base::unique_fd socketFd,
		return status;
		}
		rpcServer->setMaxThreads(binderThreadPoolMaxCount);
		LOG(INFO) << "RpcBinder: Started Binder debug on " << getInterfaceDescriptor();
		ALOGI("RpcBinder: Started Binder debug on %s", String8(getInterfaceDescriptor()).c_str());
		rpcServer->start();
		e->mRpcServerLinks.emplace(link);
		LOG_RPC_DETAIL("%s(fd=%d) successful", __PRETTY_FUNCTION__, socketFdForPrint);
		@@ -752,7 +751,7 @@ status_t BBinder::onTransact(
		{
		switch (code) {
		case INTERFACE_TRANSACTION:
		CHECK(reply != nullptr);
		LOG_ALWAYS_FATAL_IF(reply == nullptr, "reply == nullptr");
		reply->writeString16(getInterfaceDescriptor());
		return NO_ERROR;

libs/binder/RecordedTransaction.cpp

+27 −30

Original line number	Diff line number	Diff line
		@@ -15,10 +15,10 @@
		*/

		#include <android-base/file.h>
		#include <android-base/logging.h>
		#include <android-base/unique_fd.h>
		#include <binder/Functional.h>
		#include <binder/RecordedTransaction.h>
		#include <inttypes.h>
		#include <sys/mman.h>
		#include <algorithm>

		@@ -127,18 +127,17 @@ std::optional<RecordedTransaction> RecordedTransaction::fromDetails(

		t.mData.mInterfaceName = std::string(String8(interfaceName).c_str());
		if (interfaceName.size() != t.mData.mInterfaceName.size()) {
		LOG(ERROR) << "Interface Name is not valid. Contains characters that aren't single byte "
		"utf-8.";
		ALOGE("Interface Name is not valid. Contains characters that aren't single byte utf-8.");
		return std::nullopt;
		}

		if (t.mSent.setData(dataParcel.data(), dataParcel.dataBufferSize()) != android::NO_ERROR) {
		LOG(ERROR) << "Failed to set sent parcel data.";
		ALOGE("Failed to set sent parcel data.");
		return std::nullopt;
		}

		if (t.mReply.setData(replyParcel.data(), replyParcel.dataBufferSize()) != android::NO_ERROR) {
		LOG(ERROR) << "Failed to set reply parcel data.";
		ALOGE("Failed to set reply parcel data.");
		return std::nullopt;
		}

		@@ -168,38 +167,37 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		const long pageSize = sysconf(_SC_PAGE_SIZE);
		struct stat fileStat;
		if (fstat(fd.get(), &fileStat) != 0) {
		LOG(ERROR) << "Unable to get file information";
		ALOGE("Unable to get file information");
		return std::nullopt;
		}

		off_t fdCurrentPosition = lseek(fd.get(), 0, SEEK_CUR);
		if (fdCurrentPosition == -1) {
		LOG(ERROR) << "Invalid offset in file descriptor.";
		ALOGE("Invalid offset in file descriptor.");
		return std::nullopt;
		}
		do {
		if (fileStat.st_size < (fdCurrentPosition + (off_t)sizeof(ChunkDescriptor))) {
		LOG(ERROR) << "Not enough file remains to contain expected chunk descriptor";
		ALOGE("Not enough file remains to contain expected chunk descriptor");
		return std::nullopt;
		}

		if (!android::base::ReadFully(fd, &chunk, sizeof(ChunkDescriptor))) {
		LOG(ERROR) << "Failed to read ChunkDescriptor from fd " << fd.get() << ". "
		<< strerror(errno);
		ALOGE("Failed to read ChunkDescriptor from fd %d. %s", fd.get(), strerror(errno));
		return std::nullopt;
		}
		transaction_checksum_t checksum = reinterpret_cast<transaction_checksum_t>(&chunk);

		fdCurrentPosition = lseek(fd.get(), 0, SEEK_CUR);
		if (fdCurrentPosition == -1) {
		LOG(ERROR) << "Invalid offset in file descriptor.";
		ALOGE("Invalid offset in file descriptor.");
		return std::nullopt;
		}
		off_t mmapPageAlignedStart = (fdCurrentPosition / pageSize) * pageSize;
		off_t mmapPayloadStartOffset = fdCurrentPosition - mmapPageAlignedStart;

		if (chunk.dataSize > kMaxChunkDataSize) {
		LOG(ERROR) << "Chunk data exceeds maximum size.";
		ALOGE("Chunk data exceeds maximum size.");
		return std::nullopt;
		}

		@@ -207,12 +205,12 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		chunk.dataSize + PADDING8(chunk.dataSize) + sizeof(transaction_checksum_t);

		if (chunkPayloadSize > (size_t)(fileStat.st_size - fdCurrentPosition)) {
		LOG(ERROR) << "Chunk payload exceeds remaining file size.";
		ALOGE("Chunk payload exceeds remaining file size.");
		return std::nullopt;
		}

		if (PADDING8(chunkPayloadSize) != 0) {
		LOG(ERROR) << "Invalid chunk size, not aligned " << chunkPayloadSize;
		ALOGE("Invalid chunk size, not aligned %zu", chunkPayloadSize);
		return std::nullopt;
		}

		@@ -228,8 +226,7 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		sizeof(transaction_checksum_t); // Skip chunk descriptor and required mmap
		// page-alignment
		if (payloadMap == MAP_FAILED) {
		LOG(ERROR) << "Memory mapping failed for fd " << fd.get() << ": " << errno << " "
		<< strerror(errno);
		ALOGE("Memory mapping failed for fd %d: %d %s", fd.get(), errno, strerror(errno));
		return std::nullopt;
		}
		for (size_t checksumIndex = 0;
		@@ -237,21 +234,21 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		checksum ^= payloadMap[checksumIndex];
		}
		if (checksum != 0) {
		LOG(ERROR) << "Checksum failed.";
		ALOGE("Checksum failed.");
		return std::nullopt;
		}

		fdCurrentPosition = lseek(fd.get(), chunkPayloadSize, SEEK_CUR);
		if (fdCurrentPosition == -1) {
		LOG(ERROR) << "Invalid offset in file descriptor.";
		ALOGE("Invalid offset in file descriptor.");
		return std::nullopt;
		}

		switch (chunk.chunkType) {
		case HEADER_CHUNK: {
		if (chunk.dataSize != static_cast<uint32_t>(sizeof(TransactionHeader))) {
		LOG(ERROR) << "Header Chunk indicated size " << chunk.dataSize << "; Expected "
		<< sizeof(TransactionHeader) << ".";
		ALOGE("Header Chunk indicated size %" PRIu32 "; Expected %zu.", chunk.dataSize,
		sizeof(TransactionHeader));
		return std::nullopt;
		}
		t.mData.mHeader = reinterpret_cast<TransactionHeader>(payloadMap);
		@@ -265,7 +262,7 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		case DATA_PARCEL_CHUNK: {
		if (t.mSent.setData(reinterpret_cast<const unsigned char*>(payloadMap),
		chunk.dataSize) != android::NO_ERROR) {
		LOG(ERROR) << "Failed to set sent parcel data.";
		ALOGE("Failed to set sent parcel data.");
		return std::nullopt;
		}
		break;
		@@ -273,7 +270,7 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		case REPLY_PARCEL_CHUNK: {
		if (t.mReply.setData(reinterpret_cast<const unsigned char*>(payloadMap),
		chunk.dataSize) != android::NO_ERROR) {
		LOG(ERROR) << "Failed to set reply parcel data.";
		ALOGE("Failed to set reply parcel data.");
		return std::nullopt;
		}
		break;
		@@ -281,7 +278,7 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		case END_CHUNK:
		break;
		default:
		LOG(INFO) << "Unrecognized chunk.";
		ALOGI("Unrecognized chunk.");
		break;
		}
		} while (chunk.chunkType != END_CHUNK);
		@@ -292,7 +289,7 @@ std::optional<RecordedTransaction> RecordedTransaction::fromFile(const unique_fd
		android::status_t RecordedTransaction::writeChunk(borrowed_fd fd, uint32_t chunkType,
		size_t byteCount, const uint8_t* data) const {
		if (byteCount > kMaxChunkDataSize) {
		LOG(ERROR) << "Chunk data exceeds maximum size";
		ALOGE("Chunk data exceeds maximum size");
		return BAD_VALUE;
		}
		ChunkDescriptor descriptor = {.chunkType = chunkType,
		@@ -321,7 +318,7 @@ android::status_t RecordedTransaction::writeChunk(borrowed_fd fd, uint32_t chunk

		// Write buffer to file
		if (!android::base::WriteFully(fd, buffer.data(), buffer.size())) {
		LOG(ERROR) << "Failed to write chunk fd " << fd.get();
		ALOGE("Failed to write chunk fd %d", fd.get());
		return UNKNOWN_ERROR;
		}
		return NO_ERROR;
		@@ -331,26 +328,26 @@ android::status_t RecordedTransaction::dumpToFile(const unique_fd& fd) const {
		if (NO_ERROR !=
		writeChunk(fd, HEADER_CHUNK, sizeof(TransactionHeader),
		reinterpret_cast<const uint8_t*>(&(mData.mHeader)))) {
		LOG(ERROR) << "Failed to write transactionHeader to fd " << fd.get();
		ALOGE("Failed to write transactionHeader to fd %d", fd.get());
		return UNKNOWN_ERROR;
		}
		if (NO_ERROR !=
		writeChunk(fd, INTERFACE_NAME_CHUNK, mData.mInterfaceName.size() * sizeof(uint8_t),
		reinterpret_cast<const uint8_t*>(mData.mInterfaceName.c_str()))) {
		LOG(INFO) << "Failed to write Interface Name Chunk to fd " << fd.get();
		ALOGI("Failed to write Interface Name Chunk to fd %d", fd.get());
		return UNKNOWN_ERROR;
		}

		if (NO_ERROR != writeChunk(fd, DATA_PARCEL_CHUNK, mSent.dataBufferSize(), mSent.data())) {
		LOG(ERROR) << "Failed to write sent Parcel to fd " << fd.get();
		ALOGE("Failed to write sent Parcel to fd %d", fd.get());
		return UNKNOWN_ERROR;
		}
		if (NO_ERROR != writeChunk(fd, REPLY_PARCEL_CHUNK, mReply.dataBufferSize(), mReply.data())) {
		LOG(ERROR) << "Failed to write reply Parcel to fd " << fd.get();
		ALOGE("Failed to write reply Parcel to fd %d", fd.get());
		return UNKNOWN_ERROR;
		}
		if (NO_ERROR != writeChunk(fd, END_CHUNK, 0, NULL)) {
		LOG(ERROR) << "Failed to write end chunk to fd " << fd.get();
		ALOGE("Failed to write end chunk to fd %d", fd.get());
		return UNKNOWN_ERROR;
		}
		return NO_ERROR;

libs/binder/RpcTrusty.cpp

+2 −3

Original line number	Diff line number	Diff line
		@@ -16,7 +16,6 @@

		#define LOG_TAG "RpcTrusty"

		#include <android-base/logging.h>
		#include <android-base/unique_fd.h>
		#include <binder/RpcSession.h>
		#include <binder/RpcTransportTipcAndroid.h>
		@@ -35,13 +34,13 @@ sp<RpcSession> RpcTrustyConnectWithSessionInitializer(
		auto request = [=] {
		int tipcFd = tipc_connect(device, port);
		if (tipcFd < 0) {
		LOG(ERROR) << "Failed to connect to Trusty service. Error code: " << tipcFd;
		ALOGE("Failed to connect to Trusty service. Error code: %d", tipcFd);
		return unique_fd();
		}
		return unique_fd(tipcFd);
		};
		if (status_t status = session->setupPreconnectedClient(unique_fd{}, request); status != OK) {
		LOG(ERROR) << "Failed to set up Trusty client. Error: " << statusToString(status).c_str();
		ALOGE("Failed to set up Trusty client. Error: %s", statusToString(status).c_str());
		return nullptr;
		}
		return session;

libs/binder/Utils.cpp

+1 −2

Original line number	Diff line number	Diff line
		@@ -16,7 +16,6 @@

		#include "Utils.h"

		#include <android-base/logging.h>
		#include <string.h>

		namespace android {
		@@ -26,7 +25,7 @@ void zeroMemory(uint8_t* data, size_t size) {
		}

		std::string HexString(const void* bytes, size_t len) {
		CHECK(bytes != nullptr \|\| len == 0) << bytes << " " << len;
		LOG_ALWAYS_FATAL_IF(len > 0 && bytes == nullptr, "%p %zu", bytes, len);

		// b/132916539: Doing this the 'C way', std::setfill triggers ubsan implicit conversion
		const uint8_t* bytes8 = static_cast<const uint8_t*>(bytes);

libs/binder/Utils.h

+10 −2

Original line number	Diff line number	Diff line
		@@ -22,8 +22,16 @@
		#include <log/log.h>
		#include <utils/Errors.h>

		#define PLOGE_VA_ARGS(...) , ##__VA_ARGS__
		#define PLOGE(fmt, ...) ALOGE(fmt ": %s" PLOGE_VA_ARGS(__VA_ARGS__), strerror(errno))
		#define PLOGE(fmt, ...) \
		do { \
		auto savedErrno = errno; \
		ALOGE(fmt ": %s" __VA_OPT__(, ) __VA_ARGS__, strerror(savedErrno)); \
		} while (0)
		#define PLOGF(fmt, ...) \
		do { \
		auto savedErrno = errno; \
		LOG_ALWAYS_FATAL(fmt ": %s" __VA_OPT__(, ) __VA_ARGS__, strerror(savedErrno)); \
		} while (0)

		/* TEMP_FAILURE_RETRY is not available on macOS and Trusty. */
		#ifndef TEMP_FAILURE_RETRY