Added hex logging back again.

Added it back in in AsyncQueue
This commit is contained in:
2016-03-14 09:43:27 +01:00
parent ac2d66c61e
commit 18816067db
5 changed files with 130 additions and 7 deletions

View File

@ -22,7 +22,7 @@
#include "asyncqueue.h" #include "asyncqueue.h"
#include "nwatch.h" #include "nwatch.h"
#include <stdbool.h> #include <stdbool.h>
#include <hexString.h>
typedef struct __async_command AQ_Cmd, *pAQ_Cmd; typedef struct __async_command AQ_Cmd, *pAQ_Cmd;
@ -394,6 +394,7 @@ static int StartCommand(pAsyncQueue self)
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); gettimeofday(&tv, NULL);
Log(ERROR, "asquio","%d unsolicited chars in AsyncQueue %s",iRet, self->queue_name); Log(ERROR, "asquio","%d unsolicited chars in AsyncQueue %s",iRet, self->queue_name);
LogHex(&tv,ERROR,SASQIO,reply,iRet);
} }
} }
} }
@ -502,6 +503,7 @@ static int CommandTimeout(void *cntx, int mode)
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); gettimeofday(&tv, NULL);
Log(DEBUG,"asquio", "Timeout Trace on AsyncQueue %s", self->queue_name); Log(DEBUG,"asquio", "Timeout Trace on AsyncQueue %s", self->queue_name);
LogHex(&tv,DEBUG,SASQIO,myCmd->tran->inp_buf,myCmd->tran->inp_idx);
} }
if (myCmd->retries > 0) { if (myCmd->retries > 0) {
--myCmd->retries; --myCmd->retries;
@ -532,6 +534,17 @@ static int DelayedStart(void *cntx, int mode)
return 1; return 1;
} }
static void LogHexPrefix(struct timeval *tv, unsigned int severity, char *prefix, char *buffer, int bufferLength)
{
char *hexData = NULL;
hexData = bytesToHexString((uint8_t *)buffer,(size_t)bufferLength);
if(hexData != NULL){
LogTS(tv,severity,SASQIO,"%s:%s", prefix,hexData);
free(hexData);
}
}
static int MyCallback(void *context, int mode) static int MyCallback(void *context, int mode)
{ {
pAsyncQueue self = (pAsyncQueue) context; pAsyncQueue self = (pAsyncQueue) context;
@ -567,8 +580,8 @@ static int MyCallback(void *context, int mode)
if (self->trace) { if (self->trace) {
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); gettimeofday(&tv, NULL);
Log(INFO, "asquio", Log(INFO, "asquio","Input Trace on AsyncQueue %s", self->queue_name);
"Received:%s:%s", self->queue_name,myCmd->tran->inp_buf); LogHex(&tv,INFO,SASQIO,myCmd->tran->inp_buf, myCmd->tran->inp_idx);
} }
PopCommand(self); PopCommand(self);
break; break;
@ -579,7 +592,10 @@ static int MyCallback(void *context, int mode)
Log(ERROR,"asquio", Log(ERROR,"asquio",
"Protocol error %d in AsyncQueue %s", "Protocol error %d in AsyncQueue %s",
iRet, self->queue_name); iRet, self->queue_name);
Log(ERROR,"asquio","SENT:%s:Received:%s",myCmd->tran->out_buf, myCmd->tran->inp_buf); LogHexPrefix(&tv,ERROR,"Sent", myCmd->tran->out_buf,myCmd->tran->out_len);
LogHexPrefix(&tv,ERROR,"Received", myCmd->tran->inp_buf,myCmd->tran->inp_len);
LogHexPrefix(&tv,ERROR,"Processed", &reply[0],i);
LogHexPrefix(&tv,ERROR,"Unprocessed", &reply[i],excess);
break; break;
} }
} }
@ -813,8 +829,7 @@ int AsyncUnitWrite(pAsyncUnit unit, void *buffer, int buflen)
if (unit->queue->trace) { if (unit->queue->trace) {
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); gettimeofday(&tv, NULL);
Log(DEBUG,"asquio" LogHexPrefix(&tv,DEBUG,"Output Trace on AsyncQueue", buffer, buflen);
"Output Trace on AsyncQueue %s:%s", unit->queue->queue_name, buffer);
} }
sock = AsyncUnitGetSocket(unit); sock = AsyncUnitGetSocket(unit);
iRet = NETWrite(sock, buffer, buflen); iRet = NETWrite(sock, buffer, buflen);

65
hexString.c Normal file
View File

