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

Commit aefc9cda authored by Andy McFadden's avatar Andy McFadden
Browse files

Resurrect verbose binder logging 

Updated the command name lists, and masked off the additional bits in
the command word when doing the name lookup.

Made descriptor values easier to grep for and consistent with kernel
output (i.e. decimal rather than hex).  Attempt to show transaction
descriptors as such (they're in a union with a pointer).

Also, the writeLines() function in Static was using a no-op
logging call to write an iovec.  It looks like all callers are using
N=1, so I just added a log for the first string.

Bug 5155269

Change-Id: I417b8d77da3eb6ee1d2069ba94047210f75738bc
parent 7f739ae6

libs/binder/IPCThreadState.cpp

+38 −36
Original line number Original line Diff line number Diff line
@@ -78,12 +78,8 @@ static const void* printCommand(TextOutput& out, const void* _cmd); 
// conditionals don't get stripped...  but that is probably what we want.

// conditionals don't get stripped...  but that is probably what we want.

#if !LOG_NDEBUG

#if !LOG_NDEBUG

static const char *kReturnStrings[] = {

static const char *kReturnStrings[] = {

#if 1 /* TODO: error update strings */

    "BR_ERROR",

    "unknown",

#else

    "BR_OK",

    "BR_OK",

    "BR_TIMEOUT",

    "BR_WAKEUP",

    "BR_TRANSACTION",

    "BR_TRANSACTION",

    "BR_REPLY",

    "BR_REPLY",

    "BR_ACQUIRE_RESULT",

    "BR_ACQUIRE_RESULT",
@@ -94,25 +90,19 @@ static const char *kReturnStrings[] = { 
    "BR_RELEASE",

    "BR_RELEASE",

    "BR_DECREFS",

    "BR_DECREFS",

    "BR_ATTEMPT_ACQUIRE",

    "BR_ATTEMPT_ACQUIRE",

    "BR_EVENT_OCCURRED",

    "BR_NOOP",

    "BR_NOOP",

    "BR_SPAWN_LOOPER",

    "BR_SPAWN_LOOPER",

    "BR_FINISHED",

    "BR_FINISHED",

    "BR_DEAD_BINDER",

    "BR_DEAD_BINDER",

    "BR_CLEAR_DEATH_NOTIFICATION_DONE"

    "BR_CLEAR_DEATH_NOTIFICATION_DONE",

#endif

    "BR_FAILED_REPLY"

};

};





static const char *kCommandStrings[] = {

static const char *kCommandStrings[] = {

#if 1 /* TODO: error update strings */

    "unknown",

#else

    "BC_NOOP",

    "BC_TRANSACTION",

    "BC_TRANSACTION",

    "BC_REPLY",

    "BC_REPLY",

    "BC_ACQUIRE_RESULT",

    "BC_ACQUIRE_RESULT",

    "BC_FREE_BUFFER",

    "BC_FREE_BUFFER",

    "BC_TRANSACTION_COMPLETE",

    "BC_INCREFS",

    "BC_INCREFS",

    "BC_ACQUIRE",

    "BC_ACQUIRE",

    "BC_RELEASE",

    "BC_RELEASE",
@@ -120,18 +110,12 @@ static const char *kCommandStrings[] = { 
    "BC_INCREFS_DONE",

    "BC_INCREFS_DONE",

    "BC_ACQUIRE_DONE",

    "BC_ACQUIRE_DONE",

    "BC_ATTEMPT_ACQUIRE",

    "BC_ATTEMPT_ACQUIRE",

    "BC_RETRIEVE_ROOT_OBJECT",

    "BC_SET_THREAD_ENTRY",

    "BC_REGISTER_LOOPER",

    "BC_REGISTER_LOOPER",

    "BC_ENTER_LOOPER",

    "BC_ENTER_LOOPER",

    "BC_EXIT_LOOPER",

    "BC_EXIT_LOOPER",

    "BC_SYNC",

    "BC_STOP_PROCESS",

    "BC_STOP_SELF",

    "BC_REQUEST_DEATH_NOTIFICATION",

    "BC_REQUEST_DEATH_NOTIFICATION",

    "BC_CLEAR_DEATH_NOTIFICATION",

    "BC_CLEAR_DEATH_NOTIFICATION",

    "BC_DEAD_BINDER_DONE"

    "BC_DEAD_BINDER_DONE"

#endif

};

};





static const char* getReturnString(size_t idx)

static const char* getReturnString(size_t idx)
@@ -154,30 +138,36 @@ static const void* printBinderTransactionData(TextOutput& out, const void* data) 
{

{

    const binder_transaction_data* btd =

    const binder_transaction_data* btd =

        (const binder_transaction_data*)data;

        (const binder_transaction_data*)data;

    out << "target=" << btd->target.ptr << " (cookie " << btd->cookie << ")" << endl

    if (btd->target.handle < 1024) {

        /* want to print descriptors in decimal; guess based on value */

        out << "target.desc=" << btd->target.handle;

    } else {

        out << "target.ptr=" << btd->target.ptr;

    }

    out << " (cookie " << btd->cookie << ")" << endl

        << "code=" << TypeCode(btd->code) << ", flags=" << (void*)btd->flags << endl

        << "code=" << TypeCode(btd->code) << ", flags=" << (void*)btd->flags << endl

        << "data=" << btd->data.ptr.buffer << " (" << (void*)btd->data_size

        << "data=" << btd->data.ptr.buffer << " (" << (void*)btd->data_size

        << " bytes)" << endl

        << " bytes)" << endl

        << "offsets=" << btd->data.ptr.offsets << " (" << (void*)btd->offsets_size

        << "offsets=" << btd->data.ptr.offsets << " (" << (void*)btd->offsets_size

        << " bytes)" << endl;

        << " bytes)";

    return btd+1;

    return btd+1;

}

}





static const void* printReturnCommand(TextOutput& out, const void* _cmd)

static const void* printReturnCommand(TextOutput& out, const void* _cmd)

{

{

    static const int32_t N = sizeof(kReturnStrings)/sizeof(kReturnStrings[0]);

    static const size_t N = sizeof(kReturnStrings)/sizeof(kReturnStrings[0]);

    

    const int32_t* cmd = (const int32_t*)_cmd;

    const int32_t* cmd = (const int32_t*)_cmd;

    int32_t code = *cmd++;

    int32_t code = *cmd++;

    if (code == BR_ERROR) {

    size_t cmdIndex = code & 0xff;

    if (code == (int32_t) BR_ERROR) {

        out << "BR_ERROR: " << (void*)(*cmd++) << endl;

        out << "BR_ERROR: " << (void*)(*cmd++) << endl;

        return cmd;

        return cmd;

    } else if (code < 0 || code >= N) {

    } else if (cmdIndex >= N) {

        out << "Unknown reply: " << code << endl;

        out << "Unknown reply: " << code << endl;

        return cmd;

        return cmd;

    }

    }

    out << kReturnStrings[cmdIndex];

    

    

    out << kReturnStrings[code];

    switch (code) {

    switch (code) {

        case BR_TRANSACTION:

        case BR_TRANSACTION:

        case BR_REPLY: {

        case BR_REPLY: {
@@ -213,6 +203,11 @@ static const void* printReturnCommand(TextOutput& out, const void* _cmd) 
            const int32_t c = *cmd++;

            const int32_t c = *cmd++;

            out << ": death cookie " << (void*)c;

            out << ": death cookie " << (void*)c;

        } break;

        } break;



        default:

            // no details to show for: BR_OK, BR_DEAD_REPLY,

            // BR_TRANSACTION_COMPLETE, BR_FINISHED

            break;

    }

    }

    

    

    out << endl;

    out << endl;
@@ -221,16 +216,17 @@ static const void* printReturnCommand(TextOutput& out, const void* _cmd) 




static const void* printCommand(TextOutput& out, const void* _cmd)

static const void* printCommand(TextOutput& out, const void* _cmd)

{

{

    static const int32_t N = sizeof(kCommandStrings)/sizeof(kCommandStrings[0]);

    static const size_t N = sizeof(kCommandStrings)/sizeof(kCommandStrings[0]);

    

    const int32_t* cmd = (const int32_t*)_cmd;

    const int32_t* cmd = (const int32_t*)_cmd;

    int32_t code = *cmd++;

    int32_t code = *cmd++;

    if (code < 0 || code >= N) {

    size_t cmdIndex = code & 0xff;



    if (cmdIndex >= N) {

        out << "Unknown command: " << code << endl;

        out << "Unknown command: " << code << endl;

        return cmd;

        return cmd;

    }

    }

    out << kCommandStrings[cmdIndex];





    out << kCommandStrings[code];

    switch (code) {

    switch (code) {

        case BC_TRANSACTION:

        case BC_TRANSACTION:

        case BC_REPLY: {

        case BC_REPLY: {
@@ -254,7 +250,7 @@ static const void* printCommand(TextOutput& out, const void* _cmd) 
        case BC_RELEASE:

        case BC_RELEASE:

        case BC_DECREFS: {

        case BC_DECREFS: {

            const int32_t d = *cmd++;

            const int32_t d = *cmd++;

            out << ": descriptor=" << (void*)d;

            out << ": desc=" << d;

        } break;

        } break;

    

    

        case BC_INCREFS_DONE:

        case BC_INCREFS_DONE:
@@ -267,7 +263,7 @@ static const void* printCommand(TextOutput& out, const void* _cmd) 
        case BC_ATTEMPT_ACQUIRE: {

        case BC_ATTEMPT_ACQUIRE: {

            const int32_t p = *cmd++;

            const int32_t p = *cmd++;

            const int32_t d = *cmd++;

            const int32_t d = *cmd++;

            out << ": decriptor=" << (void*)d << ", pri=" << p;

            out << ": desc=" << d << ", pri=" << p;

        } break;

        } break;

        

        

        case BC_REQUEST_DEATH_NOTIFICATION:

        case BC_REQUEST_DEATH_NOTIFICATION:
@@ -281,6 +277,11 @@ static const void* printCommand(TextOutput& out, const void* _cmd) 
            const int32_t c = *cmd++;

            const int32_t c = *cmd++;

            out << ": death cookie " << (void*)c;

            out << ": death cookie " << (void*)c;

        } break;

        } break;



        default:

            // no details to show for: BC_REGISTER_LOOPER, BC_ENTER_LOOPER,

            // BC_EXIT_LOOPER

            break;

    }

    }

    

    

    out << endl;

    out << endl;
@@ -592,6 +593,7 @@ void IPCThreadState::decWeakHandle(int32_t handle) 




status_t IPCThreadState::attemptIncStrongHandle(int32_t handle)

status_t IPCThreadState::attemptIncStrongHandle(int32_t handle)

{

{

    LOG_REMOTEREFS("IPCThreadState::attemptIncStrongHandle(%d)\n", handle);

    mOut.writeInt32(BC_ATTEMPT_ACQUIRE);

    mOut.writeInt32(BC_ATTEMPT_ACQUIRE);

    mOut.writeInt32(0); // xxx was thread priority

    mOut.writeInt32(0); // xxx was thread priority

    mOut.writeInt32(handle);

    mOut.writeInt32(handle);

libs/utils/Static.cpp

+3 −1
Original line number Original line Diff line number Diff line
@@ -56,7 +56,9 @@ public: 
protected:

protected:

    virtual status_t writeLines(const struct iovec& vec, size_t N)

    virtual status_t writeLines(const struct iovec& vec, size_t N)

    {

    {

        android_writevLog(&vec, N);

        //android_writevLog(&vec, N);       <-- this is now a no-op

        if (N != 1) LOGI("WARNING: writeLines N=%d\n", N);

        LOGI("%.*s", vec.iov_len, (const char*) vec.iov_base);

        return NO_ERROR;

        return NO_ERROR;

    }

    }

};

};