Commit df230d59 authored by Scott Vokes's avatar Scott Vokes Committed by Greg Williams
Browse files

Add optional request/response time logging to measure per-cmd response time.

parent e27e62b6

RELEASE.md

+4 −0
Original line number Diff line number Diff line 
v0.11.2 (kinetic-protocol 3.0.5)

--------------------------------

* Changed all threads to be block indefinitely and be fully event-driven.



v0.11.1 (kinetic-protocol 3.0.5)

--------------------------------

* Fixed race condition causing timeouts to not ne handled resulting in a deadlock.

config/Doxyfile

+1 −1
Original line number Diff line number Diff line
@@ -38,7 +38,7 @@ PROJECT_NAME = kinetic-c 
# could be handy for archiving the generated documentation or if some version

# control system is used.



PROJECT_NUMBER           = "v0.11.1"

PROJECT_NUMBER           = "v0.11.2-beta"



# Using the PROJECT_BRIEF tag one can provide an optional one line description

# for a project that appears at the top of each page and should give viewer a

config/VERSION

+1 −1
Original line number Diff line number Diff line 
0.11.1
 
0.11.2-beta

src/lib/kinetic_logger.h

+1 −0
Original line number Diff line number Diff line
@@ -27,6 +27,7 @@ 


#define KINETIC_LOGGER_DISABLED false

#define KINETIC_LOGGER_FLUSH_THREAD_ENABLED false

#define KINETIC_LOGGER_LOG_SEQUENCE_ID true

#define KINETIC_LOG_FILE "kinetic.log"



void KineticLogger_Init(const char* logFile, int log_level);

src/lib/kinetic_operation.c

+18 −2
Original line number Diff line number Diff line
@@ -58,6 +58,20 @@ KineticStatus KineticOperation_SendRequest(KineticOperation* const operation) 
    return status;

}



static void log_request_seq_id(int fd, int64_t seq_id, KineticMessageType mt)

{

    #if KINETIC_LOGGER_LOG_SEQUENCE_ID

    struct timeval tv;

    gettimeofday(&tv, NULL);

    LOGF2("SEQ_ID request fd %d seq_id %lld %08lld.%08d cmd %02x",

        fd, (long long)seq_id,

        (long)tv.tv_sec, (long)tv.tv_usec, (uint8_t)mt);

    #else

    (void)seq_id;

    (void)mt;

    #endif

}    



// TODO: Assess refactoring this method by dissecting out Operation and relocate to kinetic_pdu

static KineticStatus KineticOperation_SendRequestInner(KineticOperation* const operation)

{
@@ -101,6 +115,8 @@ static KineticStatus KineticOperation_SendRequestInner(KineticOperation* const o 
        .len = request->message.message.commandBytes.len,

    });



    log_request_seq_id(operation->connection->socket, seq_id, request->message.header.messageType);



    switch (proto->authType) {

    case KINETIC_PROTO_MESSAGE_AUTH_TYPE_PINAUTH:

        /* TODO: If operation uses PIN AUTH, then init that */
@@ -164,12 +180,12 @@ static KineticStatus KineticOperation_SendRequestInner(KineticOperation* const o 
    assert(request);



    LOGF2("[PDU TX] pdu: %p, session: %p, bus: %p, "

        "fd: %6d, seq: %8lld, protoLen: %8u, valueLen: %8u, op: %p",

        "fd: %6d, seq: %8lld, protoLen: %8u, valueLen: %8u, op: %p, msgType: %02x",

        (void*)operation->request,

        (void*)operation->connection->pSession, (void*)operation->connection->messageBus,

        operation->connection->socket, request->message.header.sequence,

        header.protobufLength, header.valueLength,

        (void*)operation);

        (void*)operation, request->message.header.messageType);

    KineticLogger_LogHeader(3, &header);

    KineticLogger_LogProtobuf(3, proto);