@ -0,0 +1,65 @@
/*
* hexString.c
* byteutils
*
* Created by Richard Murphy on 3/7/10.
* Copyright 2010 McKenzie-Murphy. All rights reserved.
*
*/
#include "hexString.h"
/* utility function to convert hex character representation to their nibble (4 bit) values */
static uint8_t
nibbleFromChar(char c)
{
if(c >= '0' && c <= '9') return c - '0';
if(c >= 'a' && c <= 'f') return c - 'a' + 10;
if(c >= 'A' && c <= 'F') return c - 'A' + 10;
return 255;
}
/* Convert a string of characters representing a hex buffer into a series of bytes of that real value */
uint8_t
*hexStringToBytes(char *inhex)
{
uint8_t *retval;
uint8_t *p;
int len, i;
len = strlen(inhex) / 2;
retval = malloc(len+1);
for(i=0, p = (uint8_t *) inhex; i<len; i++) {
retval[i] = (nibbleFromChar(*p) << 4) | nibbleFromChar(*(p+1));
p += 2;
}
retval[len] = 0;
return retval;
}
static char byteMap[] = { '0', '1', '2', '3', '4', '5', '6', '7', '8', '9', 'a', 'b', 'c', 'd', 'e', 'f' };
static int byteMapLen = sizeof(byteMap);
/* Utility function to convert nibbles (4 bit values) into a hex character representation */
static char
nibbleToChar(uint8_t nibble)
{
if(nibble < byteMapLen) return byteMap[nibble];
return '*';
}
/* Convert a buffer of binary values into a hex string representation */
char
*bytesToHexString(uint8_t *bytes, size_t buflen)
{
char *retval;
int i;
retval = malloc(buflen*2 + 1);
for(i=0; i<buflen; i++) {
retval[i*2] = nibbleToChar(bytes[i] >> 4);
retval[i*2+1] = nibbleToChar(bytes[i] & 0x0f);
}
retval[i] = '\0';
return retval;
}

18
hexString.h Normal file
View File

@ -0,0 +1,18 @@
/*
* hexString.h
* byteutils
*
* Created by Richard Murphy on 3/7/10.
* Copyright 2010 McKenzie-Murphy. All rights reserved.
*
*/
#include <stdint.h>
#include <stdlib.h>
#include <string.h>
uint8_t
*hexStringToBytes(char *inhex);
char
*bytesToHexString(uint8_t *bytes, size_t buflen);

17
logv2.c
View File

@ -15,6 +15,7 @@
#include <lld_str.h> #include <lld_str.h>
#include <lld.h> #include <lld.h>
#include <dynstring.h> #include <dynstring.h>
#include <hexString.h>
/*============================================================================== /*==============================================================================
some static fields which control log file rotation some static fields which control log file rotation
===============================================================================*/ ===============================================================================*/
@ -456,6 +457,22 @@ void LogTS(struct timeval *tv, unsigned int severity, unsigned int subsystem,con
} }
}
/*----------------------------------------------------------------------------*/
void LogHex(struct timeval*tv, unsigned int severity, unsigned int subsystem,
char *buffer, int bufferLength)
{
char subText[30], timeStamp[256], *hexData;
formatSubsystem(subsystem,subText,sizeof(subText));
formatTimeStamp(tv, timeStamp,sizeof(timeStamp),0);
hexData = bytesToHexString((uint8_t *)buffer,(size_t)bufferLength);
if(hexData != NULL){
LogInternal((char *)timeStamp, severity, subText,hexData);
free(hexData);
}
} }
/*----------------------------------------------------------------------------*/ /*----------------------------------------------------------------------------*/
void Log(unsigned int severity, const char *subsystem,const char *format,...) void Log(unsigned int severity, const char *subsystem,const char *format,...)

10
logv2.h
View File

@ -64,7 +64,15 @@ void LogIS(unsigned int severity, unsigned int subsystem,const char *format,...)
* \param ... The data to format * \param ... The data to format
*/ */
void LogTS(struct timeval *tv, unsigned int severity, unsigned int subsystem,const char *format,...); void LogTS(struct timeval *tv, unsigned int severity, unsigned int subsystem,const char *format,...);
/*
* write a log entry in hex
* \param timeStamp A user supplied timestamp. Can be NULL, then the current time is used
* \param severity The message severity. Must be one of the defines given above
* \param subsystem The subsystem reporting the log messages
* \param buffer the bytes to log as hex
* \param bufferLength The length of buffer
*/
void LogHex(struct timeval*tv, unsigned int severity, unsigned int subsystem,char *buffer, int bufferLength);
/* The callback functio which is called by the logging system on log events /* The callback functio which is called by the logging system on log events