Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 8f786c9f authored by Tomasz Wasilczyk's avatar Tomasz Wasilczyk Committed by Automerger Merge Worker
Browse files

Merge "Migrate off of streaming logging" into main am: 65a9d4be 

Original change: https://android-review.googlesource.com/c/platform/frameworks/native/+/2812995



Change-Id: I7bf04d70328310312fe300a88f3fc47890f1216f
Signed-off-by: default avatarAutomerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
parents 02ba47d3 65a9d4be

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