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

Commit 38003165 authored by Stephen Crane's avatar Stephen Crane
Browse files

[storageproxyd] Dump binary buffers to log instead of stderr 

Rewrites the buffer logging to print to the Android log instead of
stderr. The storageproxyd service is started by init and stderr is not
logged anywhere. Because we want to log sense data errors under normal
operation, we need to log to logcat instead of stderr.

Test: Define RPMB_DEBUG, build for qemu-trusty, run, inspect logcat
Bug: 195544379
Change-Id: Iecc0d4680420bb92c94be628789093888a2f1941
parent c92ae83a

trusty/storage/proxy/rpmb.c

+55 −10
Original line number Original line Diff line number Diff line
@@ -107,16 +107,61 @@ static enum dev_type dev_type = UNKNOWN_RPMB; 




static const char* UFS_WAKE_LOCK_NAME = "ufs_seq_wakelock";

static const char* UFS_WAKE_LOCK_NAME = "ufs_seq_wakelock";





static void print_buf(FILE* handle, const char* prefix, const uint8_t* buf, size_t size) {

/**

 * log_buf - Log a byte buffer to the android log.

 * @priority: One of ANDROID_LOG_* priority levels from android_LogPriority in

 *            android/log.h

 * @prefix:   A null-terminated string that identifies this buffer. Must be less

 *            than 128 bytes.

 * @buf:      Buffer to dump.

 * @size:     Length of @buf in bytes.

 */

#define LOG_BUF_SIZE 256

static int log_buf(int priority, const char* prefix, const uint8_t* buf, size_t size) {

    int rc;

    size_t i;

    size_t i;

    char line[LOG_BUF_SIZE] = {0};

    char* cur = line;





    fprintf(handle, "%s @%p [%zu]", prefix, buf, size);

    rc = snprintf(line, LOG_BUF_SIZE, "%s @%p [%zu]", prefix, buf, size);

    if (rc < 0 || rc >= LOG_BUF_SIZE) {

        goto err;

    }

    cur += rc;

    for (i = 0; i < size; i++) {

    for (i = 0; i < size; i++) {

        if (i && i % 32 == 0) fprintf(handle, "\n%*s", (int)strlen(prefix), "");

        if (i % 32 == 0) {

        fprintf(handle, " %02x", buf[i]);

            /*

             * Flush the line out to the log after we have printed 32 bytes

             * (also flushes the header line on the first iteration and sets up

             * for printing the buffer itself)

             */

            LOG_PRI(priority, LOG_TAG, "%s", line);

            memset(line, 0, LOG_BUF_SIZE);

            cur = line;

            /* Shift output over by the length of the prefix */

            rc = snprintf(line, LOG_BUF_SIZE, "%*s", (int)strlen(prefix), "");

            if (rc < 0 || rc >= LOG_BUF_SIZE) {

                goto err;

            }

            cur += rc;

        }

        rc = snprintf(cur, LOG_BUF_SIZE - (cur - line), "%02x ", buf[i]);

        if (rc < 0 || rc >= LOG_BUF_SIZE - (cur - line)) {

            goto err;

        }

        cur += rc;

    }

    LOG_PRI(priority, LOG_TAG, "%s", line);



    return 0;



err:

    if (rc < 0) {

        return rc;

    } else {

        ALOGE("log_buf prefix was too long");

        return -1;

    }

    }

    fprintf(handle, "\n");

    fflush(handle);

}

}





static void set_sg_io_hdr(sg_io_hdr_t* io_hdrp, int dxfer_direction, unsigned char cmd_len,

static void set_sg_io_hdr(sg_io_hdr_t* io_hdrp, int dxfer_direction, unsigned char cmd_len,
@@ -194,7 +239,7 @@ static bool check_scsi_sense(const uint8_t* sense_buf, size_t len) { 




    ALOGE("Unexpected SCSI sense data: key=%hhu, asc=%hhu, ascq=%hhu\n", sense_key,

    ALOGE("Unexpected SCSI sense data: key=%hhu, asc=%hhu, ascq=%hhu\n", sense_key,

          additional_sense_code, additional_sense_code_qualifier);

          additional_sense_code, additional_sense_code_qualifier);

    print_buf(stderr, "sense buffer: ", sense_buf, len);

    log_buf(ANDROID_LOG_ERROR, "sense buffer: ", sense_buf, len);

    return false;

    return false;

}

}
@@ -257,7 +302,7 @@ static int send_mmc_rpmb_req(int mmc_fd, const struct storage_rpmb_send_req* req 
        mmc_ioc_cmd_set_data((*cmd), write_buf);

        mmc_ioc_cmd_set_data((*cmd), write_buf);

#ifdef RPMB_DEBUG

#ifdef RPMB_DEBUG

        ALOGI("opcode: 0x%x, write_flag: 0x%x\n", cmd->opcode, cmd->write_flag);

        ALOGI("opcode: 0x%x, write_flag: 0x%x\n", cmd->opcode, cmd->write_flag);

        print_buf(stdout, "request: ", write_buf, req->reliable_write_size);

        log_buf(ANDROID_LOG_INFO, "request: ", write_buf, req->reliable_write_size);

#endif

#endif

        write_buf += req->reliable_write_size;

        write_buf += req->reliable_write_size;

        mmc.multi.num_of_cmds++;

        mmc.multi.num_of_cmds++;
@@ -273,7 +318,7 @@ static int send_mmc_rpmb_req(int mmc_fd, const struct storage_rpmb_send_req* req 
        mmc_ioc_cmd_set_data((*cmd), write_buf);

        mmc_ioc_cmd_set_data((*cmd), write_buf);

#ifdef RPMB_DEBUG

#ifdef RPMB_DEBUG

        ALOGI("opcode: 0x%x, write_flag: 0x%x\n", cmd->opcode, cmd->write_flag);

        ALOGI("opcode: 0x%x, write_flag: 0x%x\n", cmd->opcode, cmd->write_flag);

        print_buf(stdout, "request: ", write_buf, req->write_size);

        log_buf(ANDROID_LOG_INFO, "request: ", write_buf, req->write_size);

#endif

#endif

        write_buf += req->write_size;

        write_buf += req->write_size;

        mmc.multi.num_of_cmds++;

        mmc.multi.num_of_cmds++;
@@ -460,7 +505,7 @@ int rpmb_send(struct storage_msg* msg, const void* r, size_t req_len) { 
        goto err_response;

        goto err_response;

    }

    }

#ifdef RPMB_DEBUG

#ifdef RPMB_DEBUG

    if (req->read_size) print_buf(stdout, "response: ", read_buf, req->read_size);

    if (req->read_size) log_buf(ANDROID_LOG_INFO, "response: ", read_buf, req->read_size);

#endif

#endif





    if (msg->flags & STORAGE_MSG_FLAG_POST_COMMIT) {

    if (msg->flags & STORAGE_MSG_FLAG_POST_COMMIT) {